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ü
