From f7fc63c452211f1c73832a503099b966c45a52f8 Mon Sep 17 00:00:00 2001 From: Andrew Bettison Date: Fri, 5 Apr 2013 16:23:20 +1030 Subject: [PATCH] Improve logging tests, fix failures, add 'log.file.path' config option --- conf_schema.h | 1 + log.c | 12 ++++++--- tests/all | 1 + tests/config | 20 -------------- tests/logging | 73 ++++++++++++++++++++++++++++++++++++++++++++++++--- 5 files changed, 80 insertions(+), 27 deletions(-) diff --git a/conf_schema.h b/conf_schema.h index 6c34d1e5..d5fe7ec3 100644 --- a/conf_schema.h +++ b/conf_schema.h @@ -276,6 +276,7 @@ END_STRUCT STRUCT(log_format_file) STRING(256, directory_path, "log", str_nonempty,, "Path of directory for log files, either absolute or relative to instance directory") +STRING(256, path, "", str_nonempty,, "Path of single log file, either absolute or relative to directory_path") ATOM(unsigned short, rotate, 12, ushort,, "Number of log files to rotate, zero means no deletion") ATOM(uint32_t, duration, 3600, uint32_time_interval,, "Time duration of each log file, zero means one file per invocation") LOG_FORMAT_OPTIONS diff --git a/log.c b/log.c index 679ffbf4..1fc2fae1 100644 --- a/log.c +++ b/log.c @@ -449,9 +449,13 @@ static void _open_log_file(_log_iterator *it) strbuf sbfile = strbuf_local(_log_file_path_buf, sizeof _log_file_path_buf); strbuf_path_join(sbfile, serval_instancepath(), log_file_directory_path(), NULL); _compute_file_start_time(it); - struct tm tm; - (void)localtime_r(&it->file_start_time, &tm); - strbuf_append_strftime(sbfile, "/serval-%Y%m%d%H%M%S.log", &tm); + if (config.log.file.path[0]) { + strbuf_path_join(sbfile, config.log.file.path, NULL); + } else { + struct tm tm; + (void)localtime_r(&it->file_start_time, &tm); + strbuf_append_strftime(sbfile, "/serval-%Y%m%d%H%M%S.log", &tm); + } if (strbuf_overrun(sbfile)) { _log_file = NO_FILE; _logs_printf_nl(LOG_LEVEL_ERROR, __HERE__, "Cannot form log file name - buffer overrun"); @@ -563,7 +567,7 @@ static void _rotate_log_file(_log_iterator *it) { if (_log_file != NO_FILE && _log_file_path == _log_file_path_buf) { assert(!cf_limbo); - if (config.log.file.duration) { + if (!config.log.file.path[0] && config.log.file.duration) { _compute_file_start_time(it); if (it->file_start_time != _log_file_start_time) { // Close the current log file, which will cause _open_log_file() to open the next one. diff --git a/tests/all b/tests/all index 7470e3d5..a4ee0fec 100755 --- a/tests/all +++ b/tests/all @@ -20,6 +20,7 @@ source "${0%/*}/../testframework.sh" +includeTests logging includeTests config includeTests keyring includeTests server diff --git a/tests/config b/tests/config index 41704b77..efbdbc35 100755 --- a/tests/config +++ b/tests/config @@ -270,24 +270,4 @@ test_InterfacesModernIncompatible() { --error-pattern='config file.*loaded despite defects.*incompatible' } -doc_LogFileAbsolute="Absolute log file directory" -test_LogFileAbsolute() { - executeOk_servald config \ - set debug.verbose true \ - set log.file.directory_path "$PWD/wakawaka" - executeOk_servald echo one - assert --message="exactly one log file" [ $(ls -d wakawaka/*.log | wc -l) -eq 1 ] - assertGrep wakawaka/*.log '^DEBUG:.*echo:argv\[1\]="one"$' -} - -doc_LogFileRelative="Relative log file directory" -test_LogFileRelative() { - executeOk_servald config \ - set debug.verbose true \ - set log.file.directory_path "blah" - executeOk_servald echo one - assert --message="exactly one log file" [ $(ls -d "$SERVALINSTANCE_PATH/blah/"*.log | wc -l) -eq 1 ] - assertGrep "$SERVALINSTANCE_PATH/blah/"*.log '^DEBUG:.*echo:argv\[1\]="one"$' -} - runTests "$@" diff --git a/tests/logging b/tests/logging index 3225a574..1b76b668 100755 --- a/tests/logging +++ b/tests/logging @@ -68,7 +68,7 @@ test_LogStderrConfigNone() { doc_LogFileDefault="By Default, all messages are appended to a configured file" test_LogFileDefault() { executeOk_servald config set log.stderr.level none - executeOk_servald config set log.file_path "$PWD/log.txt" + executeOk_servald config set log.file.path "$PWD/log.txt" executeOk_servald log error 'hoopla' assertGrep --matches=1 log.txt '^ERROR:.*hoopla$' executeOk_servald log warn 'buckle' @@ -89,7 +89,7 @@ doc_LogFileConfigLevel="Configure level of messages appended to a configured fil test_LogFileConfigLevel() { executeOk_servald config set log.stderr.level none executeOk_servald config set log.file.level info - executeOk_servald config set log.file_path "$PWD/log.txt" + executeOk_servald config set log.file.path "$PWD/log.txt" executeOk_servald log warn 'buckle' assertGrep --matches=1 log.txt '^WARN:.*buckle$' executeOk_servald log debug 'eccles' @@ -108,7 +108,7 @@ test_LogFileConfigLevel() { doc_LogFileStderrFile="Log messages to stderr and a configured file" test_LogFileStderrFile() { - executeOk_servald config set log.file_path "$PWD/log.txt" + executeOk_servald config set log.file.path "$PWD/log.txt" executeOk_servald log info 'lymph' assertGrep --matches=1 log.txt 'INFO:.*lymph$' assertStderrIs '' @@ -130,4 +130,71 @@ test_LogFileStderrFile() { assertGrep --matches=1 log.txt '^ERROR:.*hoopla$' } +doc_LogFileRotation="Log file rotation and deletion" +test_LogFileRotation() { + executeOk_servald config \ + set log.file.directory_path "$PWD" \ + set log.file.rotate 3 \ + set log.file.duration 2s + assert --message="no log files yet" [ $(ls *.log | wc -l) -eq 0 ] + executeOk_servald log info one + assert --message="one log file" [ $(ls *.log | wc -l) -eq 1 ] + log1=*.log + sleep 2.1 + executeOk_servald log info two + assert --message="two log files" [ $(ls *.log | wc -l) -eq 2 ] + log2=$(ls *.log | tail -n 1) + assert --message="ascending log file name" [ "$log2" != "$log1" ] + sleep 2.1 + executeOk_servald log info three + assert --message="three log files" [ $(ls *.log | wc -l) -eq 3 ] + log3=$(ls *.log | tail -n 1) + assert --message="ascending log file name" [ "$log3" != "$log1" -a "$log3" != "$log2" ] + sleep 2.1 + executeOk_servald log info four + assert --message="three log files" [ $(ls *.log | wc -l) -eq 3 ] + assert --message="first log file gone" ! [ -e $log1 ] + log4=$(ls *.log | tail -n 1) + assert --message="ascending log file name" [ "$log4" != "$log2" -a "$log4" != "$log3" -a "$log4" != "$log1" ] +} + +doc_LogFileDirectoryAbsolute="Absolute log file directory path" +test_LogFileDirectoryAbsolute() { + executeOk_servald config \ + set debug.verbose true \ + set log.file.directory_path "$PWD/wakawaka" + executeOk_servald echo one + assert --message="exactly one log file" [ $(ls -d wakawaka/*.log | wc -l) -eq 1 ] + assertGrep wakawaka/*.log '^DEBUG:.*echo:argv\[1\]="one"$' +} + +doc_LogFileDirectoryRelative="Relative log file directory path" +test_LogFileDirectoryRelative() { + executeOk_servald config \ + set debug.verbose true \ + set log.file.directory_path "blah" + executeOk_servald echo one + assert --message="exactly one log file" [ $(ls -d "$SERVALINSTANCE_PATH/blah/"*.log | wc -l) -eq 1 ] + assertGrep "$SERVALINSTANCE_PATH/blah/"*.log '^DEBUG:.*echo:argv\[1\]="one"$' +} + +doc_LogFileAbsolute="Absolute log file path" +test_LogFileAbsolute() { + executeOk_servald config \ + set debug.verbose true \ + set log.file.path "$PWD/log.txt" + executeOk_servald echo one + assertGrep log.txt '^DEBUG:.*echo:argv\[1\]="one"$' +} + +doc_LogFileRelative="Relative log file path" +test_LogFileRelative() { + executeOk_servald config \ + set debug.verbose true \ + set log.file.directory_path "$PWD" \ + set log.file.path "log.txt" + executeOk_servald echo one + assertGrep log.txt '^DEBUG:.*echo:argv\[1\]="one"$' +} + runTests "$@"