file-logger: Add option to print milliseconds within the current second after timestamp

For this to look right time_format should end with %S or %T.

Closes strongswan/strongswan#18.

conf/options/charon-logging.opt

@@ -28,6 +28,10 @@ charon.filelog.<filename>.time_format
 	Prefix each log entry with a timestamp. The option accepts a format string
 	as passed to **strftime**(3).
 
+charon.filelog.<filename>.time_add_ms = no
+	Adds the milliseconds within the current second after the timestamp
+	(separated by a dot, so _time_format_ should end with %S or %T).
+
 charon.syslog {}
 	Section to define syslog loggers, see LOGGER CONFIGURATION in
 	**strongswan.conf**(5).

src/conftest/conftest.c

@@ -390,7 +390,7 @@ static void load_logger_options(file_logger_t *logger, char *section)
 	ike_name = conftest->test->get_bool(conftest->test,
 					"log.%s.ike_name", FALSE, section);
 
-	logger->set_options(logger, time_format, ike_name);
+	logger->set_options(logger, time_format, FALSE, ike_name);
 }
 
 /**
@@ -463,7 +463,7 @@ int main(int argc, char *argv[])
 	lib->credmgr->add_set(lib->credmgr, &conftest->creds->set);
 
 	logger = file_logger_create("stdout");
-	logger->set_options(logger, NULL, FALSE);
+	logger->set_options(logger, NULL, FALSE, FALSE);
 	logger->open(logger, FALSE, FALSE);
 	logger->set_level(logger, DBG_ANY, LEVEL_CTRL);
 	charon->bus->add_logger(charon->bus, &logger->logger);

src/libcharon/bus/listeners/file_logger.c

@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2012 Tobias Brunner
+ * Copyright (C) 2012-2015 Tobias Brunner
  * Copyright (C) 2006 Martin Willi
  * Hochschule fuer Technik Rapperswil
  *
@@ -64,6 +64,11 @@ struct private_file_logger_t {
 	 */
 	char *time_format;
 
+	/**
+	 * Add milliseconds after the time string
+	 */
+	bool add_ms;
+
 	/**
 	 * Print the name/# of the IKE_SA?
 	 */
@@ -87,7 +92,9 @@ METHOD(logger_t, log_, void,
 	char timestr[128], namestr[128] = "";
 	const char *current = message, *next;
 	struct tm tm;
-	time_t t;
+	timeval_t tv;
+	time_t s;
+	u_int ms = 0;
 
 	this->lock->read_lock(this->lock);
 	if (!this->out)
@@ -97,8 +104,10 @@ METHOD(logger_t, log_, void,
 	}
 	if (this->time_format)
 	{
-		t = time(NULL);
+		gettimeofday(&tv, NULL);
-		localtime_r(&t, &tm);
+		s = tv.tv_sec;
+		ms = tv.tv_usec / 1000;
+		localtime_r(&s, &tm);
 		strftime(timestr, sizeof(timestr), this->time_format, &tm);
 	}
 	if (this->ike_name && ike_sa)
@@ -126,8 +135,16 @@ METHOD(logger_t, log_, void,
 		next = strchr(current, '\n');
 		if (this->time_format)
 		{
-			fprintf(this->out, "%s %.2d[%N]%s ",
+			if (this->add_ms)
-					timestr, thread, debug_names, group, namestr);
+			{
+				fprintf(this->out, "%s.%03u %.2d[%N]%s ",
+						timestr, ms, thread, debug_names, group, namestr);
+			}
+			else
+			{
+				fprintf(this->out, "%s %.2d[%N]%s ",
+						timestr, thread, debug_names, group, namestr);
+			}
 		}
 		else
 		{
@@ -182,11 +199,12 @@ METHOD(file_logger_t, set_level, void,
 }
 
 METHOD(file_logger_t, set_options, void,
-	private_file_logger_t *this, char *time_format, bool ike_name)
+	private_file_logger_t *this, char *time_format, bool add_ms, bool ike_name)
 {
 	this->lock->write_lock(this->lock);
 	free(this->time_format);
 	this->time_format = strdupnull(time_format);
+	this->add_ms = add_ms;
 	this->ike_name = ike_name;
 	this->lock->unlock(this->lock);
 }

src/libcharon/bus/listeners/file_logger.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (C) 2012 Tobias Brunner
+ * Copyright (C) 2012-2015 Tobias Brunner
  * Copyright (C) 2006 Martin Willi
  * Hochschule fuer Technik Rapperswil
  *
@@ -48,9 +48,12 @@ struct file_logger_t {
 	 * Set options used by this logger
 	 *
 	 * @param time_format	format of timestamp prefix, as in strftime(), cloned
+	 * @param add_ms		TRUE to add the number of milliseconds within the
+	 *						current second after the timestamp
 	 * @param ike_name		TRUE to prefix the name of the IKE_SA
 	 */
-	void (*set_options) (file_logger_t *this, char *time_format, bool ike_name);
+	void (*set_options) (file_logger_t *this, char *time_format, bool add_ms,
+						 bool ike_name);
 
 	/**
 	 * Open (or reopen) the log file according to the given parameters

src/libcharon/daemon.c

@@ -324,11 +324,13 @@ static void load_file_logger(private_daemon_t *this, char *filename,
 	file_logger_t *file_logger;
 	debug_t group;
 	level_t def;
-	bool ike_name, flush_line, append;
+	bool add_ms, ike_name, flush_line, append;
 	char *time_format;
 
 	time_format = lib->settings->get_str(lib->settings,
 						"%s.filelog.%s.time_format", NULL, lib->ns, filename);
+	add_ms = lib->settings->get_bool(lib->settings,
+						"%s.filelog.%s.time_add_ms", FALSE, lib->ns, filename);
 	ike_name = lib->settings->get_bool(lib->settings,
 						"%s.filelog.%s.ike_name", FALSE, lib->ns, filename);
 	flush_line = lib->settings->get_bool(lib->settings,
@@ -337,7 +339,7 @@ static void load_file_logger(private_daemon_t *this, char *filename,
 						"%s.filelog.%s.append", TRUE, lib->ns, filename);
 
 	file_logger = add_file_logger(this, filename, current_loggers);
-	file_logger->set_options(file_logger, time_format, ike_name);
+	file_logger->set_options(file_logger, time_format, add_ms, ike_name);
 	file_logger->open(file_logger, flush_line, append);
 
 	def = lib->settings->get_int(lib->settings, "%s.filelog.%s.default", 1,