From b2ce70987c2f724436514e8f91f9f455be7d13ff Mon Sep 17 00:00:00 2001 From: Bond_009 Date: Wed, 30 Nov 2022 22:07:34 +0100 Subject: Change log level for slow HTTP responses from WRN TO DBG The added log level check is there because Request.GetDisplayUrl() is a pretty expensive call, creating a StringBuilder and string which doesn't need to happen on most installs where debug logging is disabled --- Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs') diff --git a/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs b/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs index 1c25696cd1..65b64da4f1 100644 --- a/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs +++ b/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs @@ -47,9 +47,10 @@ namespace Jellyfin.Server.Middleware context.Response.OnStarting(() => { watch.Stop(); - if (enableWarning && watch.ElapsedMilliseconds > warningThreshold) + var responseTimeForCompleteRequest = watch.ElapsedMilliseconds; + if (enableWarning && responseTimeForCompleteRequest > warningThreshold && _logger.IsEnabled(LogLevel.Debug)) { - _logger.LogWarning( + _logger.LogDebug( "Slow HTTP Response from {Url} to {RemoteIp} in {Elapsed:g} with Status Code {StatusCode}", context.Request.GetDisplayUrl(), context.GetNormalizedRemoteIp(), @@ -57,7 +58,6 @@ namespace Jellyfin.Server.Middleware context.Response.StatusCode); } - var responseTimeForCompleteRequest = watch.ElapsedMilliseconds; context.Response.Headers[ResponseHeaderResponseTime] = responseTimeForCompleteRequest.ToString(CultureInfo.InvariantCulture); return Task.CompletedTask; }); -- cgit v1.2.3 From a455e580be2e650fafb8e768c4978d9ff83ca3c4 Mon Sep 17 00:00:00 2001 From: Bond-009 Date: Wed, 14 Dec 2022 22:03:26 +0100 Subject: Use static methods StopWatch where it makes sense (#8898) --- Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs | 14 +++++++------- Jellyfin.Server/Program.cs | 7 ++----- 2 files changed, 9 insertions(+), 12 deletions(-) (limited to 'Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs') diff --git a/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs b/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs index 65b64da4f1..531897cd49 100644 --- a/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs +++ b/Jellyfin.Server/Middleware/ResponseTimeMiddleware.cs @@ -40,25 +40,25 @@ namespace Jellyfin.Server.Middleware /// Task. public async Task Invoke(HttpContext context, IServerConfigurationManager serverConfigurationManager) { - var watch = new Stopwatch(); - watch.Start(); + var startTimestamp = Stopwatch.GetTimestamp(); + var enableWarning = serverConfigurationManager.Configuration.EnableSlowResponseWarning; var warningThreshold = serverConfigurationManager.Configuration.SlowResponseThresholdMs; context.Response.OnStarting(() => { - watch.Stop(); - var responseTimeForCompleteRequest = watch.ElapsedMilliseconds; - if (enableWarning && responseTimeForCompleteRequest > warningThreshold && _logger.IsEnabled(LogLevel.Debug)) + var responseTime = Stopwatch.GetElapsedTime(startTimestamp); + var responseTimeMs = responseTime.TotalMilliseconds; + if (enableWarning && responseTimeMs > warningThreshold && _logger.IsEnabled(LogLevel.Debug)) { _logger.LogDebug( "Slow HTTP Response from {Url} to {RemoteIp} in {Elapsed:g} with Status Code {StatusCode}", context.Request.GetDisplayUrl(), context.GetNormalizedRemoteIp(), - watch.Elapsed, + responseTime, context.Response.StatusCode); } - context.Response.Headers[ResponseHeaderResponseTime] = responseTimeForCompleteRequest.ToString(CultureInfo.InvariantCulture); + context.Response.Headers[ResponseHeaderResponseTime] = responseTimeMs.ToString(CultureInfo.InvariantCulture); return Task.CompletedTask; }); diff --git a/Jellyfin.Server/Program.cs b/Jellyfin.Server/Program.cs index 46f45b9adf..7052f4d2bf 100644 --- a/Jellyfin.Server/Program.cs +++ b/Jellyfin.Server/Program.cs @@ -94,8 +94,7 @@ namespace Jellyfin.Server private static async Task StartApp(StartupOptions options) { - var stopWatch = new Stopwatch(); - stopWatch.Start(); + var startTimestamp = Stopwatch.GetTimestamp(); // Log all uncaught exceptions to std error static void UnhandledExceptionToConsole(object sender, UnhandledExceptionEventArgs e) => @@ -217,9 +216,7 @@ namespace Jellyfin.Server await appHost.RunStartupTasksAsync(_tokenSource.Token).ConfigureAwait(false); - stopWatch.Stop(); - - _logger.LogInformation("Startup complete {Time:g}", stopWatch.Elapsed); + _logger.LogInformation("Startup complete {Time:g}", Stopwatch.GetElapsedTime(startTimestamp)); // Block main thread until shutdown await Task.Delay(-1, _tokenSource.Token).ConfigureAwait(false); -- cgit v1.2.3