ExternalVendorCode/serval-dna
1
0
Fork 0
mirror of https://github.com/servalproject/serval-dna.git synced 2025-04-07 11:08:36 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Improve configuration dump to log

Browse Source 
Refactor much of the new code in log.c

Add new functions: cf_load_strict() and cf_reload_strict() for use by the
server, which does not want to overwrite its in-memory config at all if there
is any defect in the config file.  However, commands always want to overwrite
the default in-memory config, even with a defective config file, so that
logging has a chance to succeed.

Added `log_format.dump_config` boolean config option
This commit is contained in:
Andrew Bettison 2013-03-29 00:22:08 +10:30
parent bcfd032223
commit 2d09ec545e
7 changed files with 286 additions and 203 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
commandline.c
View File

@ -230,7 +230,7 @@ int parseCommandLine(const char *argv0, int argc, const char *const *args)
else {
strbuf b = strbuf_alloca(160);
strbuf_append_argv(b, argc, args);
result = WHYF("configuration unavailable, not running command: %s", strbuf_str(b));
result = WHYF("configuration defective, not running command: %s", strbuf_str(b));
}
} else {
// Load configuration so that "unsupported command" log message can get out

51
conf.c
View File

@ -179,7 +179,7 @@ int cf_init()
return 0;
}
static int reload_and_parse(int permissive)
static int reload_and_parse(int permissive, int strict)
{
int result = CFOK;
if (cf_limbo)
@ -200,47 +200,64 @@ static int reload_and_parse(int permissive)
if (result == CFOK || result == CFEMPTY) {
result = CFOK;
config = new_config;
} else if (result != CFERROR) {
result &= ~CFEMPTY;
} else if (result != CFERROR && !strict) {
result &= ~CFEMPTY; // don't log "empty" as a problem
config = new_config;
WARN("limping along with incomplete configuration");
}
}
}
}
}
// Let log messages out.
cf_limbo = 0;
logFlush();
if (result != CFOK) {
int ret = 1;
if (result == CFOK) {
logConfigChanged();
} else {
strbuf b = strbuf_alloca(180);
strbuf_cf_flag_reason(b, result);
if (!permissive)
return WHYF("config file %s not loaded -- %s", conffile_path(), strbuf_str(b));
WARNF("config file %s loaded despite problems -- %s", conffile_path(), strbuf_str(b));
if (strict)
ret = WHYF("defective config file %s not loaded -- %s", conffile_path(), strbuf_str(b));
else {
if (!permissive)
ret = WHYF("config file %s loaded despite defects -- %s", conffile_path(), strbuf_str(b));
else
WARNF("config file %s loaded despite defects -- %s", conffile_path(), strbuf_str(b));
logConfigChanged();
}
}
logCurrentConfig();
return 1;
cf_limbo = 0; // let log messages out
logFlush();
return ret;
}
int cf_load()
{
conffile_meta = config_meta = FILE_META_UNKNOWN;
return reload_and_parse(0);
return reload_and_parse(0, 0);
}
int cf_load_strict()
{
conffile_meta = config_meta = FILE_META_UNKNOWN;
return reload_and_parse(0, 1);
}
int cf_load_permissive()
{
conffile_meta = config_meta = FILE_META_UNKNOWN;
return reload_and_parse(1);
return reload_and_parse(1, 0);
}
int cf_reload()
{
return reload_and_parse(0);
return reload_and_parse(0, 0);
}
int cf_reload_strict()
{
return reload_and_parse(0, 1);
}
int cf_reload_permissive()
{
return reload_and_parse(1);
return reload_and_parse(1, 0);
}

2
conf.h
View File

@ -647,8 +647,10 @@ extern struct config_main config;
int cf_init();
int cf_load();
int cf_load_strict();
int cf_load_permissive();
int cf_reload();
int cf_reload_strict();
int cf_reload_permissive();
#endif //__SERVALDNA_CONFIG_H

32
conf_schema.h
View File

@ -227,34 +227,38 @@ ATOM(bool_t, externalblobs, 0, boolean,, "")
END_STRUCT
STRUCT(log_format)
ATOM(bool_t, show_pid, 1, boolean,, "If true, all log lines contain PID of logging process")
ATOM(bool_t, show_time, 1, boolean,, "If true, all log lines contain time stamp")
ATOM(int, level, LOG_LEVEL_DEBUG, log_level,, "Only log messages at and above this level of severity")
ATOM(bool_t, show_pid, 1, boolean,, "If true, all log lines contain PID of logging process")
ATOM(bool_t, show_time, 1, boolean,, "If true, all log lines contain time stamp")
ATOM(int, level, LOG_LEVEL_DEBUG, log_level,, "Only log messages at and above this level of severity")
ATOM(bool_t, dump_config, 1, boolean,, "If true, current configuration is dumped into start of log")
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,, full)
SUB_STRUCT(log_format, stderr,, helpful)
SUB_STRUCT(log_format, stderr,, important)
SUB_STRUCT(log_format, android,, android)
END_STRUCT
STRUCT_DEFAULT(log_format, helpful)
ATOM_DEFAULT(show_pid, 0)
ATOM_DEFAULT(show_time, 0)
ATOM_DEFAULT(level, LOG_LEVEL_WARN)
STRUCT_DEFAULT(log_format, important)
ATOM_DEFAULT(show_pid, 0)
ATOM_DEFAULT(show_time, 0)
ATOM_DEFAULT(level, LOG_LEVEL_WARN)
ATOM_DEFAULT(dump_config, 0)
END_STRUCT_DEFAULT
STRUCT_DEFAULT(log_format, full)
ATOM_DEFAULT(show_pid, 1)
ATOM_DEFAULT(show_time, 1)
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
ATOM_DEFAULT(show_pid, 1)
ATOM_DEFAULT(show_time, 1)
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
ATOM_DEFAULT(dump_config, 1)
END_STRUCT_DEFAULT
STRUCT_DEFAULT(log_format, android)
ATOM_DEFAULT(show_pid, 0)
ATOM_DEFAULT(show_time, 1)
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
ATOM_DEFAULT(show_pid, 0)
ATOM_DEFAULT(show_time, 1)
ATOM_DEFAULT(level, LOG_LEVEL_DEBUG)
ATOM_DEFAULT(dump_config, 1)
END_STRUCT_DEFAULT
STRUCT(server)

398
log.c
View File

@ -167,6 +167,10 @@ struct _log_state {
*/
struct tm last_tm;
/* Whether the current configuration has been logged in the current file yet.
*/
bool_t config_logged;
};
struct _log_state state_file;
@ -176,29 +180,58 @@ struct _log_state state_android;
struct _log_state state_stderr;
typedef struct _log_iterator {
int level;
struct __sourceloc whence;
const struct config_log_format *config;
struct _log_state *state;
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)
static void _log_iterator_start(_log_iterator *it)
{
assert(level <= LOG_LEVEL_FATAL);
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)
static int _log_iterator_advance(_log_iterator *it)
{
if (it->config == NULL) {
it->config = &config.log.file;
it->state = &state_file;
return 1;
}
if (it->config == &config.log.file) {
#ifdef ANDROID
it->config = &config.log.android;
it->state = &state_android;
return 1;
}
if (it->config == &config.log.android) {
#endif // ANDROID
it->config = &config.log.stderr;
it->state = &state_stderr;
return 1;
}
return 0;
}
static int _log_enabled(_log_iterator *it)
{
if (it->config == &config.log.file) {
_open_log_file(); // puts initial INFO message at start of log file
if (logfile_file == NO_FILE)
return 0;
}
else if (it->config == &config.log.stderr) {
_open_log_stderr();
if (logfile_stderr == NULL || logfile_stderr == NO_FILE)
return 0;
}
return 1;
}
static void _log_prefix_level(_log_iterator *it, int level)
{
const char *levelstr = "UNKWN:";
switch (level) {
@ -211,37 +244,31 @@ static void _log_level_prefix(_log_iterator *it, int level)
xprintf(it->xpf, "%-6.6s", levelstr);
}
static int _log_prefix(const struct config_log_format *cfg, _log_iterator *it, int level)
static void _log_prefix(_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 (it->config == &config.log.file) {
if (strbuf_is_empty(&logbuf))
strbuf_init(&logbuf, _log_buf, sizeof _log_buf);
else if (strbuf_len(&logbuf))
strbuf_putc(&logbuf, '\n');
it->xpf = XPRINTF_STRBUF(&logbuf);
_log_level_prefix(it, level);
_log_prefix_level(it, level);
}
#ifdef ANDROID
else if (cfg == &config.log.android) {
else if (it->config == &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;
else if (it->config == &config.log.stderr) {
it->xpf = XPRINTF_STDIO(logfile_stderr);
_log_level_prefix(it, level);
_log_prefix_level(it, level);
}
else
abort();
if (cfg->show_pid)
if (it->config->show_pid)
xprintf(it->xpf, "[%5u] ", getpid());
if (cfg->show_time) {
if (it->config->show_time) {
if (it->tv.tv_sec == 0) {
xputs("NOTIME______ ", it->xpf);
} else {
@ -252,210 +279,243 @@ static int _log_prefix(const struct config_log_format *cfg, _log_iterator *it, i
xprintf(it->xpf, "%s.%03u ", buf, it->tv.tv_usec / 1000);
}
}
return 1;
}
static void _log_finish(const struct config_log_format *cfg, _log_iterator *it, int level)
static void _log_prefix_whence(_log_iterator *it, struct __sourceloc whence)
{
if (cfg == &config.log.file) {
_flush_log_file();
if (whence.file) {
xprintf(it->xpf, "%s", _trimbuildpath(whence.file));
if (whence.line)
xprintf(it->xpf, ":%u", whence.line);
if (whence.function)
xprintf(it->xpf, ":%s()", whence.function);
xputs(" ", it->xpf);
} else if (whence.function) {
xprintf(it->xpf, "%s() ", whence.function);
}
}
static void _log_end_line(_log_iterator *it, int level)
{
#ifdef ANDROID
else if (cfg == &config.log.android) {
if (it->config == &config.log.android) {
int alevel = ANDROID_LOG_UNKNOWN;
switch (it->level) {
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();
}
__android_log_print(alevel, "servald", "%s", strbuf_str(_log_buf_android));
}
#endif // ANDROID
else if (cfg == &config.log.stderr) {
fputc('\n', logfile_stderr);
_flush_log_stderr();
}
else
abort();
#endif // ANDROID
if (it->config == &config.log.stderr) {
fputc('\n', logfile_stderr);
}
}
static int _log_prepare(const struct config_log_format *cfg, struct _log_state *state, _log_iterator *it)
static void _log_flush(_log_iterator *it)
{
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 (it->config == &config.log.file) {
_flush_log_file();
}
else if (it->config == &config.log.stderr) {
_flush_log_stderr();
}
}
static void _log_vprintf_nl(_log_iterator *it, int level, const char *fmt, va_list ap)
{
_log_prefix(it, level);
vxprintf(it->xpf, fmt, ap);
_log_end_line(it, level);
}
static void _log_printf_nl(_log_iterator *it, int level, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
_log_vprintf_nl(it, level, fmt, ap);
va_end(ap);
}
static int _log_current_config(_log_iterator *it, int level)
{
if (!cf_limbo) {
struct cf_om_node *root = NULL;
int ret = cf_fmt_config_main(&root, &config);
if (ret == CFERROR) {
_log_printf_nl(it, level, "Cannot dump current configuration: cf_fmt_config_main() returned CFERROR");
} else {
_log_printf_nl(it, level, "Current configuration:");
struct cf_om_iterator oit;
int empty = 1;
for (cf_om_iter_start(&oit, root); oit.node; cf_om_iter_next(&oit)) {
if (oit.node->text && oit.node->line_number) {
empty = 0;
_log_printf_nl(it, level, " %s=%s", oit.node->fullkey, oit.node->text);
}
}
if (empty)
_log_printf_nl(it, level, " (empty)");
}
}
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);
cf_om_free_node(&root);
it->state->config_logged = 1;
}
return 1;
}
static int _log_iterator_next(_log_iterator *it)
static void _log_update(_log_iterator *it)
{
if (it->_file == 0) {
if (_log_prepare(&config.log.file, &state_file, it)) {
it->_file = 1;
return 1;
if ( it->tm.tm_mday != it->state->last_tm.tm_mday
|| it->tm.tm_mon != it->state->last_tm.tm_mon
|| it->tm.tm_year != it->state->last_tm.tm_year
) {
char buf[50];
if (strftime(buf, sizeof buf, "%F %T %z", &it->tm)) {
_log_printf_nl(it, LOG_LEVEL_INFO, "Local date/time: %s", buf);
it->state->last_tm = it->tm;
}
}
else if (it->_file == 1) {
_log_finish(&config.log.file, it, it->level);
if (!it->state->version_logged) {
_log_printf_nl(it, LOG_LEVEL_INFO, "Serval DNA version: %s", version_servald);
it->state->version_logged = 1;
}
it->_file = 2;
#ifdef ANDROID
if (it->_android == 0) {
if (_log_prepare(&config.log.android, &state_android, it)) {
it->_android = 1;
return 1;
if (it->config->dump_config && !it->state->config_logged) {
_log_current_config(it, LOG_LEVEL_INFO);
}
}
static int _log_iterator_next(_log_iterator *it, int level)
{
assert(level >= LOG_LEVEL_SILENT);
assert(level <= LOG_LEVEL_FATAL);
_log_end_line(it, level);
_log_flush(it);
while (_log_iterator_advance(it)) {
if (_log_enabled(it)) {
_log_update(it);
if (level >= it->config->level) {
_log_prefix(it, level);
return 1;
}
_log_flush(it);
}
}
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()
{
_flush_log_file();
_flush_log_stderr();
_log_iterator it;
_log_iterator_start(&it);
while (_log_iterator_next(&it, LOG_LEVEL_SILENT))
;
}
void logArgv(int level, struct __sourceloc whence, const char *label, int argc, const char *const *argv)
{
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) {
xputs(label, it.xpf);
xputc(' ', it.xpf);
if (level != LOG_LEVEL_SILENT) {
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);
while (_log_iterator_next(&it, level)) {
_log_prefix_whence(&it, whence);
if (label) {
xputs(label, it.xpf);
xputc(' ', it.xpf);
}
xputs(strbuf_str(&b), it.xpf);
}
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') {
_log_iterator_start(&it, level, whence);
while (_log_iterator_next(&it))
xprintf(it.xpf, "%.*s", p - s, s);
s = p + 1;
if (level != LOG_LEVEL_SILENT) {
_log_iterator it;
const char *s = str;
const char *p;
for (p = str; *p; ++p) {
if (*p == '\n') {
_log_iterator_start(&it);
while (_log_iterator_next(&it, level)) {
_log_prefix_whence(&it, whence);
xprintf(it.xpf, "%.*s", p - s, s);
}
s = p + 1;
}
}
if (p > s) {
_log_iterator_start(&it);
while (_log_iterator_next(&it, level)) {
_log_prefix_whence(&it, whence);
xprintf(it.xpf, "%.*s", p - s, s);
}
}
}
if (p > s) {
_log_iterator_start(&it, level, whence);
while (_log_iterator_next(&it))
xprintf(it.xpf, "%.*s", p - s, s);
}
}
void logMessage(int level, struct __sourceloc whence, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
vlogMessage(level, whence, fmt, ap);
va_end(ap);
if (level != LOG_LEVEL_SILENT) {
va_list ap;
va_start(ap, fmt);
vlogMessage(level, whence, fmt, ap);
va_end(ap);
}
}
void vlogMessage(int level, struct __sourceloc whence, const char *fmt, va_list ap)
{
_log_iterator it;
_log_iterator_start(&it, level, whence);
while (_log_iterator_next(&it))
vxprintf(it.xpf, fmt, ap);
}
void logCurrentConfig()
{
struct cf_om_node *root = NULL;
int ret = cf_fmt_config_main(&root, &config);
if (ret == CFERROR) {
cf_om_free_node(&root);
WHY("cannot log current config");
} else {
struct cf_om_iterator it;
logMessage(LOG_LEVEL_INFO, __NOWHERE__, "Current configuration:");
for (cf_om_iter_start(&it, root); it.node; cf_om_iter_next(&it)) {
if (it.node->text && it.node->line_number)
logMessage(LOG_LEVEL_INFO, __NOWHERE__, " %s=%s", it.node->fullkey, it.node->text);
if (level != LOG_LEVEL_SILENT) {
_log_iterator it;
_log_iterator_start(&it);
while (_log_iterator_next(&it, level)) {
_log_prefix_whence(&it, whence);
vxprintf(it.xpf, fmt, ap);
}
}
}
void logConfigChanged()
{
state_file.config_logged = 0;
#ifdef ANDROID
state_android.config_logged = 0;
#endif
state_stderr.config_logged = 0;
logFlush();
}
int logDump(int level, struct __sourceloc whence, char *name, const unsigned char *addr, size_t len)
{
char buf[100];
size_t i;
if (name)
logMessage(level, whence, "Dump of %s", name);
for(i = 0; i < len; i += 16) {
strbuf b = strbuf_local(buf, sizeof buf);
strbuf_sprintf(b, " %04x :", i);
int j;
for (j = 0; j < 16 && i + j < len; j++)
strbuf_sprintf(b, " %02x", addr[i + j]);
for (; j < 16; j++)
strbuf_puts(b, " ");
strbuf_puts(b, " ");
for (j = 0; j < 16 && i + j < len; j++)
strbuf_sprintf(b, "%c", addr[i+j] >= ' ' && addr[i+j] < 0x7f ? addr[i+j] : '.');
logMessage(level, whence, "%s", strbuf_str(b));
if (level != LOG_LEVEL_SILENT) {
char buf[100];
size_t i;
if (name)
logMessage(level, whence, "Dump of %s", name);
for(i = 0; i < len; i += 16) {
strbuf b = strbuf_local(buf, sizeof buf);
strbuf_sprintf(b, " %04x :", i);
int j;
for (j = 0; j < 16 && i + j < len; j++)
strbuf_sprintf(b, " %02x", addr[i + j]);
for (; j < 16; j++)
strbuf_puts(b, " ");
strbuf_puts(b, " ");
for (j = 0; j < 16 && i + j < len; j++)
strbuf_sprintf(b, "%c", addr[i+j] >= ' ' && addr[i+j] < 0x7f ? addr[i+j] : '.');
logMessage(level, whence, "%s", strbuf_str(b));
}
}
return 0;
}

2
log.h
View File

@ -94,7 +94,7 @@ void logArgv(int level, struct __sourceloc whence, const char *label, int argc,
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 logCurrentConfig();
void logConfigChanged();
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);

2
server.c
View File

@ -140,7 +140,7 @@ int server(char *backing_file)
*/
void server_config_reload(struct sched_ent *alarm)
{
switch (cf_reload()) {
switch (cf_reload_strict()) {
case -1:
WARN("server continuing with prior config");
break;