[Perf] High Allocator LoggingScope when no loggers

[benaadams]

Using works with null references, so this is simpler than outlined below; added change to logging to improve efficiency.

---

Creating a scope is expensive (at benchmarking speeds) and the techempower benchmarks specify in general requirements item 2:

All test implementations must disable all disk logging. For many reasons, we expect all tests will run without writing logs to disk. Most importantly, the volume of requests is sufficiently high to fill up disks even with only a single line written to disk per request. Please disable all forms of disk logging. We recommend but do not require disabling console logging as well.

For fair comparison, only create the logging scope if logging is enabled:

Add LogLevel of None = 7?

Change the following from:

var logger = _applicationServices.GetRequiredService<ILogger<HostingEngine>>();
...
var server = ServerFactory.Start(_serverInstance,
    async features =>
    {
        try
        {
            using (logger.BeginScope("Request Id: {RequestId}", requestIdentifier))
            {
                contextAccessor.HttpContext = httpContext;
                await application(httpContext);
            }
        }
        catch (Exception ex)
        {
            if (telemetrySource.IsEnabled("Microsoft.AspNet.Hosting.UnhandledException"))
            {
                telemetrySource.WriteTelemetry("Microsoft.AspNet.Hosting.UnhandledException", new { httpContext = httpContext, exception = ex });
            }

            throw;
        }

To something similar to:

var logger = _applicationServices.GetRequiredService<ILogger<HostingEngine>>();
...
var isLogging = logger.IsEnabled(LogLevel.Critical); // ? not sure about how not logging is checked
var server = ServerFactory.Start(_serverInstance,
    async features =>
    {
        ILogger loggerScope;
        try
        {
            if (isLogging) 
            {
                loggerScope = logger.BeginScope("Request Id: {RequestId}", requestIdentifier);
            }

            contextAccessor.HttpContext = httpContext;
            await application(httpContext);
        }
        catch (Exception ex)
        {
            if (telemetrySource.IsEnabled("Microsoft.AspNet.Hosting.UnhandledException"))
            {
                telemetrySource.WriteTelemetry("Microsoft.AspNet.Hosting.UnhandledException", new { httpContext = httpContext, exception = ex });
            }

            throw;
        }
        finally
        {
            if (loggerScope != null) loggerScope.Dispose();
        }

Ensure having no local logging scope doesn't cause issues.

[benaadams]

For reference 437 kBytes for 4k requests; or 672 Mbytes/s for 6M rps.
40 GBytes/min for the GC to clean up:

[benaadams]

Would be partially resolved by aspnet/Logging#254

Before Allocations 12000 per 4k

Before Bytes 448kB per 4k

After Allocations 8000 per 4k

After Bytes 256kB per 4k

[benaadams]

Taking it a little further and changing

using (logger.BeginScope("Request Id: {RequestId}", requestIdentifier))

to

using (logger.IsEnabled(LogLevel.Critical) 
    ? logger.BeginScope("Request Id: {RequestId}", requestIdentifier) 
    : null)

With this change reduces it to zero allocations

And zero bytes

[benaadams]

@davidfowl please reopen; commit Reduce logging overhead in hosting has brought this back but with even higher byte allocation.

For 2003 requests

Drill down on Issue aspnet/KestrelHttpServer#288
Measurements post PR aspnet/KestrelHttpServer#287

Allocations (Same as previous)

Bytes (256kB per 4k -> 352kB per 4k; up 96kB)

[davidfowl]

/cc @lodejard

[lodejard]

Too many cross-references, history, and screen shots! :) I can't tell how much of this is from before the current changes, or what the recommendation is.

Can we discuss this in a more direct way?

[davidfowl]

@benaadams @lodejard this still relevant? If so reopen

[benaadams]

Still features (just under highlighted line)

Don't know how urgent it is

[benaadams]

Also other than string and QUWICDC is the only thing on that list that can't be pooled (am guessing RequestServicesFeature can be optionally removed)

[davidfowl]

@benaadams what are those strings?

[benaadams]

Header, host, path values - is what I did the StringCache for back in the day aspnet/KestrelHttpServer#411 (comment)