Laden...

[Artikel] myCSharp.de läuft auf .NET 6

Erstellt von gfoidl vor 2 Jahren Letzter Beitrag vor 2 Jahren 1.228 Views
gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren
[Artikel] myCSharp.de läuft auf .NET 6

myCSharp.de läuft auf .NET 6

am Sonntagmittag des 28.11.2021 wurde die Laufzeitumgebung vom Forum von .NET 5 auf .NET 6 gewechselt.

Metriken / EventCounters

Wir nutzen Application Insights um Metriken zu sammeln. Dabei sind es zum einen standardmäßige Metriken von .NET, ASP.NET Core und EF Core die aufgezeichnet werden, zum anderen haben wir eine Menge an eigenen Metriken erstellt, um zu sehen wie sich unser Code so verhält.

Das hört sich komplizierter an als es ist, daher ein Beispiel.
Zum Rendern vom BBCode in eine HTML-Darstellung werden StringBuilder verwendet, welche gepoolt werden. Um hier zu sehen, ob das Pooling funktioniert od. nicht, haben wir eine spezielle Policy erstellt:


using System.Text;
using Microsoft.Extensions.ObjectPool;

namespace MyCSharp.Portal.Diagnostics;

public class MonitoringStringBuilderPooledObjectPolicy : StringBuilderPooledObjectPolicy
{
    public override StringBuilder Create()
    {
        StringBuilderPoolEventCounterSource.Log.LogCreated();
        return base.Create();
    }

    public override bool Return(StringBuilder obj)
    {
        bool isReturned = base.Return(obj);

        if (isReturned)
        {
            StringBuilderPoolEventCounterSource.Log.LogReturned();
        }
        else
        {
            StringBuilderPoolEventCounterSource.Log.LogNotReturned();
        }

        return isReturned;
    }
}

Die dazugehörende EventSource:


using System;
using System.Collections.Generic;
using System.Diagnostics.Tracing;
using System.Runtime.CompilerServices;
using System.Threading;

namespace MyCSharp.Portal.Diagnostics;

[EventSource(Name = EventSourceName)]
internal sealed class StringBuilderPoolEventCounterSource : EventSource
{
    public static readonly StringBuilderPoolEventCounterSource Log = new();

    public const string EventSourceName = "MyCSharp.StringBuilderPool";
    private const string CreatedPerSecondCounterName = "created-per-second";
    private const string ReturnedPerSecondCounterName = "returned-per-second";
    private const string NotReturnedPerSecondCounterName = "not-returned-per-second";
    private const string TotalCreatedCounterName = "total-created";
    private const string TotalReturnedCounterName = "total-returned";
    private const string TotalNotReturnedCounterName = "total-not-returned";
    private const string TotalUsedCounterName = "total-used";

    private const int CreatedId = 1;
    private const int ReturnedId = 2;
    private const int NotReturnedId = 3;

    private long _totalCreated;
    private long _totalReturned;
    private long _totalNotReturned;
    private long _totalUsed;

    private IncrementingPollingCounter? _createdPerSecondCounter;
    private IncrementingPollingCounter? _returnedPerSecondCounter;
    private IncrementingPollingCounter? _notReturnedPerSecondCounter;
    private PollingCounter? _totalCreatedCounter;
    private PollingCounter? _totalReturnedCounter;
    private PollingCounter? _totalNotReturnedCounter;
    private PollingCounter? _totalUsedCounter;

    private StringBuilderPoolEventCounterSource() { }

    [NonEvent]
    public void LogCreated()
    {
        Interlocked.Increment(ref _totalCreated);

        if (IsEnabled())
        {
            Created();
        }
    }

    [MethodImpl(MethodImplOptions.NoInlining)]
    [Event(CreatedId, Level = EventLevel.Informational)]
    private void Created() => WriteEvent(CreatedId);

    [NonEvent]
    public void LogReturned()
    {
        Interlocked.Increment(ref _totalReturned);
        Interlocked.Increment(ref _totalUsed);

        if (IsEnabled())
        {
            Returned();
        }
    }

    [MethodImpl(MethodImplOptions.NoInlining)]
    [Event(ReturnedId, Level = EventLevel.Informational)]
    private void Returned() => WriteEvent(ReturnedId);

    [NonEvent]
    public void LogNotReturned()
    {
        Interlocked.Increment(ref _totalNotReturned);
        Interlocked.Increment(ref _totalUsed);

        if (IsEnabled())
        {
            NotReturned();
        }
    }

    [MethodImpl(MethodImplOptions.NoInlining)]
    [Event(NotReturnedId, Level = EventLevel.Informational)]
    private void NotReturned() => WriteEvent(NotReturnedId);

    protected override void OnEventCommand(EventCommandEventArgs command)
    {
        if (command.Command == EventCommand.Enable)
        {
            _createdPerSecondCounter ??= new IncrementingPollingCounter(CreatedPerSecondCounterName, this, () => Volatile.Read(ref _totalCreated))
            {
                DisplayName = "Created Rate",
                DisplayRateTimeScale = TimeSpan.FromMinutes(1)  // Application Insights is 1 minute
            };

            _totalCreatedCounter ??= new PollingCounter(TotalCreatedCounterName, this, () => _totalCreated)
            {
                DisplayName = "Total Created"
            };

            _returnedPerSecondCounter ??= new IncrementingPollingCounter(ReturnedPerSecondCounterName, this, () => Volatile.Read(ref _totalReturned))
            {
                DisplayName = "Returned Rate",
                DisplayRateTimeScale = TimeSpan.FromMinutes(1)  // Application Insights is 1 minute
            };

            _totalReturnedCounter ??= new PollingCounter(TotalReturnedCounterName, this, () => Interlocked.Read(ref _totalReturned))
            {
                DisplayName = "Total Returned"
            };

            _notReturnedPerSecondCounter ??= new IncrementingPollingCounter(NotReturnedPerSecondCounterName, this, () => Volatile.Read(ref _totalNotReturned))
            {
                DisplayName = "Not-Returned Rate",
                DisplayRateTimeScale = TimeSpan.FromMinutes(1)  // Application Insights is 1 minute
            };

            _totalNotReturnedCounter ??= new PollingCounter(TotalNotReturnedCounterName, this, () => Volatile.Read(ref _totalNotReturned))
            {
                DisplayName = "Total Not-Returned"
            };

            _totalUsedCounter ??= new PollingCounter(TotalUsedCounterName, this, () => _totalUsed)
            {
                DisplayName = "Total Used"
            };
        }
    }

    public static IEnumerable<string> GetCounterNames()
    {
        yield return CreatedPerSecondCounterName;
        yield return ReturnedPerSecondCounterName;
        yield return NotReturnedPerSecondCounterName;
        yield return TotalCreatedCounterName;
        yield return TotalReturnedCounterName;
        yield return TotalNotReturnedCounterName;
        yield return TotalUsedCounterName;
    }
}

Application Insights sammelt standardmäßig keine Counters, daher müssen diese selbst aktiviert werden. Das machen wir mit (sorry für den vielen Code, aber dort seht ihr welche Counter wir sonst noch aktiviert haben):


using System.Collections.Generic;
using Microsoft.ApplicationInsights.Extensibility.EventCounterCollector;
using MyCSharp.Portal.Diagnostics;

namespace MyCSharp.Portal.Monitoring.Diagnostics;

public static class AppInsightsExtensions
{
    public static void AddMyCSharpEventCounters(this EventCounterCollectionModule module)
    {
        AddRuntimeCounters(module);
        AddHostingCounters(module);
        AddKestrelCounters(module);
        //AddHttpConnectionCounters(module);    // counters for SignalR
        AddDnsCounters(module);
        AddEntityFrameworkCounters(module);

        foreach (string eventCounterName in ContentRendererEventSource.GetCounterNames())
            module.Counters.Add(new EventCounterCollectionRequest(ContentRendererEventSource.EventSourceName, eventCounterName));

        foreach (string eventCounterName in StringBuilderPoolEventCounterSource.GetCounterNames())
            module.Counters.Add(new EventCounterCollectionRequest(StringBuilderPoolEventCounterSource.EventSourceName, eventCounterName));

        foreach (string eventCounterName in BBCodeLinkToUrlTextFormatterEventSource.GetCounterNames())
            module.Counters.Add(new EventCounterCollectionRequest(BBCodeLinkToUrlTextFormatterEventSource.EventSourceName, eventCounterName));

        foreach (string eventCounterName in SmtpMailSenderEventSource.GetCounterNames())
            module.Counters.Add(new EventCounterCollectionRequest(SmtpMailSenderEventSource.EventSourceName, eventCounterName));
    }

    private static void AddRuntimeCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "System.Runtime";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "time-in-gc";
            yield return "alloc-rate";
            yield return "cpu-usage";
            yield return "exception-count";
            yield return "gc-heap-size";
            yield return "gen-0-gc-count";
            yield return "gen-0-size";
            yield return "gen-1-gc-count";
            yield return "gen-1-size";
            yield return "gen-2-gc-count";
            yield return "gen-2-size";
            yield return "loh-size";
            yield return "poh-size";
            yield return "gc-fragmentation";
            yield return "monitor-lock-contention-count";
            yield return "active-timer-count";
            yield return "threadpool-completed-items-count";
            yield return "threadpool-queue-length";
            yield return "threadpool-thread-count";
            yield return "working-set";
        }
    }

    private static void AddHostingCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "Microsoft.AspNetCore.Hosting";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "current-requests";
            yield return "failed-requests";
            yield return "requests-per-second";
            yield return "total-requests";
        }
    }

    private static void AddHttpConnectionCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "Microsoft.AspNetCore.Http.Connections";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "connections-duration";
            yield return "current-connections";
            yield return "connections-started";
            yield return "connections-stopped";
            yield return "connections-timed-out";
        }
    }

    private static void AddKestrelCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "Microsoft-AspNetCore-Server-Kestrel";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "connection-queue-length";
            yield return "connections-per-second";
            yield return "current-connections";
            yield return "current-tls-handshakes";
            yield return "failed-tls-handshakes";
            yield return "request-queue-length";
            yield return "tls-handshakes-per-second";
            yield return "total-connections";
            yield return "total-tls-handshakes";
        }
    }

    private static void AddDnsCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "System.Net.NameResolution";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "dns-lookups-requested";
            yield return "dns-lookups-duration";
        }
    }

    private static void AddEntityFrameworkCounters(EventCounterCollectionModule module)
    {
        const string EventSourceName = "Microsoft.EntityFrameworkCore";

        foreach (string eventCounterName in GetCounters())
            module.Counters.Add(new EventCounterCollectionRequest(EventSourceName, eventCounterName));

        static IEnumerable<string> GetCounters()
        {
            yield return "active-db-contexts";
            yield return "total-queries";
            yield return "queries-per-second";
            yield return "total-save-changes";
            yield return "save-changes-per-second";
            yield return "compiled-query-cache-hit-rate";
            yield return "total-execution-strategy-operation-failures";
            yield return "execution-strategy-operation-failures-per-second";
            yield return "total-optimistic-concurrency-failures";
            yield return "optimistic-concurrency-failures-per-second";
        }
    }
}

registriert wird das Ganze im Startup mittels


public static class AspNetCoreMonitoringRegistration
{
    public static IServiceCollection AddMyCSharpAspNetCoreMonitoring(this IServiceCollection services)
    {
        services.AddApplicationInsightsTelemetry();
        services.AddSingleton<ITelemetryInitializer, HttpRequestUserInformationTelemetryInitializer>();

        services.ConfigureTelemetryModule<EventCounterCollectionModule>((module, _) =>
        {
            module.AddMyCSharpEventCounters();
        });

        return services;
    }
}

Metriken vom Forum für .NET 6

In performance-verbesserungen-in-net-6 wurde ja schon allgemein über die Verbesserungen von / mit .NET 6 berichtet, nun wollen wir aber ein Metriken / Charts von unserem Forum anschauen.

In den jeweiligen Diagrammen ist per roter vertikaler Linie der Zeitpunkt des Upgrades von .NET 5 auf .NET 6 gekennzeichnet.
Es gab im dargestellten Zeitraum keine Änderungen am Forum-Code!. D.h. die Effekte beruhen auf Verbesserungen in .NET 6, ASP.NET Core 6 und EF Core 6. Od. anders ausgedrückt: alleine durch ein Upgrade auf .NET 6 bekommt man Leistung geschenkt.

Das Forum an sich ist nicht unbedingt als "CPU-bound" zu sehen, der Großteil ist "IO-bound":* HTTP-Request entgegennehmen

  • Holen von Daten aus der Datenbank
  • HTML-Ausgabe vorbereiten -- hauptsächlich Rendern vom BBCode*
  • HTTP-Response senden

* das ist der einzig wirkliche CPU-bound Teil, aber diese Komponenten haben wir soweit optimiert, dass sind in den CPU-Profiles und auch GC-Profiles nicht mehr so einfach zu finden sind 🙂

Da "IO-bound" dominant ist, geht es bei Performance-Optimierungen v.a. um das Vermeiden von Allokationen, da so der GC weniger Arbeit hat.
Dies wurde in ASP.NET Core 6 und auch in EF Core 6 vorangetrieben, so dass diese Effekte bei uns deutlich zu sehen sind.

Die nachfolgenden Diagramme -- aufgeteilt auf mehrere Beiträge -- der Metriken kommentiere ich nicht gesondert (nur Mini-Anmerkungen), sondern will sie einfach wirken lassen.
Bei Bedarf stellt eine Frage und wir schauen ob und wie wir den Themenpunkt klären können.

Ich plane demnächst* einen weiteren Beitrag mit ein paar statistischen Einblicken ins Forum, wie Verteilung der Anzahl der Beiträge pro Thread, Länge der Beiträge, etc.
Diese Werte spielten bei der Optimierung der Foren-Software eine wichtige Rolle, da so bestimmte Schwellenwerte festgelegt werden konnten.

* kanns leider nicht genauer terminisieren, da ich sehr viel zu tun habe

mfG Gü

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Allocation Rate (Objekte / s)

Man beachte die ausgeprägte Korrelation zwischen diesen beiden Metriken (CPU Usage und Allocation Rate) (da IO-bound).

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

GC Heap Size (# Objects)

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

EF Query Cache Hit-rate (%)

Anmerkung: bis zum Ende des Sommers hatten wir eine Hit-Rate von 100 %, aber durch irgendein Update sank diese auf 50-60 %. Bisher konnten wir nicht wirklich exakt lokalisieren warum das so war. Aber da wir jetzt wieder bei 100 % sind, werden wir diese Issue wohl schließen können.

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Thread count (# Threads)

Anmerkung: die VM hat 4 Kerne

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Thread Pool completed work items (# Items / s)

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

16.807 Beiträge seit 2008
vor 2 Jahren

Hallo zusammen,

ich bin sehr zufrieden - vor allem weil die Kosten sinken 🙂
Kann da nur ein ganz großes Danke an gfoidl (und das .NET Team) sagen, dass wir so sehr von den Performance-Neuerungen profitieren 🙂

T
2.219 Beiträge seit 2008
vor 2 Jahren

Mich würde interessieren ob/was für Änderungen von eurer Seite gemacht wurden.
Vermutlich habt ihr auch einige Stellschrauben gedreht um da noch etwas besseres Verhalten zu bekommen.
Wenn diese Änderungen ohne euer Zutun nur durch einen Wechsel von .NET 5 auf 6 kamen, wäre das schon sehr beeindruckend.

T-Virus

Developer, Developer, Developer, Developer....

99 little bugs in the code, 99 little bugs. Take one down, patch it around, 117 little bugs in the code.

16.807 Beiträge seit 2008
vor 2 Jahren

Mich würde interessieren ob/was für Änderungen von eurer Seite gemacht wurden.

Ausser Pakete aktualisieren haben wir bei .NET 6 nicht viel geändert; halt Breaking Changes gepflegt.
Wir haben damit im Mai begonnen, aber weil einige Dependencies noch nicht mit .NET 6 kompatibel waren, hat sich das gezogen.
Erst Ende Nov war alles bereit.
Dazu muss man sagen, dass dank gfoidl ein Großteil der CodeBase bereits sehr optimiert ist.

Die neuen Features in .NET 6 (und EF Core) ermöglichen uns nun aber noch mehr Dinge zu optimieren.

T
2.219 Beiträge seit 2008
vor 2 Jahren

Das ist echt toll 🙂
Mal schauen was zukünftige .NET Updates noch alles rausholen können
Gibt es hier auch ein paar Zahlene wie sich z.B. die Requests pro Sek. verbessert haben?
Diese dürften sich vermutlich auch verbessert haben ohne weiteres zutun.

T-Virus

Developer, Developer, Developer, Developer....

99 little bugs in the code, 99 little bugs. Take one down, patch it around, 117 little bugs in the code.

gfoidl Themenstarter:in
6.911 Beiträge seit 2009
vor 2 Jahren

Hallo T-Virus ,

Vermutlich habt ihr auch einige Stellschrauben gedreht um da noch etwas besseres Verhalten zu bekommen.

Ein paar Stellschrauben-Änderungen haben wir geplant, aber absichtilch noch nicht umgesetz, da wir den reinen Vergleich von .NET 5 -> .NET 6 sehen wollten.
Bei solchen Schritten wollen wir nicht "so viel wie möglich", sondern "Schritt für Schritt", da sich so auch der Einfluss der einzelnen Änderungen besser sehen lässt (und wir ja auch davon lernen können und wollen).

Mehr Artikel in dieser Hinsicht sind geplant (eigentlich eh schon lange), aber die Zeit ist da ein Antagonist (wie so oft).

Gibt es hier auch ein paar Zahlene wie sich z.B. die Requests pro Sek. verbessert haben?

Ja, aber das lass ich Abt beantworten 😉
Persönlich finde ich die Application efficiency = (Requests per second) / (CPU utilization of application) interessanter als die normalen Reqs/s.

mfG Gü

Stellt fachliche Fragen bitte im Forum, damit von den Antworten alle profitieren. Daher beantworte ich solche Fragen nicht per PM.

"Alle sagten, das geht nicht! Dann kam einer, der wusste das nicht - und hat's gemacht!"

16.807 Beiträge seit 2008
vor 2 Jahren

Gibt es hier auch ein paar Zahlene wie sich z.B. die Requests pro Sek. verbessert haben?

Ja, geht so - der Bottleneck ist mittlerweile die Datenbank, aber das ist normal.
Eine Webinstanz skaliert immer besser als DBs.

Trotzdem haben wir nen ganz guten Puffer, dass wir auch die üblichen Angriffe abwehren können.
D.h. pro Web-Instanz konnten wir zuvor ca. 580 Req/s beantworten, jetzt sind es ~980/s.
Auf die Web-Instanz selbst prasselt aber nich so viel runter im Normalzustand, weil wir ja auch nen Caching- und Firewall-System davor haben.