Fix not saving log lines #934
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
When log lines are appearing in different runs off the log recorder, but have the same timestamp, they would be omitted, as the "last" log line already has this timestamp.
cemathey
approved these changes
Feb 14, 2025
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
When log lines are appearing in different runs off the log recorder, but have the same timestamp, they would be omitted, as the "last" log line already has this timestamp.
Some details of the analysis, how I came to the tests of that PR:
There is a greyhound night game here: https://greyrcon.de:82/games/2648
The player
🅶 I|I marsmykhas 41 kills according to the stats page. In-game and reported by HLU, he has 43 kills, hence supposedly 2 kills are "missing".In HLU, the player has the following kills recorded (excuse the german in the copy, it's just the line number):
(the lines with the dash before are the kills that are missing in the CRCon logs from the database)
The CRCon game logs mention 41 kills only: (retrieved from the Game Logs view, hence from the CRCon database, not the live game data):
Looking closer to the kill at
20:41:06that is missing I looked directly at the logs returned from the game server, as seen by CRCon (this is an excerpt for this specific absolute time):{ "version": 1, "timestamp_ms": 1739479269000, "event_time": "2025-02-13T20:41:09", "relative_time_ms": -3394.249, "raw": "[3.37 sec (1739479269)] KILL: Λ • rotzaug(Axis/76561197981464099) -> (WTH) RayG_93(Allies/76561198015268767) with GEWEHR 43", "line_without_time": "KILL: Λ • rotzaug(Axis/76561197981464099) -> (WTH) RayG_93(Allies/76561198015268767) with GEWEHR 43", "action": "KILL", "player_name_1": "Λ • rotzaug", "player_id_1": "76561197981464099", "player_name_2": "(WTH) RayG_93", "player_id_2": "76561198015268767", "weapon": "GEWEHR 43", "message": "Λ • rotzaug(Axis/76561197981464099) -> (WTH) RayG_93(Allies/76561198015268767) with GEWEHR 43", "sub_content": null }, { "version": 1, "timestamp_ms": 1739479266000, "event_time": "2025-02-13T20:41:06", "relative_time_ms": -6394.249000000001, "raw": "[6.14 sec (1739479266)] KILL: 🅶 I|I marsmyk(Allies/76561198130579400) -> [82ADr]DaddyNoob(Axis/76561198258090341) with M97 TRENCH GUN", "line_without_time": "KILL: 🅶 I|I marsmyk(Allies/76561198130579400) -> [82ADr]DaddyNoob(Axis/76561198258090341) with M97 TRENCH GUN", "action": "KILL", "player_name_1": "🅶 I|I marsmyk", "player_id_1": "76561198130579400", "player_name_2": "[82ADr]DaddyNoob", "player_id_2": "76561198258090341", "weapon": "M97 TRENCH GUN", "message": "🅶 I|I marsmyk(Allies/76561198130579400) -> [82ADr]DaddyNoob(Axis/76561198258090341) with M97 TRENCH GUN", "sub_content": null }, { "version": 1, "timestamp_ms": 1739479266000, "event_time": "2025-02-13T20:41:06", "relative_time_ms": -6394.249000000001, "raw": "[6.35 sec (1739479266)] KILL: GODSEND(Axis/76561198122749126) -> G I|I Weidemilch(Allies/76561198983922637) with GEWEHR 43", "line_without_time": "KILL: GODSEND(Axis/76561198122749126) -> G I|I Weidemilch(Allies/76561198983922637) with GEWEHR 43", "action": "KILL", "player_name_1": "GODSEND", "player_id_1": "76561198122749126", "player_name_2": "G I|I Weidemilch", "player_id_2": "76561198983922637", "weapon": "GEWEHR 43", "message": "GODSEND(Axis/76561198122749126) -> G I|I Weidemilch(Allies/76561198983922637) with GEWEHR 43", "sub_content": null }, { "version": 1, "timestamp_ms": 1739479260000, "event_time": "2025-02-13T20:41:00", "relative_time_ms": -1503.8100000000002, "raw": "[1.52 sec (1739479260)] KILL: |HTD| Leonardo(Allies/76561197993751812) -> Ξ Fignaldo(Axis/76561198150864345) with M1 GARAND", "line_without_time": "KILL: |HTD| Leonardo(Allies/76561197993751812) -> Ξ Fignaldo(Axis/76561198150864345) with M1 GARAND", "action": "KILL", "player_name_1": "|HTD| Leonardo", "player_id_1": "76561197993751812", "player_name_2": "Ξ Fignaldo", "player_id_2": "76561198150864345", "weapon": "M1 GARAND", "message": "|HTD| Leonardo(Allies/76561197993751812) -> Ξ Fignaldo(Axis/76561198150864345) with M1 GARAND", "sub_content": null },The second object is the
KILLevent that is missing in the CRCon logs database. It has the exact same time as theKILLevent fromGODSENDagainstWeidemilch, which is in the logs table of CRCon:My assumption therefore is that the kill of
marsmykat that time was simply omitted as the CRCon assumed this event was already saved in the database. The logic for skipping events if they have the same timestamp than the already saved one, is the same for years. However, saving log events to the database as often as 5 minutes only, might have resulted in this issue by not being encountered often, if at all. Reducing this to saving logs every 10 seconds made this issue appear more often.Relying on the timestamp only is not good for identifying duplicate logs, as multiple logs can happen at the exact same time, at least as reported by the game server. Hence, use a combination of the event time, as well as the log message.
HLU Logs:
AUTO_Thu_13_Feb_19.26.txt