Make logging timestamps configurable (#16581)

doc/luanti.6

@@ -1,4 +1,4 @@
-.TH luanti 6 "2 February 2019" "" ""
+.TH luanti 6 "2025-10-16" "" ""
 
 .SH NAME
 luanti, luantiserver \- voxel game engine
@@ -7,12 +7,10 @@ luanti, luantiserver \- voxel game engine
 .B luanti
 [\fB--server SERVER OPTIONS\fR | \fBCLIENT OPTIONS\fR]
 [\fBCOMMON OPTIONS\fR]
-[\fBWORLD PATH\fR]
 
 .B luantiserver
 [\fBSERVER OPTIONS\fR]
 [\fBCOMMON OPTIONS\fR]
-[\fBWORLD PATH\fR]
 
 .SH DESCRIPTION
 .B Luanti (formerly Minetest) is a voxel game engine with easy modding and game creation.
@@ -43,8 +41,11 @@ Print enormous amounts of information to console
 .B \-\-quiet
 Print only errors to console
 .TP
-.B \-\-color <value>
-Colorize the logs ('always', 'never' or 'auto'), defaults to 'auto'
+.B \-\-color always | never | auto
+Coloured logs, default: 'auto'
+.TP
+.B \-\-log-timestamp wall | relative | none
+Timestamped logs, default: 'wall'
 .TP
 .B \-\-gameid <value> | list
 Set gameid or list available ones
@@ -66,14 +67,17 @@ Set network port (UDP) to use
 .TP
 .B \-\-run\-unittests
 Run unit tests and exit
+.TP
+.B \-\-run\-benchmarks
+Run benchmarks and exit
 
 .SH CLIENT OPTIONS
 .TP
 .B \-\-address <value>
-Address to connect to
+Address to connect to ('' = local game)
 .TP
 .B \-\-go
-Disable main menu
+Skip main menu, go directly in-game
 .TP
 .B \-\-name <value>
 Set player name
@@ -85,48 +89,47 @@ Set password
 Set password from contents of file
 .TP
 .B \-\-random\-input
-Enable random user input, for testing (client only)
-.TP
-.TP
-.B \-\-speedtests
-Run speed tests
+Enable random user input (for testing)
 
 .SH SERVER OPTIONS
 .TP
 .B \-\-migrate <value>
-Migrate from current map backend to another. Possible values are sqlite3,
-leveldb, redis, postgresql, and dummy.
+Migrate from current map backend to another. See supported backends
+with \-\-help.
 .TP
 .B \-\-migrate-auth <value>
-Migrate from current auth backend to another. Possible values are sqlite3,
-leveldb, and files.
+Migrate from current auth backend to another. See supported backends
+with \-\-help.
 .TP
 .B \-\-migrate-players <value>
-Migrate from current players backend to another. Possible values are sqlite3,
-leveldb, postgresql, dummy, and files.
+Migrate from current players backend to another. See supported backends
+with \-\-help.
 .TP
 .B \-\-migrate-mod-storage <value>
-Migrate from current mod storage backend to another. Possible values are
-sqlite3, dummy, and files.
+Migrate from current mod storage backend to another. See supported backends
+with \-\-help.
 .TP
 .B \-\-terminal
 Display an interactive terminal over ncurses during execution.
 
-.SH ENVIRONMENT
+.SH ENVIRONMENT VARIABLES
 .TP
 .B MINETEST_GAME_PATH
-Colon delimited list of directories to search for games.
+Colon delimited list of directories to search for games
 .TP
 .B MINETEST_MOD_PATH
-Colon delimited list of directories to search for mods.
+Colon delimited list of directories to search for mods
 .TP
 .B MINETEST_USER_PATH
-Path to Luanti user data directory.
+Path to Luanti user data directory
+.TP
+.B LOG_TIMESTAMP
+Equivalent to \-\-log-timestamp
 
 .SH BUGS
 Please report all bugs at https://github.com/luanti-org/luanti/issues.
 
-.SH AUTHOR
+.SH AUTHORS
 .PP
 Perttu Ahola <celeron55@gmail.com> and contributors.
 .PP

src/log.cpp

@@ -220,7 +220,7 @@ const char *Logger::getLevelLabel(LogLevel lev)
 
 LogColor Logger::color_mode = LOG_COLOR_AUTO;
 
-const std::string &Logger::getThreadName()
+inline const std::string &Logger::getThreadName()
 {
 	std::thread::id id = std::this_thread::get_id();
 
@@ -237,6 +237,22 @@ const std::string &Logger::getThreadName()
 	return fallback_name;
 }
 
+LogTimestamp Logger::timestamp_mode = LOG_TIMESTAMP_WALL;
+
+inline std::string Logger::getLogTimestamp()
+{
+	const static u64 begin_of_time = porting::getTimeMs();
+	if (timestamp_mode == LOG_TIMESTAMP_NONE)
+		return std::string();
+	if (timestamp_mode == LOG_TIMESTAMP_WALL)
+		return getTimestamp();
+	// LOG_TIMESTAMP_RELATIVE
+	float rel = (porting::getTimeMs() - begin_of_time) / 1000.0f;
+	char s[24];
+	snprintf(s, sizeof(s), "[% 8.2f]", rel);
+	return s;
+}
+
 void Logger::log(LogLevel lev, std::string_view text)
 {
 	if (isLevelSilenced(lev))
@@ -244,10 +260,12 @@ void Logger::log(LogLevel lev, std::string_view text)
 
 	const std::string &thread_name = getThreadName();
 	const char *label = getLevelLabel(lev);
-	const std::string timestamp = getTimestamp();
+	const std::string timestamp = getLogTimestamp();
 
 	std::string line = timestamp;
-	line.append(": ").append(label).append("[").append(thread_name)
+	if (!line.empty())
+		line.append(": ");
+	line.append(label).append("[").append(thread_name)
 		.append("]: ").append(text);
 
 	logToOutputs(lev, line, timestamp, thread_name, text);

src/log_internal.h

@@ -28,12 +28,18 @@ enum LogLevel {
 	LL_MAX,
 };
 
-enum LogColor {
+enum LogColor : u8 {
 	LOG_COLOR_NEVER,
 	LOG_COLOR_ALWAYS,
 	LOG_COLOR_AUTO,
 };
 
+enum LogTimestamp : u8 {
+	LOG_TIMESTAMP_NONE,
+	LOG_TIMESTAMP_WALL,
+	LOG_TIMESTAMP_RELATIVE
+};
+
 typedef u8 LogLevelMask;
 #define LOGLEVEL_TO_MASKLEVEL(x) (1 << x)
 
@@ -65,6 +71,7 @@ public:
 	}
 
 	static LogColor color_mode;
+	static LogTimestamp timestamp_mode;
 
 private:
 	void logToOutputsRaw(LogLevel, std::string_view line);
@@ -73,12 +80,13 @@ private:
 		std::string_view payload_text);
 
 	const std::string &getThreadName();
+	static std::string getLogTimestamp();
 
+	mutable std::mutex m_mutex;
 	std::vector<ILogOutput *> m_outputs[LL_MAX];
 	std::atomic<bool> m_has_outputs[LL_MAX];
 	std::atomic<bool> m_silenced_levels[LL_MAX];
 	std::map<std::thread::id, std::string> m_thread_names;
-	mutable std::mutex m_mutex;
 };
 
 class ILogOutput {

src/main.cpp

@@ -71,6 +71,7 @@ extern "C" {
 #define ENV_NO_COLOR "NO_COLOR"
 #define ENV_CLICOLOR "CLICOLOR"
 #define ENV_CLICOLOR_FORCE "CLICOLOR_FORCE"
+#define ENV_LOG_TIMESTAMP "LOG_TIMESTAMP"
 
 typedef std::map<std::string, ValueSpec> OptionList;
 
@@ -293,7 +294,7 @@ static void get_env_opts(Settings &args)
 	// CLICOLOR != 0: ANSI colors are supported (auto-detection, this is the default)
 	// CLICOLOR == 0: ANSI colors are NOT supported
 	const char *clicolor = std::getenv(ENV_CLICOLOR);
-	if (clicolor && std::string(clicolor) == "0") {
+	if (clicolor && std::string_view(clicolor) == "0") {
 		args.set("color", "never");
 	}
 	// NO_COLOR only specifies that no color is allowed.
@@ -304,10 +305,15 @@ static void get_env_opts(Settings &args)
 	}
 	// CLICOLOR_FORCE is another option, which should turn on colors "no matter what".
 	const char *clicolor_force = std::getenv(ENV_CLICOLOR_FORCE);
-	if (clicolor_force && std::string(clicolor_force) != "0") {
+	if (clicolor_force && std::string_view(clicolor_force) != "0") {
 		// should ALWAYS have colors, so we ignore tty (no "auto")
 		args.set("color", "always");
 	}
+
+	// No standard, Luanti-specific
+	const char *log_ts = std::getenv(ENV_LOG_TIMESTAMP);
+	if (log_ts)
+		args.set("log-timestamp", log_ts);
 }
 
 static bool get_cmdline_opts(int argc, char *argv[], Settings *cmd_args)
@@ -355,8 +361,10 @@ static void set_allowed_options(OptionList *allowed_options)
 			"'name' lists names, 'both' lists both)"))));
 	allowed_options->insert(std::make_pair("quiet", ValueSpec(VALUETYPE_FLAG,
 			_("Print only errors to console"))));
-	allowed_options->insert(std::make_pair("color", ValueSpec(VALUETYPE_STRING,
-			_("Coloured logs ('always', 'never' or 'auto'), defaults to 'auto'"))));
+	allowed_options->emplace("color", ValueSpec(VALUETYPE_STRING,
+			_("Coloured logs ('always', 'never' or 'auto'), default: 'auto'")));
+	allowed_options->emplace("log-timestamp", ValueSpec(VALUETYPE_STRING,
+			_("Timestamped logs ('wall', 'relative' or 'none'), default: 'wall'")));
 	allowed_options->insert(std::make_pair("info", ValueSpec(VALUETYPE_FLAG,
 			_("Print more information to console"))));
 	allowed_options->insert(std::make_pair("verbose",  ValueSpec(VALUETYPE_FLAG,
@@ -524,11 +532,9 @@ static bool setup_log_params(const Settings &cmd_args)
 		g_logger.addOutputMaxLevel(&stderr_output, LL_ERROR);
 	}
 
-	// Coloured log messages (see log.h)
+	// Message color
 	std::string color_mode;
-	if (cmd_args.exists("color")) {
-		color_mode = cmd_args.get("color");
-	}
+	cmd_args.getNoEx("color", color_mode);
 	if (!color_mode.empty()) {
 		if (color_mode == "auto") {
 			Logger::color_mode = LOG_COLOR_AUTO;
@@ -542,6 +548,22 @@ static bool setup_log_params(const Settings &cmd_args)
 		}
 	}
 
+	// Timestamp
+	std::string ts_mode;
+	cmd_args.getNoEx("log-timestamp", ts_mode);
+	if (!ts_mode.empty()) {
+		if (ts_mode == "wall") {
+			Logger::timestamp_mode = LOG_TIMESTAMP_WALL;
+		} else if (ts_mode == "relative") {
+			Logger::timestamp_mode = LOG_TIMESTAMP_RELATIVE;
+		} else if (ts_mode == "none") {
+			Logger::timestamp_mode = LOG_TIMESTAMP_NONE;
+		} else {
+			errorstream << "Invalid timestamp mode: " << ts_mode << std::endl;
+			return false;
+		}
+	}
+
 	// In certain cases, output info level on stderr
 	if (cmd_args.getFlag("info") || cmd_args.getFlag("verbose") ||
 			cmd_args.getFlag("trace") || cmd_args.getFlag("speedtests"))