[Bug]: logtimestamp will use the server's start timestamp for every log entry, rather than the time the line occurs at

User story

As a server administrator, I want accurate timestamps recorded in the console log files.

Game

Minecraft, Valheim

Linux distro

Ubuntu 22.04

Command

command: start

Further information

The logtimestamp setting appears to re-use the server start timestamp for every log entry, resulting in timestamps that are unreliable. This can most easily be confirmed by servers that already utilize time/datestamps in their log (like Valheim).

This may be a limitation of how tmux works. Reviewing the code in command_start.sh

addtimestamp="gawk '{ print strftime(\\\"[$logtimestampformat]\\\"), \\\$0 }'"

<...>

        if [ "${consolelogging}" == "on" ] || [ -z "${consolelogging}" ]; then
                if [ "${logtimestamp}" == "on" ]; then
                        tmux -L "${socketname}" pipe-pane -o -t "${sessionname}" "exec bash -c \"cat | $addtimestamp\" >> '${consolelog}'"
                else
                        tmux -L "${socketname}" pipe-pane -o -t "${sessionname}" "exec cat >> '${consolelog}'"
                fi
        else

given that this is in command_start.sh, this will affect all gameservers.

logs provided show the timestamp added by lgsm, followed by the minecraft native console timestamp, as well as valheim console logs which display not just time, but date, showing a huge disparity between the two.

Relevant log output

Minecraft:
[2024-02-04 09:30:56] [11:04:07] [RCON Listener #2/INFO] [minecraft/GenericThread]: Thread RCON Client /127.0.0.1 started
[2024-02-04 09:30:56] [11:04:07] [Server thread/INFO] [minecraft/MinecraftServer]: [Rcon: Automatic saving is now enabled]
[2024-02-04 09:30:56] [11:04:07] [RCON Client /127.0.0.1 #23/INFO] [minecraft/RconClient]: Thread RCON Client /127.0.0.1 shutting down
[2024-02-04 09:30:56] [11:19:01] [RCON Listener #2/INFO] [minecraft/GenericThread]: Thread RCON Client /127.0.0.1 started
[2024-02-04 09:30:56] [11:19:01] [Server thread/INFO] [minecraft/MinecraftServer]: [Rcon: Automatic saving is now disabled]
[2024-02-04 09:30:56] [11:19:01] [RCON Client /127.0.0.1 #24/INFO] [minecraft/RconClient]: Thread RCON Client /127.0.0.1 shutting down

Valheim:
[2024-02-04 09:30:55] 02/12/2024 18:33:38: Sending message to save player profiles
[2024-02-04 09:30:55] 02/12/2024 18:33:38: PrepareSave: clone done in 30ms
[2024-02-04 09:30:55] 02/12/2024 18:33:38: PrepareSave: ZDOExtraData.PrepareSave done in 10 ms
[2024-02-04 09:30:55] 02/12/2024 18:33:38: World save writing starting
[2024-02-04 09:30:55] 02/12/2024 18:33:38: World save writing started
[2024-02-04 09:30:55] 02/12/2024 18:33:38: Saved 83716 ZDOs
[2024-02-04 09:30:55] 02/12/2024 18:33:38: World save writing finishing
[2024-02-04 09:30:55] 02/12/2024 18:33:38: World save writing finished
[2024-02-04 09:30:55] 02/12/2024 18:33:38: World saved ( 201.645ms )
[2024-02-04 09:30:55] 02/12/2024 18:41:42:  Connections 0 ZDOS:83716  sent:0 recv:0
[2024-02-04 09:30:55] 02/12/2024 18:48:38: Sending message to save player profiles
[2024-02-04 09:30:55] 02/12/2024 18:48:38: PrepareSave: clone done in 13ms
[2024-02-04 09:30:55] 02/12/2024 18:48:38: PrepareSave: ZDOExtraData.PrepareSave done in 10 ms
[2024-02-04 09:30:55] 02/12/2024 18:48:38: World save writing starting
[2024-02-04 09:30:55] 02/12/2024 18:48:38: World save writing started
[2024-02-04 09:30:55] 02/12/2024 18:48:39: Saved 83716 ZDOs
[2024-02-04 09:30:55] 02/12/2024 18:48:39: World save writing finishing
[2024-02-04 09:30:55] 02/12/2024 18:48:39: World save writing finished
[2024-02-04 09:30:55] 02/12/2024 18:48:39: World saved ( 212.881ms )

Steps to reproduce

set logtimestamp="on" in lgsm/config-lgsm/gameserver/*.cfg
start the gameserver
review log/console/gameserver-console.log and see the same timestamp (server star time) for all console entries regardless of how long has passed.

GameServerManagers / LinuxGSM