From 599a61eea6aa60c8b8e1ecaa027642f5ebe8331c Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Tue, 25 Aug 2020 21:46:15 +1000 Subject: [PATCH 1/7] Print full date and time in logs Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 17 ++++++----------- 1 file changed, 6 insertions(+), 11 deletions(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index 04b180c..274dc43 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -178,17 +178,12 @@ void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) #define MAX_RTPPRINTF_BUFFER_SIZE (1024) char s[MAX_RTPPRINTF_BUFFER_SIZE+1]; #undef MAX_RTPPRINTF_BUFFER_SIZE - if (level == TURN_LOG_LEVEL_ERROR) { - snprintf(s,sizeof(s)-100,"%lu: ERROR: ",(unsigned long)log_time()); - size_t slen = strlen(s); - vsnprintf(s+slen,sizeof(s)-slen-1,format, args); - fwrite(s,strlen(s),1,stdout); - } else if(!no_stdout_log) { - snprintf(s,sizeof(s)-100,"%lu: ",(unsigned long)log_time()); - size_t slen = strlen(s); - vsnprintf(s+slen,sizeof(s)-slen-1,format, args); - fwrite(s,strlen(s),1,stdout); - } + struct tm local_now = localtime(time(NULL)); + strptime(s, sizeof(s)-100, "%Y-%m-%dT%H:%M:%S", &local_now); + snprintf(s + 19,sizeof(s)-100,(level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); + size_t slen = strlen(s); + vsnprintf(s+slen,sizeof(s)-slen-1,format, args); + fwrite(s,strlen(s),1,stdout); #endif va_end(args); } From 762ee2348210a5481e00673e3696d0acf84a1f6d Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Wed, 26 Aug 2020 21:05:08 +1000 Subject: [PATCH 2/7] Fixing a few errors - C still coming back to me Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index 274dc43..dde543f 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -178,8 +178,8 @@ void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) #define MAX_RTPPRINTF_BUFFER_SIZE (1024) char s[MAX_RTPPRINTF_BUFFER_SIZE+1]; #undef MAX_RTPPRINTF_BUFFER_SIZE - struct tm local_now = localtime(time(NULL)); - strptime(s, sizeof(s)-100, "%Y-%m-%dT%H:%M:%S", &local_now); + time_t now = time(NULL); + strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); snprintf(s + 19,sizeof(s)-100,(level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); size_t slen = strlen(s); vsnprintf(s+slen,sizeof(s)-slen-1,format, args); From 16eeb53e079c973e0254d5ec97444e000c0ff591 Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Mon, 31 Aug 2020 22:34:54 +1000 Subject: [PATCH 3/7] Allow new log format to be turned on if required This provides the 'use_new_timestamp_log_format' variable in `ns_turn_utils.h`. By default it is set to 0 and the old 'seconds since daemon was started' timestamp will be emitted. However, if it is set to 1 or any 'true' number the new date and time timestamp format will be used instead. This has also resulted in a small clean-up of some of the string length handling. Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 18 ++++++++++++------ src/apps/common/ns_turn_utils.h | 1 + 2 files changed, 13 insertions(+), 6 deletions(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index dde543f..ee3c8bf 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -158,6 +158,8 @@ void set_no_stdout_log(int val) no_stdout_log = val; } +int use_new_log_timestamp_format = 0; + void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) { #if !defined(TURN_LOG_FUNC_IMPL) @@ -178,12 +180,16 @@ void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) #define MAX_RTPPRINTF_BUFFER_SIZE (1024) char s[MAX_RTPPRINTF_BUFFER_SIZE+1]; #undef MAX_RTPPRINTF_BUFFER_SIZE - time_t now = time(NULL); - strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); - snprintf(s + 19,sizeof(s)-100,(level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); - size_t slen = strlen(s); - vsnprintf(s+slen,sizeof(s)-slen-1,format, args); - fwrite(s,strlen(s),1,stdout); + size_t so_far = 0; + if (use_new_log_timestamp_format) { + time_t now = time(NULL); + so_far += strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); + } else { + so_far += snprintf(s, sizeof(s), "%lu: ", (unsigned long)log_time()); + } + so_far += snprintf(s + so_far, sizeof(s)-100, (level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); + so_far += vsnprintf(s + so_far,sizeof(s) - (so_far+1), format, args); + fwrite(s, so_far, 1, stdout); #endif va_end(args); } diff --git a/src/apps/common/ns_turn_utils.h b/src/apps/common/ns_turn_utils.h index 77ade9a..8aabae0 100644 --- a/src/apps/common/ns_turn_utils.h +++ b/src/apps/common/ns_turn_utils.h @@ -69,6 +69,7 @@ void addr_debug_print(int verbose, const ioa_addr *addr, const char* s); extern volatile int _log_time_value_set; extern volatile turn_time_t _log_time_value; +extern int use_new_log_timestamp_format; void rtpprintf(const char *format, ...); int vrtpprintf(TURN_LOG_LEVEL level, const char *format, va_list args); From 5e87c444693b39e11cabc498450dacbef30ec64a Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Tue, 1 Sep 2020 18:35:01 +1000 Subject: [PATCH 4/7] Merge turn_log_func_default and vrtpprintf The function `turn_log_func_default` calls the function `vrtpprintf` to print to syslog or the log file. The latter does exactly the same string formatting as the former, so here we merge the two functions into one to do the string formatting once. This also makes sure that the log line is consistent on all outputs. Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 73 +++++++++------------------------ 1 file changed, 20 insertions(+), 53 deletions(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index ee3c8bf..0007a55 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -160,41 +160,6 @@ void set_no_stdout_log(int val) int use_new_log_timestamp_format = 0; -void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) -{ -#if !defined(TURN_LOG_FUNC_IMPL) - { - va_list args; - va_start(args,format); - vrtpprintf(level, format, args); - va_end(args); - } -#endif - - { - va_list args; - va_start(args,format); -#if defined(TURN_LOG_FUNC_IMPL) - TURN_LOG_FUNC_IMPL(level,format,args); -#else -#define MAX_RTPPRINTF_BUFFER_SIZE (1024) - char s[MAX_RTPPRINTF_BUFFER_SIZE+1]; -#undef MAX_RTPPRINTF_BUFFER_SIZE - size_t so_far = 0; - if (use_new_log_timestamp_format) { - time_t now = time(NULL); - so_far += strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); - } else { - so_far += snprintf(s, sizeof(s), "%lu: ", (unsigned long)log_time()); - } - so_far += snprintf(s + so_far, sizeof(s)-100, (level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); - so_far += vsnprintf(s + so_far,sizeof(s) - (so_far+1), format, args); - fwrite(s, so_far, 1, stdout); -#endif - va_end(args); - } -} - void addr_debug_print(int verbose, const ioa_addr *addr, const char* s) { if (verbose) { @@ -513,20 +478,29 @@ static int get_syslog_level(TURN_LOG_LEVEL level) return LOG_INFO; } -int vrtpprintf(TURN_LOG_LEVEL level, const char *format, va_list args) +void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) { + va_list args; + va_start(args,format); +#if defined(TURN_LOG_FUNC_IMPL) + TURN_LOG_FUNC_IMPL(level,format,args); +#else /* Fix for Issue 24, raised by John Selbie: */ #define MAX_RTPPRINTF_BUFFER_SIZE (1024) char s[MAX_RTPPRINTF_BUFFER_SIZE+1]; #undef MAX_RTPPRINTF_BUFFER_SIZE - - size_t sz; - - snprintf(s, sizeof(s), "%lu: ",(unsigned long)log_time()); - sz=strlen(s); - vsnprintf(s+sz, sizeof(s)-1-sz, format, args); - s[sizeof(s)-1]=0; - + size_t so_far = 0; + if (use_new_log_timestamp_format) { + time_t now = time(NULL); + so_far += strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); + } else { + so_far += snprintf(s, sizeof(s), "%lu: ", (unsigned long)log_time()); + } + so_far += snprintf(s + so_far, sizeof(s)-100, (level == TURN_LOG_LEVEL_ERROR) ? ": ERROR: " : ": "); + so_far += vsnprintf(s + so_far,sizeof(s) - (so_far+1), format, args); + /* always write to stdout */ + fwrite(s, so_far, 1, stdout); + /* write to syslog or to log file */ if(to_syslog) { syslog(get_syslog_level(level),"%s",s); } else { @@ -539,16 +513,9 @@ int vrtpprintf(TURN_LOG_LEVEL level, const char *format, va_list args) } log_unlock(); } +#endif + va_end(args); - return 0; -} - -void rtpprintf(const char *format, ...) -{ - va_list args; - va_start (args, format); - vrtpprintf(TURN_LOG_LEVEL_INFO, format, args); - va_end (args); } ///////////// ORIGIN /////////////////// From f59e9f8ad429da71ec2147915ea652e6b9891b9d Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Tue, 1 Sep 2020 18:43:56 +1000 Subject: [PATCH 5/7] Allow the log timestamp format to be set This allows the timestamp format in log output to be set by a function. Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 10 +++++++++- src/apps/common/ns_turn_utils.h | 2 ++ 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index 0007a55..1f5570d 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -158,6 +158,14 @@ void set_no_stdout_log(int val) no_stdout_log = val; } +#define MAX_LOG_TIMESTAMP_FORMAT_LEN 48 +static char turn_log_timestamp_format[MAX_LOG_TIMESTAMP_FORMAT_LEN] = "%Y-%m-%dT%H:%M:%S"; + +void set_turn_log_timestamp_format(char* new_format) +{ + strncpy(turn_log_timestamp_format, new_format, MAX_LOG_TIMESTAMP_FORMAT_LEN-1); +} + int use_new_log_timestamp_format = 0; void addr_debug_print(int verbose, const ioa_addr *addr, const char* s) @@ -492,7 +500,7 @@ void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...) size_t so_far = 0; if (use_new_log_timestamp_format) { time_t now = time(NULL); - so_far += strftime(s, sizeof(s), "%Y-%m-%dT%H:%M:%S", localtime(&now)); + so_far += strftime(s, sizeof(s), turn_log_timestamp_format, localtime(&now)); } else { so_far += snprintf(s, sizeof(s), "%lu: ", (unsigned long)log_time()); } diff --git a/src/apps/common/ns_turn_utils.h b/src/apps/common/ns_turn_utils.h index 8aabae0..d9e9488 100644 --- a/src/apps/common/ns_turn_utils.h +++ b/src/apps/common/ns_turn_utils.h @@ -61,6 +61,8 @@ void set_no_stdout_log(int val); void set_log_to_syslog(int val); void set_simple_log(int val); +void set_turn_log_timestamp_format(char* new_format); + void turn_log_func_default(TURN_LOG_LEVEL level, const char* format, ...); void addr_debug_print(int verbose, const ioa_addr *addr, const char* s); From ed88f1605ae6deada2045842a66aafae08fd1578 Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Tue, 1 Sep 2020 20:57:54 +1000 Subject: [PATCH 6/7] Neater ISO-8601 timestamp format string Signed-off-by: Paul Wayper --- src/apps/common/ns_turn_utils.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/apps/common/ns_turn_utils.c b/src/apps/common/ns_turn_utils.c index 1f5570d..7022eda 100644 --- a/src/apps/common/ns_turn_utils.c +++ b/src/apps/common/ns_turn_utils.c @@ -159,7 +159,7 @@ void set_no_stdout_log(int val) } #define MAX_LOG_TIMESTAMP_FORMAT_LEN 48 -static char turn_log_timestamp_format[MAX_LOG_TIMESTAMP_FORMAT_LEN] = "%Y-%m-%dT%H:%M:%S"; +static char turn_log_timestamp_format[MAX_LOG_TIMESTAMP_FORMAT_LEN] = "%FT%T%z"; void set_turn_log_timestamp_format(char* new_format) { From c315c288bd2f52155b27598803933aa89238218d Mon Sep 17 00:00:00 2001 From: Paul Wayper Date: Tue, 1 Sep 2020 21:01:28 +1000 Subject: [PATCH 7/7] Add options for new log timestamp and setting timestamp format This adds the `--new-log-timestamp` and `--new-timestamp-format ` options to the `turnserver` program. Setting `--new-log-timestamp` on the command line, or `new-log-timestamp` in the configuration file, will cause all logs to be written with an ISI-8601 timestamp (`YYYY-MM-DDTHH:MM:SSZZZZZ` with `T` being literal and `ZZZZZ` being `+` or `-` and the hour and minute offset from GMT for the local timezone). This replaces the 'number of seconds since daemon was started' format. Setting the `--new-timestamp-format ` option with a given format, or `new-log-timestamp=` in the configuration file, will use this instead of the standard timestamp format. Timestamp format strings up to 48 characters can be accommodated; more will be truncated. This will only be used when the `--new-log-timestamp` option (above) is set. Thanks to Hendrik Huels for the idea and some of the code for setting the log timestamp string. Signed-off-by: Paul Wayper --- src/apps/relay/mainrelay.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/apps/relay/mainrelay.c b/src/apps/relay/mainrelay.c index 0aabb3b..d0134f2 100644 --- a/src/apps/relay/mainrelay.c +++ b/src/apps/relay/mainrelay.c @@ -603,6 +603,8 @@ static char Usage[] = "Usage: turnserver [options]\n" " --simple-log This flag means that no log file rollover will be used, and the log file\n" " name will be constructed as-is, without PID and date appendage.\n" " This option can be used, for example, together with the logrotate tool.\n" +" --new-log-timestamp Enable full ISO-8601 timestamp in all logs.\n" +" --new-timestamp_format Set timestamp format (in strftime(1) format)\n" " --stale-nonce[=] Use extra security with nonce value having limited lifetime (default 600 secs).\n" " --max-allocate-lifetime Set the maximum value for the allocation lifetime. Default to 3600 secs.\n" " --channel-lifetime Set the lifetime for channel binding, default to 600 secs.\n" @@ -761,6 +763,8 @@ enum EXTRA_OPTS { NO_STDOUT_LOG_OPT, SYSLOG_OPT, SIMPLE_LOG_OPT, + NEW_LOG_TIMESTAMP_OPT, + NEW_TIMESTAMP_FORMAT_OPT, AUX_SERVER_OPT, UDP_SELF_BALANCE_OPT, ALTERNATE_SERVER_OPT, @@ -899,6 +903,8 @@ static const struct myoption long_options[] = { { "no-stdout-log", optional_argument, NULL, NO_STDOUT_LOG_OPT }, { "syslog", optional_argument, NULL, SYSLOG_OPT }, { "simple-log", optional_argument, NULL, SIMPLE_LOG_OPT }, + { "new-log-timestamp", optional_argument, NULL, NEW_LOG_TIMESTAMP_OPT }, + { "new-timestamp_format", required_argument, NULL, NEW_TIMESTAMP_FORMAT_OPT }, { "aux-server", required_argument, NULL, AUX_SERVER_OPT }, { "udp-self-balance", optional_argument, NULL, UDP_SELF_BALANCE_OPT }, { "alternate-server", required_argument, NULL, ALTERNATE_SERVER_OPT }, @@ -1717,6 +1723,10 @@ static void read_config_file(int argc, char **argv, int pass) set_log_to_syslog(get_bool_value(value)); } else if((pass==0) && (c==SIMPLE_LOG_OPT)) { set_simple_log(get_bool_value(value)); + } else if ((pass==0) && (c==NEW_LOG_TIMESTAMP_OPT)) { + use_new_log_timestamp_format=1; + } else if ((pass==0) && (c==NEW_TIMESTAMP_FORMAT_OPT)) { + set_turn_log_timestamp_format(value); } else if((pass == 0) && (c != 'u')) { set_option(c, value); } else if((pass > 0) && (c == 'u')) {