Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Write log header later to ensure game identifiers are present #6138

Merged
merged 2 commits into from Jan 22, 2024

Conversation

peppy
Copy link
Sponsor Member

@peppy peppy commented Jan 17, 2024

The flow in GameHost ensures that the game/version identifiers are set before Logger.Storage is set. Unfortunately, until now any call to the static Logger.Log would immediately materialise the headers into their final string form. A stray log call before GameHost.Run could result in less-than-optimal headers.

This can be seen in osu!'s runtime log from an early log call.

Before:

2024-01-17 15:34:40 [verbose]: ----------------------------------------------------------
2024-01-17 15:34:40 [verbose]: runtime Log for dean (LogLevel: Debug)
2024-01-17 15:34:40 [verbose]: Running game unknown on .NET 6.0.25
2024-01-17 15:34:40 [verbose]: Environment: macOS (Unix 14.3.0), 8 cores
2024-01-17 15:34:40 [verbose]: ----------------------------------------------------------
2024-01-17 15:34:40 [verbose]: Starting legacy IPC provider...

After:

----------------------------------------------------------
runtime Log for dean (LogLevel: Debug)
Running osu-development 0.0.0.0 on .NET 6.0.25
Environment: macOS (Unix 14.3.0), 8 cores 
----------------------------------------------------------
2024-01-17 15:27:24 [verbose]: Starting legacy IPC provider...

Note that timestamps are not prefixed to the header now, but I think this is probably for the best.

@bdach
Copy link
Collaborator

bdach commented Jan 17, 2024

Note that timestamps are not prefixed to the header now, but I think this is probably for the best.

Is there any particular reason for that? Not that I necessarily care very much, but it just reads like a non-sequitur compared to the rest of the OP. I don't see why that measure would need to be taken.

@peppy
Copy link
Sponsor Member Author

peppy commented Jan 18, 2024

I don't see why that measure would need to be taken.

I can add it back, but if you check the code it should be apparently why they aren't there (different code path now).

It would look something like this:

diff --git a/osu.Framework/Logging/Logger.cs b/osu.Framework/Logging/Logger.cs
index 32731b801..63dddb504 100644
--- a/osu.Framework/Logging/Logger.cs
+++ b/osu.Framework/Logging/Logger.cs
@@ -315,7 +315,7 @@ private void add(string message = @"", LogLevel level = LogLevel.Verbose, Except
             IEnumerable<string> lines = logOutput
                                         .Replace(@"\r\n", @"\n")
                                         .Split('\n')
-                                        .Select(s => $@"{DateTime.UtcNow.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture)} [{level.ToString().ToLowerInvariant()}]: {s.Trim()}");
+                                        .Select(l => addTimestamp(l, level));
 
             if (outputToListeners)
             {
@@ -394,11 +394,16 @@ private void writePendingLines()
                 {
                     if (!headerAdded)
                     {
-                        writer.WriteLine("----------------------------------------------------------");
-                        writer.WriteLine($"{Name} Log for {UserIdentifier} (LogLevel: {Level})");
-                        writer.WriteLine($"Running {GameIdentifier} {VersionIdentifier} on .NET {Environment.Version}");
-                        writer.WriteLine($"Environment: {RuntimeInfo.OS} ({Environment.OSVersion}), {Environment.ProcessorCount} cores ");
-                        writer.WriteLine("----------------------------------------------------------");
+                        lines = new[]
+                                {
+                                    "----------------------------------------------------------",
+                                    $"{Name} Log for {UserIdentifier} (LogLevel: {Level})",
+                                    $"Running {GameIdentifier} {VersionIdentifier} on .NET {Environment.Version}",
+                                    $"Environment: {RuntimeInfo.OS} ({Environment.OSVersion}), {Environment.ProcessorCount} cores ",
+                                    "----------------------------------------------------------"
+                                }
+                                .Select(l => addTimestamp(l, Level))
+                                .Concat(lines).ToArray();
 
                         headerAdded = true;
                     }
@@ -412,6 +417,11 @@ private void writePendingLines()
             }
         }
 
+        private string addTimestamp(string s, LogLevel level)
+        {
+            return $@"{DateTime.UtcNow.ToString("yyyy-MM-dd HH:mm:ss", CultureInfo.InvariantCulture)} [{level.ToString().ToLowerInvariant()}]: {s.Trim()}";
+        }
+
         /// <summary>
         /// Whether the output of this logger should be sent to listeners of <see cref="Debug"/> and <see cref="Console"/>.
         /// Defaults to true.

@bdach bdach self-requested a review January 22, 2024 14:05
Copy link
Collaborator

@bdach bdach left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

seems fine

@bdach bdach enabled auto-merge January 22, 2024 14:19
@bdach bdach merged commit d7dd556 into ppy:master Jan 22, 2024
13 checks passed
@peppy peppy deleted the logger-ensure-header-later branch February 29, 2024 01:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants