Merge pull request #618 from PaulWay/paulway_log_real_time

Print full date and time in logs

src/apps/common/ns_turn_utils.c

@@ -158,42 +158,16 @@ void set_no_stdout_log(int val)
 	no_stdout_log = val;
 }
 
-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
+#define MAX_LOG_TIMESTAMP_FORMAT_LEN 48
+static char turn_log_timestamp_format[MAX_LOG_TIMESTAMP_FORMAT_LEN] = "%FT%T%z";
 
-	{
-		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
-		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);
-		}
-#endif
-		va_end(args);
-	}
+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)
 {
 	if (verbose) {
@@ -512,20 +486,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), turn_log_timestamp_format, 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 {
@@ -538,16 +521,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 ///////////////////

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);
@@ -69,6 +71,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);

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    	<format>	Set timestamp format (in strftime(1) format)\n"
 " --stale-nonce[=<value>]			Use extra security with nonce value having limited lifetime (default 600 secs).\n"
 " --max-allocate-lifetime	<value>		Set the maximum value for the allocation lifetime. Default to 3600 secs.\n"
 " --channel-lifetime		<value>		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')) {