Log datetime

doc/meson.build

@@ -36,6 +36,15 @@ if get_option('manpages')
     install: true,
     install_dir: [join_paths(get_option('mandir'), 'man1'), join_paths(get_option('mandir'), 'man5')],
   )
+  custom_target(
+    'Conf example',
+    input: 'mpdconf.example',
+    output: 'mpdconf.example',
+    command: ['cp', '@INPUT@', '@OUTPUT@'],
+    build_by_default: true,
+    install: true,
+    install_dir: join_paths(get_option('datadir'), 'doc')
+  )
 endif
 
 if get_option('doxygen')

doc/mpd.conf.5.rst

@@ -105,6 +105,19 @@ log_level <level>
 
    The default is :samp:`notice`.
 
+log_timestamp <none|minutes|seconds|milliseconds>
+   Log messages are prefixed with a timestamp when
+   written to a log file or to stdout (but not when written
+   to syslog or to systemd log).
+   The following time formats are available:
+
+   - :samp:`none`: "message" (without timestamp)
+   - :samp:`minutes`: "Jan 30 17:11 : message"
+   - :samp:`seconds`: "Jan 30 17:11:32 : message"
+   - :samp:`milliseconds`: "Jan 30 17:11:32.271 : message"
+
+   The default is :samp:`seconds`.
+
 follow_outside_symlinks <yes or no>
   Control if MPD will follow symbolic links pointing outside the music dir. You
   must recreate the database after changing this option. The default is "yes".

doc/mpdconf.example

@@ -98,6 +98,13 @@
 #
 #log_level			"notice"
 #
+# The timestamp prefixed to log lines when written to a log file
+# or to stdout (but not when written to syslog or to systemd log).
+# Available setting arguments are "none", "minutes", "seconds",
+# and "milliseconds".
+#
+#log_timestamp		"seconds"
+#
 # Setting "restore_paused" to "yes" puts MPD into pause mode instead
 # of starting playback after startup.
 #

src/Log.hxx

@@ -13,6 +13,13 @@
 
 class Domain;
 
+enum class LogTimestamp {
+	NONE,
+	MINUTES,
+	SECONDS,
+	MILLISECONDS
+};
+
 void
 Log(LogLevel level, const Domain &domain, std::string_view msg) noexcept;
 

src/LogBackend.cxx

@@ -9,11 +9,12 @@
 #include "Version.h"
 #include "config.h"
 
+#include <fmt/chrono.h>
 #include <cassert>
-
-#include <stdio.h>
-#include <string.h>
-#include <time.h>
+#include <cstdio>
+#include <cstring>
+#include <chrono>
+#include <functional>
 
 #ifdef HAVE_SYSLOG
 #include <syslog.h>
@@ -50,7 +51,15 @@ ToAndroidLogLevel(LogLevel log_level) noexcept
 
 static LogLevel log_threshold = LogLevel::NOTICE;
 
-static bool enable_timestamp;
+static bool enable_timestamp = false;
+
+static constexpr size_t LOG_DATE_BUF_SIZE = std::char_traits<char>::length("Jan 22 15:43:14.000 : ") + 1;
+
+template<typename DurationType>
+static const char *
+log_date(char buf[LOG_DATE_BUF_SIZE]);
+
+static auto log_time_formatter = log_date<std::chrono::seconds>;
 
 #ifdef HAVE_SYSLOG
 static bool enable_syslog;
@@ -62,25 +71,56 @@ SetLogThreshold(LogLevel _threshold) noexcept
 	log_threshold = _threshold;
 }
 
+template <typename DurationType>
+inline constexpr const char *date_format_of = "";
+
+template<>
+inline constexpr const char *date_format_of<std::chrono::minutes> = "{:%b %d %H:%M} : ";
+template<>
+inline constexpr const char *date_format_of<std::chrono::seconds> = "{:%b %d %H:%M:%S} : ";
+template<>
+inline constexpr const char *date_format_of<std::chrono::milliseconds> = "{:%b %d %H:%M:%S} : ";
+
+template<typename DurationType>
+static const char *
+log_date(char buf[LOG_DATE_BUF_SIZE])
+{
+	using namespace std::chrono;
+
+	/*
+	 * NOTE: fmt of chrono::time_point with %S writes
+	 *       a floating point number of seconds if the
+	 *       duration resolution is less than second
+	 */
+	auto [p, n] = fmt::format_to_n(buf, LOG_DATE_BUF_SIZE, date_format_of<DurationType>,
+				       floor<DurationType>(system_clock::now()));
+	assert(n < LOG_DATE_BUF_SIZE);
+	*p = 0;
+	return buf;
+}
+
+static auto
+null_log_time_formatter = [](char buf[LOG_DATE_BUF_SIZE]) -> const char* {
+	buf[0] = 0;
+	return buf;
+};
+
 void
-EnableLogTimestamp() noexcept
+EnableLogTimestamp(LogTimestamp _log_time_stamp) noexcept
 {
 #ifdef HAVE_SYSLOG
 	assert(!enable_syslog);
 #endif
 	assert(!enable_timestamp);
 
 	enable_timestamp = true;
-}
 
-static const char *
-log_date() noexcept
-{
-	static constexpr size_t LOG_DATE_BUF_SIZE = std::char_traits<char>::length("Jan 22 15:43:14 : ") + 1;
-	static char buf[LOG_DATE_BUF_SIZE];
-	time_t t = time(nullptr);
-	strftime(buf, LOG_DATE_BUF_SIZE, "%b %d %H:%M:%S : ", localtime(&t));
-	return buf;
+	switch (_log_time_stamp) {
+		case LogTimestamp::MINUTES: log_time_formatter = log_date<std::chrono::minutes>; break;
+		case LogTimestamp::SECONDS: log_time_formatter = log_date<std::chrono::seconds>; break;
+		case LogTimestamp::MILLISECONDS: log_time_formatter = log_date<std::chrono::milliseconds>; break;
+		case LogTimestamp::NONE: log_time_formatter = null_log_time_formatter; break;
+	}
 }
 
 #ifdef HAVE_SYSLOG
@@ -147,8 +187,9 @@ LogFinishSysLog() noexcept
 static void
 FileLog(const Domain &domain, std::string_view message) noexcept
 {
+	char date_buf[LOG_DATE_BUF_SIZE];
 	fmt::print(stderr, "{}{}: {}\n",
-		   enable_timestamp ? log_date() : "",
+		   log_time_formatter(date_buf),
 		   domain.GetName(),
 		   StripRight(message));
 

src/LogBackend.hxx

@@ -5,12 +5,13 @@
 #define MPD_LOG_BACKEND_HXX
 
 #include "LogLevel.hxx"
+#include "Log.hxx"
 
 void
 SetLogThreshold(LogLevel _threshold) noexcept;
 
 void
-EnableLogTimestamp() noexcept;
+EnableLogTimestamp(LogTimestamp _log_time_stamp) noexcept;
 
 void
 LogInitSysLog() noexcept;

src/LogInit.cxx

@@ -70,8 +70,6 @@ log_init_file(int line)
 			       out_path, line);
 #endif
 	}
-
-	EnableLogTimestamp();
 }
 
 static inline LogLevel
@@ -95,7 +93,22 @@ parse_log_level(const char *value)
 		throw FmtRuntimeError("unknown log level {:?}", value);
 }
 
-#endif
+static inline LogTimestamp
+parse_log_timestamp(const char *value)
+{
+	if (StringIsEqual(value, "none"))
+		return LogTimestamp::NONE;
+	if (StringIsEqual(value, "minutes"))
+		return LogTimestamp::MINUTES;
+	else if (StringIsEqual(value, "seconds"))
+		return LogTimestamp::SECONDS;
+	else if (StringIsEqual(value, "milliseconds"))
+		return LogTimestamp::MILLISECONDS;
+	else
+		throw FmtRuntimeError("unknown log timestamp {:?}. expected one of: none, minutes, seconds, milliseconds", value);
+}
+
+#endif // #ifndef ANDROID
 
 void
 log_early_init(bool verbose) noexcept
@@ -128,9 +141,15 @@ log_init(const ConfigData &config, bool verbose, bool use_stdout)
 				: LogLevel::NOTICE;
 		}));
 
+	LogTimestamp log_timestamp = config.With(ConfigOption::LOG_TIMESTAMP, [](const char *s){
+		return s != nullptr
+		       ? parse_log_timestamp(s)
+		       : LogTimestamp::SECONDS;
+	});
+
 	if (use_stdout) {
 		out_fd = STDOUT_FILENO;
-		EnableLogTimestamp();
+		EnableLogTimestamp(log_timestamp);
 	} else {
 		const auto *param = config.GetParam(ConfigOption::LOG_FILE);
 		if (param == nullptr) {
@@ -158,6 +177,7 @@ log_init(const ConfigData &config, bool verbose, bool use_stdout)
 #endif
 		} else {
 			out_path = param->GetPath();
+			EnableLogTimestamp(log_timestamp);
 			log_init_file(param->line);
 		}
 	}

src/config/Option.hxx

@@ -27,6 +27,7 @@ enum class ConfigOption {
 	BIND_TO_ADDRESS,
 	PORT,
 	LOG_LEVEL,
+	LOG_TIMESTAMP,
 	ZEROCONF_NAME,
 	ZEROCONF_ENABLED,
 	PASSWORD,

src/config/Templates.cxx

@@ -25,6 +25,7 @@ const ConfigTemplate config_param_templates[] = {
 	{ "bind_to_address", true },
 	{ "port" },
 	{ "log_level" },
+	{ "log_timestamp" },
 	{ "zeroconf_name" },
 	{ "zeroconf_enabled" },
 	{ "password", true },