mirror of
https://github.com/servalproject/serval-dna.git
synced 2025-04-07 11:08:36 +00:00
Log to file, Android and stderr simultaneously
Indepent configuration of show_pid, show_time and log level for each destination Update test scripts for new config options Include xprintf.c in MDP client source files (now used by log.c)
This commit is contained in:
parent
a50594971c
commit
95b0c028f2
@ -23,6 +23,7 @@ MONITORCLIENTSRCS=conf.c \
|
||||
conf_schema.c \
|
||||
dataformats.c \
|
||||
log.c \
|
||||
xprintf.c \
|
||||
os.c \
|
||||
mem.c \
|
||||
monitor-client.c \
|
||||
@ -40,6 +41,7 @@ MDPCLIENTSRCS=conf.c \
|
||||
os.c \
|
||||
mem.c \
|
||||
log.c \
|
||||
xprintf.c \
|
||||
mdp_client.c \
|
||||
instance.c \
|
||||
net.c \
|
||||
|
@ -763,10 +763,12 @@ int app_server_start(const struct cli_parsed *parsed, void *context)
|
||||
exit(WHY_perror("fork"));
|
||||
case 0: {
|
||||
/* Grandchild process. Close logfile (so that it gets re-opened again on demand, with
|
||||
our own file pointer), disconnect from current directory, disconnect standard I/O
|
||||
streams, and start a new process session so that if we are being started by an adb
|
||||
shell session, then we don't receive a SIGHUP when the adb shell process ends. */
|
||||
close_logging();
|
||||
our own file pointer), disable logging to stderr (about to get closed), disconnect
|
||||
from current directory, disconnect standard I/O streams, and start a new process
|
||||
session so that if we are being started by an adb shell session on an Android device,
|
||||
then we don't receive a SIGHUP when the adb shell process ends. */
|
||||
close_log_file();
|
||||
disable_log_stderr();
|
||||
int fd;
|
||||
if ((fd = open("/dev/null", O_RDWR, 0)) == -1)
|
||||
_exit(WHY_perror("open(\"/dev/null\")"));
|
||||
@ -789,6 +791,7 @@ int app_server_start(const struct cli_parsed *parsed, void *context)
|
||||
/* Need the cast on Solaris because it defines NULL as 0L and gcc doesn't see it as a
|
||||
sentinal. */
|
||||
execl(execpath, execpath, "start", "foreground", (void *)NULL);
|
||||
WHYF_perror("execl(%s,\"start\",\"foreground\")", alloca_str_toprint(execpath));
|
||||
_exit(-1);
|
||||
}
|
||||
_exit(server(NULL));
|
||||
|
@ -234,8 +234,9 @@ END_STRUCT
|
||||
|
||||
STRUCT(log)
|
||||
STRING(256, file_path, "", str_nonempty,, "Path of log file, either absolute or relative to instance directory")
|
||||
SUB_STRUCT(log_format, file_format,, full)
|
||||
SUB_STRUCT(log_format, stderr_format,, helpful)
|
||||
SUB_STRUCT(log_format, file,, full)
|
||||
SUB_STRUCT(log_format, stderr,, helpful)
|
||||
SUB_STRUCT(log_format, android,, android)
|
||||
END_STRUCT
|
||||
|
||||
STRUCT_DEFAULT(log_format, helpful)
|
||||
@ -250,6 +251,12 @@ ATOM_DEFAULT(show_time, 1)
|
||||
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
|
||||
END_STRUCT_DEFAULT
|
||||
|
||||
STRUCT_DEFAULT(log_format, android)
|
||||
ATOM_DEFAULT(show_pid, 0)
|
||||
ATOM_DEFAULT(show_time, 1)
|
||||
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
|
||||
END_STRUCT_DEFAULT
|
||||
|
||||
STRUCT(server)
|
||||
STRING(256, chdir, "/", absolute_path,, "Absolute path of chdir(2) for server process")
|
||||
STRING(256, interface_path, "", str_nonempty,, "Path of directory containing interface files, either absolute or relative to instance directory")
|
||||
|
@ -192,24 +192,22 @@ dna_helper_start()
|
||||
switch (dna_helper_pid = fork()) {
|
||||
case 0:
|
||||
/* Child, should exec() to become helper after installing file descriptors. */
|
||||
close_log_file();
|
||||
setenv("MYSID", mysid, 1);
|
||||
set_logging(stderr);
|
||||
signal(SIGTERM, SIG_DFL);
|
||||
close(stdin_fds[1]);
|
||||
close(stdout_fds[0]);
|
||||
close(stderr_fds[0]);
|
||||
if (dup2(stderr_fds[1], 2) == -1 || dup2(stdout_fds[1], 1) == -1 || dup2(stdin_fds[0], 0) == -1) {
|
||||
LOG_perror(LOG_LEVEL_FATAL, "dup2");
|
||||
fflush(stderr);
|
||||
_exit(-1);
|
||||
}
|
||||
{
|
||||
execv(config.dna.helper.executable, (char **)argv);
|
||||
LOGF_perror(LOG_LEVEL_FATAL, "execl(%s, [%s])",
|
||||
LOGF_perror(LOG_LEVEL_FATAL, "execv(%s, [%s])",
|
||||
alloca_str_toprint(config.dna.helper.executable),
|
||||
strbuf_str(argv_sb)
|
||||
);
|
||||
fflush(stderr);
|
||||
}
|
||||
do { _exit(-1); } while (1);
|
||||
break;
|
||||
|
437
log.c
437
log.c
@ -41,88 +41,102 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
|
||||
#include "str.h"
|
||||
#include "strbuf.h"
|
||||
#include "strbuf_helpers.h"
|
||||
#include "xprintf.h"
|
||||
|
||||
int serverMode = 0;
|
||||
const struct __sourceloc __whence = __NOWHERE__;
|
||||
|
||||
static FILE *logfile = NULL;
|
||||
static FILE *logfile_file = NULL;
|
||||
static FILE *logfile_stderr = NULL;
|
||||
#define NO_FILE ((FILE *)1)
|
||||
|
||||
/* The logbuf is used to accumulate log messages before the log file is open and ready for
|
||||
/* The file logbuf is used to accumulate log messages before the log file is open and ready for
|
||||
* writing.
|
||||
*/
|
||||
static char _log_buf[8192];
|
||||
static struct strbuf logbuf = STRUCT_STRBUF_EMPTY;
|
||||
|
||||
/* Whether the software version has been logged in the current file yet.
|
||||
*/
|
||||
bool_t version_logged = 0;
|
||||
|
||||
struct tm last_tm;
|
||||
/* The time stamp of the last logged message, used to detect when the date advances so that
|
||||
* the date can be logged.
|
||||
*/
|
||||
struct tm last_tm;
|
||||
|
||||
#ifdef ANDROID
|
||||
|
||||
#include <android/log.h>
|
||||
#endif
|
||||
|
||||
void set_logging(FILE *f)
|
||||
{
|
||||
logfile = f;
|
||||
if (f == stdout)
|
||||
INFO("Logging to stdout");
|
||||
else if (f == stderr)
|
||||
INFO("Logging to stderr");
|
||||
else if (f != NULL)
|
||||
INFOF("Logging to stream with fd=%d", fileno(f));
|
||||
}
|
||||
/* The Android logbuf is used to accumulate a single log line before printing to Android's
|
||||
* logging API.
|
||||
*/
|
||||
static char _log_buf_android[1024];
|
||||
static struct strbuf logbuf_android;
|
||||
|
||||
static FILE *_open_logging()
|
||||
#endif // ANDROID
|
||||
|
||||
static void _open_log_file()
|
||||
{
|
||||
#ifdef ANDROID
|
||||
return NULL;
|
||||
#endif
|
||||
if (!logfile) {
|
||||
if (!logfile_file) {
|
||||
const char *logpath = getenv("SERVALD_LOG_FILE");
|
||||
if (!logpath) {
|
||||
if (cf_limbo)
|
||||
return NULL;
|
||||
return;
|
||||
logpath = config.log.file_path;
|
||||
}
|
||||
if (!logpath || !logpath[0]) {
|
||||
logfile = stderr;
|
||||
logfile_file = NO_FILE;
|
||||
if (serverMode)
|
||||
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "No logfile configured -- logging to stderr");
|
||||
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "No logfile_file configured");
|
||||
} else {
|
||||
char path[1024];
|
||||
if (!FORM_SERVAL_INSTANCE_PATH(path, logpath)) {
|
||||
logfile = stderr;
|
||||
logMessage(LOG_LEVEL_WARN, __NOWHERE__, "Logfile path overrun -- logging to stderr");
|
||||
} else if ((logfile = fopen(path, "a"))) {
|
||||
setlinebuf(logfile);
|
||||
logfile_file = NO_FILE;
|
||||
logMessage(LOG_LEVEL_WARN, __NOWHERE__, "Logfile path overrun");
|
||||
} else if ((logfile_file = fopen(path, "a"))) {
|
||||
setlinebuf(logfile_file);
|
||||
if (serverMode)
|
||||
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "Logging to %s (fd %d)", path, fileno(logfile));
|
||||
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "Logging to %s (fd %d)", path, fileno(logfile_file));
|
||||
} else {
|
||||
logfile = stderr;
|
||||
logfile_file = NO_FILE;
|
||||
WARNF_perror("fopen(%s)", path);
|
||||
logMessage(LOG_LEVEL_WARN, __NOWHERE__, "Cannot append to %s -- falling back to stderr", path);
|
||||
logMessage(LOG_LEVEL_WARN, __NOWHERE__, "Cannot append to %s", path);
|
||||
}
|
||||
}
|
||||
}
|
||||
return logfile;
|
||||
}
|
||||
|
||||
FILE *open_logging()
|
||||
static void _flush_log_file()
|
||||
{
|
||||
return _open_logging();
|
||||
if (logfile_file && logfile_file != NO_FILE) {
|
||||
fprintf(logfile_file, "%s%s%s",
|
||||
strbuf_len(&logbuf) ? strbuf_str(&logbuf) : "",
|
||||
strbuf_len(&logbuf) ? "\n" : "",
|
||||
strbuf_overrun(&logbuf) ? "LOG OVERRUN\n" : ""
|
||||
);
|
||||
strbuf_reset(&logbuf);
|
||||
}
|
||||
}
|
||||
|
||||
void close_logging()
|
||||
void close_log_file()
|
||||
{
|
||||
if (logfile) {
|
||||
fclose(logfile);
|
||||
logfile = NULL;
|
||||
if (logfile_file && logfile_file != NO_FILE)
|
||||
fclose(logfile_file);
|
||||
logfile_file = NULL;
|
||||
}
|
||||
|
||||
static void _open_log_stderr()
|
||||
{
|
||||
if (!logfile_stderr) {
|
||||
logfile_stderr = stderr;
|
||||
setlinebuf(logfile_stderr);
|
||||
}
|
||||
}
|
||||
|
||||
static void _flush_log_stderr()
|
||||
{
|
||||
if (logfile_stderr && logfile_stderr != NO_FILE)
|
||||
fflush(logfile_stderr);
|
||||
}
|
||||
|
||||
void disable_log_stderr()
|
||||
{
|
||||
if (logfile_stderr && logfile_stderr != NO_FILE) {
|
||||
fflush(logfile_stderr);
|
||||
logfile_stderr = NO_FILE;
|
||||
}
|
||||
}
|
||||
|
||||
@ -140,161 +154,254 @@ static const char *_trimbuildpath(const char *path)
|
||||
return &path[lastsep];
|
||||
}
|
||||
|
||||
static int _log_prepare(int level, struct __sourceloc whence)
|
||||
struct _log_state {
|
||||
|
||||
/* This structure is initially zerofilled. */
|
||||
|
||||
/* Whether the software version has been logged in the current file yet.
|
||||
*/
|
||||
bool_t version_logged;
|
||||
|
||||
/* The time stamp of the last logged message, used to detect when the date advances so that
|
||||
* the date can be logged.
|
||||
*/
|
||||
struct tm last_tm;
|
||||
|
||||
};
|
||||
|
||||
struct _log_state state_file;
|
||||
#ifdef ANDROID
|
||||
struct _log_state state_android;
|
||||
#endif
|
||||
struct _log_state state_stderr;
|
||||
|
||||
typedef struct _log_iterator {
|
||||
int level;
|
||||
struct __sourceloc whence;
|
||||
struct timeval tv;
|
||||
struct tm tm;
|
||||
XPRINTF xpf;
|
||||
int _file;
|
||||
#ifdef ANDROID
|
||||
int _android;
|
||||
#endif
|
||||
int _stderr;
|
||||
} _log_iterator;
|
||||
|
||||
static void _log_iterator_start(_log_iterator *it, int level, struct __sourceloc whence)
|
||||
{
|
||||
assert(level <= LOG_LEVEL_FATAL);
|
||||
if (level < config.log.file_format.level)
|
||||
return 0;
|
||||
struct timeval tv;
|
||||
tv.tv_sec = 0;
|
||||
if (config.log.file_format.show_time)
|
||||
gettimeofday(&tv, NULL);
|
||||
if (!version_logged)
|
||||
logVersion();
|
||||
_open_logging(); // Put initial INFO message at start of log file
|
||||
// No calls outside log.c from this point on.
|
||||
while (1) {
|
||||
memset(it, 0, sizeof *it);
|
||||
it->level = level;
|
||||
it->whence = whence;
|
||||
gettimeofday(&it->tv, NULL);
|
||||
localtime_r(&it->tv.tv_sec, &it->tm);
|
||||
}
|
||||
|
||||
static void _log_level_prefix(_log_iterator *it, int level)
|
||||
{
|
||||
const char *levelstr = "UNKWN:";
|
||||
switch (level) {
|
||||
case LOG_LEVEL_FATAL: levelstr = "FATAL:"; break;
|
||||
case LOG_LEVEL_ERROR: levelstr = "ERROR:"; break;
|
||||
case LOG_LEVEL_WARN: levelstr = "WARN:"; break;
|
||||
case LOG_LEVEL_INFO: levelstr = "INFO:"; break;
|
||||
case LOG_LEVEL_DEBUG: levelstr = "DEBUG:"; break;
|
||||
}
|
||||
xprintf(it->xpf, "%-6.6s", levelstr);
|
||||
}
|
||||
|
||||
static int _log_prefix(const struct config_log_format *cfg, _log_iterator *it, int level)
|
||||
{
|
||||
if (cfg == &config.log.file) {
|
||||
_open_log_file(); // puts initial INFO message at start of log file
|
||||
if (logfile_file == NO_FILE)
|
||||
return 0;
|
||||
if (strbuf_is_empty(&logbuf))
|
||||
strbuf_init(&logbuf, _log_buf, sizeof _log_buf);
|
||||
else if (strbuf_len(&logbuf))
|
||||
strbuf_putc(&logbuf, '\n');
|
||||
#ifndef ANDROID
|
||||
const char *levelstr = "UNKWN:";
|
||||
switch (level) {
|
||||
case LOG_LEVEL_FATAL: levelstr = "FATAL:"; break;
|
||||
case LOG_LEVEL_ERROR: levelstr = "ERROR:"; break;
|
||||
case LOG_LEVEL_WARN: levelstr = "WARN:"; break;
|
||||
case LOG_LEVEL_INFO: levelstr = "INFO:"; break;
|
||||
case LOG_LEVEL_DEBUG: levelstr = "DEBUG:"; break;
|
||||
}
|
||||
strbuf_sprintf(&logbuf, "%-6.6s", levelstr);
|
||||
#endif
|
||||
if (config.log.file_format.show_pid)
|
||||
strbuf_sprintf(&logbuf, " [%5u]", getpid());
|
||||
if (config.log.file_format.show_time) {
|
||||
if (tv.tv_sec == 0) {
|
||||
strbuf_puts(&logbuf, " NOTIME______");
|
||||
} else {
|
||||
struct tm tm;
|
||||
localtime_r(&tv.tv_sec, &tm);
|
||||
char buf[50];
|
||||
if (strftime(buf, sizeof buf, "%T", &tm) == 0)
|
||||
strbuf_puts(&logbuf, " EMPTYTIME___");
|
||||
else
|
||||
strbuf_sprintf(&logbuf, " %s.%03u", buf, tv.tv_usec / 1000);
|
||||
if (tm.tm_mday != last_tm.tm_mday || tm.tm_mon != last_tm.tm_mon || tm.tm_year != last_tm.tm_year) {
|
||||
if (strftime(buf, sizeof buf, "%F %T %z", &tm))
|
||||
strbuf_puts(&logbuf, " Local date/time: ");
|
||||
strbuf_puts(&logbuf, buf);
|
||||
last_tm = tm;
|
||||
continue;
|
||||
}
|
||||
last_tm = tm;
|
||||
}
|
||||
}
|
||||
break;
|
||||
it->xpf = XPRINTF_STRBUF(&logbuf);
|
||||
_log_level_prefix(it, level);
|
||||
}
|
||||
if (whence.file) {
|
||||
strbuf_sprintf(&logbuf, " %s", _trimbuildpath(whence.file));
|
||||
if (whence.line)
|
||||
strbuf_sprintf(&logbuf, ":%u", whence.line);
|
||||
if (whence.function)
|
||||
strbuf_sprintf(&logbuf, ":%s()", whence.function);
|
||||
strbuf_putc(&logbuf, ' ');
|
||||
} else if (whence.function) {
|
||||
strbuf_sprintf(&logbuf, " %s() ", whence.function);
|
||||
#ifdef ANDROID
|
||||
else if (cfg == &config.log.android) {
|
||||
strbuf_init(&logbuf_android, _log_buf_android, sizeof _log_buf_android);
|
||||
it->xpf = XPRINTF_STRBUF(&logbuf_android);
|
||||
}
|
||||
#endif // ANDROID
|
||||
else if (cfg == &config.log.stderr) {
|
||||
_open_log_stderr();
|
||||
if (logfile_stderr == NULL || logfile_stderr == NO_FILE)
|
||||
return 0;
|
||||
it->xpf = XPRINTF_STDIO(logfile_stderr);
|
||||
_log_level_prefix(it, level);
|
||||
}
|
||||
else
|
||||
abort();
|
||||
if (cfg->show_pid)
|
||||
xprintf(it->xpf, "[%5u] ", getpid());
|
||||
if (cfg->show_time) {
|
||||
if (it->tv.tv_sec == 0) {
|
||||
xputs("NOTIME______ ", it->xpf);
|
||||
} else {
|
||||
char buf[50];
|
||||
if (strftime(buf, sizeof buf, "%T", &it->tm) == 0)
|
||||
xputs("EMPTYTIME___ ", it->xpf);
|
||||
else
|
||||
xprintf(it->xpf, "%s.%03u ", buf, it->tv.tv_usec / 1000);
|
||||
}
|
||||
}
|
||||
strbuf_putc(&logbuf, ' ');
|
||||
return 1;
|
||||
}
|
||||
|
||||
/* Internal logging implementation.
|
||||
*
|
||||
* This function is called after every single log message is appended to logbuf, and is given the
|
||||
* level of the message. This function must reset the given strbuf after its contents have been
|
||||
* sent to the log, otherwise log messages will be repeated. If this function never resets the
|
||||
* strbuf, then it may eventually overrun.
|
||||
*
|
||||
* This function is also called to flush the given logbuf, by giving a log level of SILENT. That
|
||||
* indicates that no new message has been appended since the last time this function was called.
|
||||
*
|
||||
* @author Andrew Bettison <andrew@servalproject.com>
|
||||
*/
|
||||
static void _log_internal(int level, struct strbuf *buf)
|
||||
static void _log_finish(const struct config_log_format *cfg, _log_iterator *it, int level)
|
||||
{
|
||||
if (cfg == &config.log.file) {
|
||||
_flush_log_file();
|
||||
}
|
||||
#ifdef ANDROID
|
||||
int alevel = ANDROID_LOG_UNKNOWN;
|
||||
switch (level) {
|
||||
case LOG_LEVEL_FATAL: alevel = ANDROID_LOG_FATAL; break;
|
||||
case LOG_LEVEL_ERROR: alevel = ANDROID_LOG_ERROR; break;
|
||||
case LOG_LEVEL_INFO: alevel = ANDROID_LOG_INFO; break;
|
||||
case LOG_LEVEL_WARN: alevel = ANDROID_LOG_WARN; break;
|
||||
case LOG_LEVEL_DEBUG: alevel = ANDROID_LOG_DEBUG; break;
|
||||
case LOG_LEVEL_SILENT: return;
|
||||
default: abort();
|
||||
else if (cfg == &config.log.android) {
|
||||
int alevel = ANDROID_LOG_UNKNOWN;
|
||||
switch (it->level) {
|
||||
case LOG_LEVEL_FATAL: alevel = ANDROID_LOG_FATAL; break;
|
||||
case LOG_LEVEL_ERROR: alevel = ANDROID_LOG_ERROR; break;
|
||||
case LOG_LEVEL_INFO: alevel = ANDROID_LOG_INFO; break;
|
||||
case LOG_LEVEL_WARN: alevel = ANDROID_LOG_WARN; break;
|
||||
case LOG_LEVEL_DEBUG: alevel = ANDROID_LOG_DEBUG; break;
|
||||
case LOG_LEVEL_SILENT: return;
|
||||
default: abort();
|
||||
}
|
||||
__android_log_print(alevel, "servald", "%s", strbuf_str(_log_buf_android));
|
||||
}
|
||||
__android_log_print(alevel, "servald", "%s", strbuf_str(buf));
|
||||
strbuf_reset(buf);
|
||||
#else
|
||||
FILE *logf = _open_logging();
|
||||
if (logf) {
|
||||
fprintf(logf, "%s%s%s",
|
||||
strbuf_len(buf) ? strbuf_str(buf) : "",
|
||||
strbuf_len(buf) ? "\n" : "",
|
||||
strbuf_overrun(buf) ? "LOG OVERRUN\n" : ""
|
||||
);
|
||||
strbuf_reset(buf);
|
||||
#endif // ANDROID
|
||||
else if (cfg == &config.log.stderr) {
|
||||
fputc('\n', logfile_stderr);
|
||||
_flush_log_stderr();
|
||||
}
|
||||
#endif
|
||||
else
|
||||
abort();
|
||||
}
|
||||
|
||||
void (*_log_implementation)(int level, struct strbuf *buf) = _log_internal;
|
||||
|
||||
static void _log_finish(int level)
|
||||
static int _log_prepare(const struct config_log_format *cfg, struct _log_state *state, _log_iterator *it)
|
||||
{
|
||||
if (_log_implementation)
|
||||
_log_implementation(level, &logbuf);
|
||||
if (it->level < cfg->level)
|
||||
return 0;
|
||||
if ( it->tm.tm_mday != state->last_tm.tm_mday
|
||||
|| it->tm.tm_mon != state->last_tm.tm_mon
|
||||
|| it->tm.tm_year != state->last_tm.tm_year
|
||||
) {
|
||||
char buf[50];
|
||||
if (strftime(buf, sizeof buf, "%F %T %z", &it->tm)) {
|
||||
if (!_log_prefix(cfg, it, LOG_LEVEL_INFO))
|
||||
return 0;
|
||||
xputs("Local date/time: ", it->xpf);
|
||||
xputs(buf, it->xpf);
|
||||
state->last_tm = it->tm;
|
||||
_log_finish(cfg, it, LOG_LEVEL_INFO);
|
||||
}
|
||||
}
|
||||
if (!state->version_logged) {
|
||||
if (!_log_prefix(cfg, it, LOG_LEVEL_INFO))
|
||||
return 0;
|
||||
xprintf(it->xpf, "Serval DNA version: %s", version_servald);
|
||||
state->version_logged = 1;
|
||||
_log_finish(cfg, it, LOG_LEVEL_INFO);
|
||||
}
|
||||
if (!_log_prefix(cfg, it, it->level))
|
||||
return 0;
|
||||
if (it->whence.file) {
|
||||
xprintf(it->xpf, "%s", _trimbuildpath(it->whence.file));
|
||||
if (it->whence.line)
|
||||
xprintf(it->xpf, ":%u", it->whence.line);
|
||||
if (it->whence.function)
|
||||
xprintf(it->xpf, ":%s()", it->whence.function);
|
||||
xputs(" ", it->xpf);
|
||||
} else if (it->whence.function) {
|
||||
xprintf(it->xpf, "%s() ", it->whence.function);
|
||||
}
|
||||
return 1;
|
||||
}
|
||||
|
||||
void set_log_implementation(void (*log_function)(int level, struct strbuf *buf))
|
||||
static int _log_iterator_next(_log_iterator *it)
|
||||
{
|
||||
_log_implementation=log_function;
|
||||
if (it->_file == 0) {
|
||||
if (_log_prepare(&config.log.file, &state_file, it)) {
|
||||
it->_file = 1;
|
||||
return 1;
|
||||
}
|
||||
}
|
||||
else if (it->_file == 1) {
|
||||
_log_finish(&config.log.file, it, it->level);
|
||||
}
|
||||
it->_file = 2;
|
||||
#ifdef ANDROID
|
||||
if (it->_android == 0) {
|
||||
if (_log_prepare(&config.log.android, &state_android, it)) {
|
||||
it->_android = 1;
|
||||
return 1;
|
||||
}
|
||||
}
|
||||
else if (it->_android == 1) {
|
||||
_log_finish(&config.log.android, it, it->level);
|
||||
}
|
||||
it->_android = 2;
|
||||
#endif // ANDROID
|
||||
if (it->_stderr == 0) {
|
||||
if (_log_prepare(&config.log.stderr, &state_stderr, it)) {
|
||||
it->_stderr = 1;
|
||||
return 1;
|
||||
}
|
||||
}
|
||||
else if (it->_stderr == 1) {
|
||||
_log_finish(&config.log.stderr, it, it->level);
|
||||
}
|
||||
it->_stderr = 2;
|
||||
return 0;
|
||||
}
|
||||
|
||||
void logFlush()
|
||||
{
|
||||
if (_log_implementation)
|
||||
_log_implementation(LOG_LEVEL_SILENT, &logbuf);
|
||||
_flush_log_file();
|
||||
_flush_log_stderr();
|
||||
}
|
||||
|
||||
void logArgv(int level, struct __sourceloc whence, const char *label, int argc, const char *const *argv)
|
||||
{
|
||||
if (_log_prepare(level, whence)) {
|
||||
struct strbuf b;
|
||||
strbuf_init(&b, NULL, 0);
|
||||
strbuf_append_argv(&b, argc, argv);
|
||||
size_t len = strbuf_count(&b);
|
||||
strbuf_init(&b, alloca(len + 1), len + 1);
|
||||
strbuf_append_argv(&b, argc, argv);
|
||||
_log_iterator it;
|
||||
_log_iterator_start(&it, level, whence);
|
||||
while (_log_iterator_next(&it)) {
|
||||
if (label) {
|
||||
strbuf_puts(&logbuf, label);
|
||||
strbuf_putc(&logbuf, ' ');
|
||||
xputs(label, it.xpf);
|
||||
xputc(' ', it.xpf);
|
||||
}
|
||||
strbuf_append_argv(&logbuf, argc, argv);
|
||||
_log_finish(level);
|
||||
xputs(strbuf_str(&b), it.xpf);
|
||||
}
|
||||
}
|
||||
|
||||
void logString(int level, struct __sourceloc whence, const char *str)
|
||||
{
|
||||
_log_iterator it;
|
||||
const char *s = str;
|
||||
const char *p;
|
||||
for (p = str; *p; ++p) {
|
||||
if (*p == '\n') {
|
||||
if (_log_prepare(level, whence)) {
|
||||
strbuf_ncat(&logbuf, s, p - s);
|
||||
_log_finish(level);
|
||||
}
|
||||
_log_iterator_start(&it, level, whence);
|
||||
while (_log_iterator_next(&it))
|
||||
xprintf(it.xpf, "%.*s", p - s, s);
|
||||
s = p + 1;
|
||||
}
|
||||
}
|
||||
if (p > s && _log_prepare(level, whence)) {
|
||||
strbuf_ncat(&logbuf, s, p - s);
|
||||
_log_finish(level);
|
||||
if (p > s) {
|
||||
_log_iterator_start(&it, level, whence);
|
||||
while (_log_iterator_next(&it))
|
||||
xprintf(it.xpf, "%.*s", p - s, s);
|
||||
}
|
||||
}
|
||||
|
||||
@ -308,16 +415,10 @@ void logMessage(int level, struct __sourceloc whence, const char *fmt, ...)
|
||||
|
||||
void vlogMessage(int level, struct __sourceloc whence, const char *fmt, va_list ap)
|
||||
{
|
||||
if (_log_prepare(level, whence)) {
|
||||
strbuf_vsprintf(&logbuf, fmt, ap);
|
||||
_log_finish(level);
|
||||
}
|
||||
}
|
||||
|
||||
void logVersion()
|
||||
{
|
||||
version_logged = 1;
|
||||
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "Serval DNA version: %s", version_servald);
|
||||
_log_iterator it;
|
||||
_log_iterator_start(&it, level, whence);
|
||||
while (_log_iterator_next(&it))
|
||||
vxprintf(it.xpf, fmt, ap);
|
||||
}
|
||||
|
||||
void logDebugFlags()
|
||||
@ -382,7 +483,7 @@ ssize_t get_self_executable_path(char *buf, size_t len)
|
||||
int log_backtrace(struct __sourceloc whence)
|
||||
{
|
||||
#ifndef NO_BACKTRACE
|
||||
open_logging();
|
||||
_open_log_file();
|
||||
char execpath[MAXPATHLEN];
|
||||
if (get_self_executable_path(execpath, sizeof execpath) == -1)
|
||||
return WHY("cannot log backtrace: own executable path unknown");
|
||||
|
7
log.h
7
log.h
@ -87,21 +87,18 @@ extern const struct __sourceloc __whence; // see above
|
||||
|
||||
extern int serverMode;
|
||||
|
||||
void set_logging(FILE *f);
|
||||
FILE *open_logging();
|
||||
void close_logging();
|
||||
void close_log_file();
|
||||
void disable_log_stderr();
|
||||
void logFlush();
|
||||
void logArgv(int level, struct __sourceloc whence, const char *label, int argc, const char *const *argv);
|
||||
void logString(int level, struct __sourceloc whence, const char *str);
|
||||
void logMessage(int level, struct __sourceloc whence, const char *fmt, ...);
|
||||
void vlogMessage(int level, struct __sourceloc whence, const char *fmt, va_list);
|
||||
void logVersion();
|
||||
void logDebugFlags();
|
||||
int logDump(int level, struct __sourceloc whence, char *name, const unsigned char *addr, size_t len);
|
||||
ssize_t get_self_executable_path(char *buf, size_t len);
|
||||
int log_backtrace(struct __sourceloc whence);
|
||||
struct strbuf;
|
||||
void set_log_implementation(void (*log_function)(int level, struct strbuf *buf));
|
||||
|
||||
#define __HERE__ ((struct __sourceloc){ .file = __FILE__, .line = __LINE__, .function = __FUNCTION__ })
|
||||
#define __NOWHERE__ ((struct __sourceloc){ .file = NULL, .line = 0, .function = NULL })
|
||||
|
24
tests/config
24
tests/config
@ -90,13 +90,13 @@ doc_GetAll="Get all config items"
|
||||
test_GetAll() {
|
||||
executeOk_servald config \
|
||||
set debug.verbose true \
|
||||
set log.show_pid true \
|
||||
set log.stderr.show_pid true \
|
||||
set server.chdir /tmp/nothing \
|
||||
set rhizome.enable no
|
||||
executeOk_servald config get
|
||||
assertStdoutLineCount '==' 4
|
||||
assertStdoutGrep --stdout --matches=1 '^debug\.verbose=true$'
|
||||
assertStdoutGrep --stdout --matches=1 '^log\.show_pid=true$'
|
||||
assertStdoutGrep --stdout --matches=1 '^log\.stderr\.show_pid=true$'
|
||||
assertStdoutGrep --stdout --matches=1 '^server\.chdir=/tmp/nothing$'
|
||||
assertStdoutGrep --stdout --matches=1 '^rhizome\.enable=no$'
|
||||
}
|
||||
@ -105,19 +105,19 @@ doc_SetDelMixed="Set and del config items in single command"
|
||||
test_SetDelMixed() {
|
||||
executeOk_servald config \
|
||||
set debug.verbose true \
|
||||
set log.show_pid true \
|
||||
set log.file.show_pid true \
|
||||
set server.chdir /tmp/nothing \
|
||||
set rhizome.enable no
|
||||
executeOk_servald config \
|
||||
set debug.verbose false \
|
||||
del log.show_pid \
|
||||
set log.show_time 1 \
|
||||
del log.file.show_pid \
|
||||
set log.file.show_time 1 \
|
||||
del server.chdir \
|
||||
del rhizome.enable
|
||||
executeOk_servald config get
|
||||
assertStdoutLineCount '==' 2
|
||||
assertStdoutGrep --stdout --matches=1 '^debug\.verbose=false$'
|
||||
assertStdoutGrep --stdout --matches=1 '^log\.show_time=1$'
|
||||
assertStdoutGrep --stdout --matches=1 '^log\.file\.show_time=1$'
|
||||
}
|
||||
|
||||
doc_SetTwice="Set a single config item twice"
|
||||
@ -140,7 +140,7 @@ test_DelNull() {
|
||||
|
||||
doc_Del="Delete single config item"
|
||||
test_Del() {
|
||||
executeOk_servald config set debug.verbose yes set log.show_pid true
|
||||
executeOk_servald config set debug.verbose yes set log.stderr.show_pid true
|
||||
executeOk_servald config get
|
||||
assertStdoutLineCount '==' 2
|
||||
executeOk_servald config del debug.verbose
|
||||
@ -167,6 +167,12 @@ test_OptionNames() {
|
||||
}
|
||||
|
||||
doc_DebugFlags="Debug config options affect verbosity"
|
||||
setup_DebugFlags() {
|
||||
setup
|
||||
executeOk_servald config \
|
||||
set log.stderr.level debug \
|
||||
set log.stderr.show_pid true
|
||||
}
|
||||
test_DebugFlags() {
|
||||
executeOk_servald echo one two three
|
||||
assertStderrGrep --matches=0 '\<echo:argv\['
|
||||
@ -268,7 +274,7 @@ doc_LogFileAbsolute="Absolute log file"
|
||||
test_LogFileAbsolute() {
|
||||
executeOk_servald config \
|
||||
set debug.verbose true \
|
||||
set log.file "$PWD/log"
|
||||
set log.file_path "$PWD/log"
|
||||
executeOk_servald echo one
|
||||
assertGrep log '^DEBUG:.*echo:argv\[1\]="one"$'
|
||||
assertGrep --matches=0 --message="log contains no error messages" log '^ERROR:'
|
||||
@ -278,7 +284,7 @@ doc_LogFileRelative="Relative log file"
|
||||
test_LogFileRelative() {
|
||||
executeOk_servald config \
|
||||
set debug.verbose true \
|
||||
set log.file "log"
|
||||
set log.file_path "log"
|
||||
executeOk_servald echo one
|
||||
assertGrep "$SERVALINSTANCE_PATH/log" '^DEBUG:.*echo:argv\[1\]="one"$'
|
||||
assertGrep --matches=0 --message="log contains no error messages" "$SERVALINSTANCE_PATH/log" '^ERROR:'
|
||||
|
@ -23,8 +23,8 @@ source "${0%/*}/../testdefs.sh"
|
||||
|
||||
configure_servald_server() {
|
||||
executeOk_servald config \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set rhizome.enable No \
|
||||
set debug.mdprequests Yes
|
||||
}
|
||||
@ -38,7 +38,7 @@ teardown() {
|
||||
is_published() {
|
||||
tfw_log "grep \"PUBLISHED.*$1\" $LOGA"
|
||||
grep "PUBLISHED.*$1" $LOGA || return 1
|
||||
return 0
|
||||
return 0
|
||||
}
|
||||
|
||||
sent_directory_request() {
|
||||
@ -98,8 +98,8 @@ start_routing_instance() {
|
||||
set monitor.socket "org.servalproject.servald.monitor.socket.$TFWUNIQUE.$instance_name" \
|
||||
set mdp.socket "org.servalproject.servald.mdp.socket.$TFWUNIQUE.$instance_name" \
|
||||
set rhizome.enable No \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set debug.mdprequests Yes
|
||||
start_servald_server
|
||||
wait_until interface_up
|
||||
|
@ -43,8 +43,9 @@ teardown() {
|
||||
# process in each instance.
|
||||
configure_servald_server() {
|
||||
executeOk_servald config \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.level debug \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set debug.dnahelper on \
|
||||
set dna.helper.executable "$dnahelper" \
|
||||
set dna.helper.argv.1 "Hello," \
|
||||
|
@ -58,8 +58,9 @@ teardown() {
|
||||
|
||||
set_server_vars() {
|
||||
executeOk_servald config \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.level debug \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set mdp.iftype.wifi.tick_ms 100 \
|
||||
set rhizome.enable No \
|
||||
set debug.overlayinterfaces Yes \
|
||||
|
@ -37,8 +37,8 @@ teardown() {
|
||||
# Called by start_servald_instances for each instance.
|
||||
configure_servald_server() {
|
||||
executeOk_servald config \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set debug.rhizome on \
|
||||
set debug.rhizome_tx on \
|
||||
set debug.rhizome_rx on \
|
||||
@ -450,7 +450,8 @@ setup_direct() {
|
||||
get_rhizome_server_port PORTA +A
|
||||
set_instance +B
|
||||
executeOk_servald config \
|
||||
set log.show_time on \
|
||||
set log.stderr.level debug \
|
||||
set log.stderr.show_time on \
|
||||
set debug.rhizome on \
|
||||
set debug.rhizome_tx on \
|
||||
set debug.rhizome_rx on \
|
||||
|
@ -39,8 +39,8 @@ start_routing_instance() {
|
||||
set server.interface_path "$SERVALD_VAR" \
|
||||
set monitor.socket "org.servalproject.servald.monitor.socket.$TFWUNIQUE.$instance_name" \
|
||||
set mdp.socket "org.servalproject.servald.mdp.socket.$TFWUNIQUE.$instance_name" \
|
||||
set log.show_pid on \
|
||||
set log.show_time on \
|
||||
set log.stderr.show_pid on \
|
||||
set log.stderr.show_time on \
|
||||
set debug.mdprequests Yes \
|
||||
set rhizome.enable no
|
||||
start_servald_server
|
||||
|
@ -53,7 +53,7 @@ test_StartCreateInstanceDir() {
|
||||
doc_StartLogfile="Starting server gives no errors"
|
||||
setup_StartLogfile() {
|
||||
setup
|
||||
executeOk_servald config set log.file "$PWD/log"
|
||||
executeOk_servald config set log.file_path "$PWD/log"
|
||||
}
|
||||
test_StartLogfile() {
|
||||
executeOk $servald start
|
||||
|
Loading…
x
Reference in New Issue
Block a user