Diagnose von Threadpool-Mängeln

.NET-Anwendungen verwenden Threads, um ihre Arbeitsanweisungen auszuführen. Beispiele hierfür sind die Abarbeitung eines Requests in einer Webanwendung oder auch die Parallelisierung von Arbeitsanweisungen, wobei mehrere Threads parallel ablaufen können und die Ergebnisse am Ende zusammengeführt werden. Ein Threadpool stellt eine vordefinierte Anzahl solcher Threads zur Verfügung, die in der Regel bereits angelegt sind. Die Verwendung eines Threadpools ermöglicht es, vordefinierte Threads einfach aus dem Pool zu verwenden, ohne sie immer wieder neu erzeugen zu müssen.

Ein Threadpool-Engpass (im Englischen auch „Threadpool Exhaustion“ genannt) tritt auf, wenn ein Thread aus dem Threadpool angefordert wird, dieser aber keinen mehr zur Verfügung stellen kann. Bei zeitintensiven Operationen oder auch bei hoher Last auf einem Webserver kann es dann passieren, dass User sehr lange auf eine Antwort warten müssen. Auch wenn die Größe des Threadpools unter .NET in gewissen Grenzen variabel ist, müssen User warten, sobald die maximale Anzahl verfügbarer Threads erreicht ist. Außerdem benötigt eine Änderung der Threadpoolgröße Zeit.

Das Problem

Die Anwendung ist eine ASP.NET Core WebAPI unter .NET 8, die als Basis für eine Single-Page-Application (SPA) verwendet wird. Bisher haben wir sie auf einem IIS unter Windows gehostet, wo sie sehr schnell lief. Nach der Migration auf Linux in einem Docker-Container haben sich die Antwortzeiten fast verdoppelt. Das ist untypisch, deshalb wollen wir dem Problem auf den Grund gehen.

Die Untersuchung des Problems

Für die Diagnose solcher Probleme bringt .NET einige Tools mit, die in unserem Fall allerdings im Docker-Container installiert werden müssen. Insbesondere benötigen wir das Tool dotnet-counters, das Teil des Dotnet Cli Diagnostic Tools ist. Diese können mit einem Trick im Docker-Image installiert werden. Man installiert sie zuerst in der Publish Stage, die auf dem .NET-SDK Image basiert. Danach kopiert man die Tools im Final Stage in das finale Image. Dieser Umweg ist notwendig, da es im finalen Image kein .NET-SDK gibt und man daher die Tools nicht installieren kann. Der folgende Code zeigt ein entsprechendes Dockerfile.

	
	FROM mcr.microsoft.com/dotnet/aspnet:8.0 AS base
		WORKDIR /app
		EXPOSE 80
		EXPOSE 443
		FROM mcr.microsoft.com/dotnet/sdk:8.0 AS build
		WORKDIR /src
		COPY ["Api/Api.csproj", "Api/"]
		RUN dotnet restore "Api/Api.csproj"
		COPY . .
		WORKDIR "/src/Api"
		RUN dotnet build "Api.csproj" -c Release -o /app/build -p:Linux=true --no-restore
		FROM build AS publish
		RUN dotnet publish "Api.csproj" -c Release -o /app/publish /p:UseAppHost=false -p:Linux=true --no-restore
		#installing tools
		RUN dotnet tool install --tool-path /tools dotnet-trace --configfile Nu-Get.config \
		 && dotnet tool install --tool-path /tools dotnet-counters --configfile Nu-Get.config \
		 && dotnet tool install --tool-path /tools dotnet-dump --configfile Nu-Get.config \
		 && dotnet tool install --tool-path /tools dotnet-gcdump --configfile Nu-Get.config 
		FROM base AS final
		# Copy dotnet-tools to base image
		WORKDIR /tools
		COPY --from=publish /tools .
		WORKDIR /app
		COPY --from=publish /app/publish .
		ENTRYPOINT ["dotnet", "Api.dll"]
	

Danach kann man die .NET Diagnostic Tools im App-Container starten.

Es ist auch wichtig, den „Fast Mode“ von Visual Studio zu deaktivieren, denn im Fast Mode ruft Visual Studio docker build mit einem Argument auf, das Docker anweist, nur die erste Stage in der Docker-Datei zu erstellen (normalerweise die base Stage), die DLLs der Anwendung werden auf dem lokalen PC erstellt und dann als Mount in das Image eingebunden (mehr dazu hier). Um den „Fast Mode“ zu deaktivieren, muss der Parameter ContainerDevelopmentMode in der Projektdatei (.csproj) auf den Wert „Regular“ gesetzt werden.

	
	<PropertyGroup>
		   <ContainerDevelopmentMode>Regular</ContainerDevelopmentMode>
		</PropertyGroup>
	

Nach dem Start der App suchen wir unseren Container mit dem Kommandozeilenbefehl docker container ls und starten dann eine Kommandozeile (bash) mit docker exec -it <container id> bash. In dieser Kommandozeile können Sie dann die Dotnet Diagnostic Tools verwenden. In unserem Fall starten wir dotnet-counters mit dem Befehl /tools/dotnet-counters.

Mit dotnet-counters ps kann man sich alle vorhandenen .NET-Prozesse ansehen. Mit dem Befehl dotnet-counters monitor –process-id=<id> kann man sämtliche Leistungsindikatorwerte überwachen, die über die API EventCounter oder Meter veröffentlicht werden. Beispielsweise kann man sich damit alle Dotnet-Metriken anzeigen lassen. Wichtige Metriken für die Analyse des Threadpools sind ThreadPool Queue Length und ThreadPool Thread Count.

Um das Problem zu reproduzieren, müssen wir das System unter Last setzen und das Verhalten beobachten. Hier kommt ein weiteres nützliches Tool ins Spiel: Bombardier. Bombardier ist ein https-Benchmarking-Tool und kann eine große Anzahl von Anfragen an einen Server senden, um zu sehen, wie die Anwendung reagiert.

Für die Auslastung habe ich den Endpunkt gewählt, der beim Laden der SPA-Seite am langsamsten war. Wir starten unsere Anwendung und erzeugen die Last mit Bombardier. Gleichzeitig sammeln wir die Dotnet-Metriken im Container mit dotnet-counters collect -process-id=<id>. Das Kommandoattribut collect bedeutet "Metriken in einer Datei sammeln".

Der Endpunkt hat eine maximale Wartezeit von 1,17 Minuten bei einer Auslastung von 125 Verbindungen über 30 Sekunden, was für eine API natürlich viel zu lang ist. Aber jetzt kennen wir den Flaschenhals unserer Anwendung. Schauen wir uns die Metriken des Threadpools an, genauer gesagt die Anzahl der Threads. Hier sieht man eine grafische Darstellung des Threadpools während der Auslastung:

Hier sieht man, dass sich die Anzahl der Threads verdreifacht und dann bei 125 stabilisiert. Wie bereits erwähnt, erhöht das System die Anzahl der verfügbaren Threads, wenn keine freien Threads mehr zur Verfügung stehen. Dafür benötigt die Runtime jedoch wertvolle Zeit. Der langsame Anstieg der Threadpool-Threads mit einer CPU-Auslastung von deutlich unter 100 Prozent deutet darauf hin, dass ein Engpass im Threadpool die Ursache für den Performance-Engpass ist.

Um das Problem besser zu verstehen, kann man auch Traces der Anwendung sammeln. Dies geschieht mit dem Diagnosetool dotnet-trace. Der vollständige Befehl lautet: /tools/dotnet-trace collect -p <process-id> --format speedscope.

Ich habe die Trace-Daten hier nur für eine Anfrage gesammelt, um zu verstehen, womit die Threads während der Benutzeranfrage beschäftigt sind. Auf der Seite https://www.speedscope.app können die Daten heruntergeladen und in Form eines Flame Graphs betrachtet werden. Flame Graphen visualisieren, wo im Code die meiste Zeit verbracht wird, und verwenden dazu nichts anderes als ihre Stack Traces. Alle ähnlichen Funktionsaufrufe werden nach Stacktiefe gruppiert. Auf diese Weise kann man herausfinden, wie lange eine bestimmte Funktion während des Profiling ausgeführt wurde.

Zunächst sehen wir hier die Main()-Methode der Anwendung.

Der Flamegraph zeigt die Threads und Methoden, die ausgeführt werden, sowie die dafür benötigte Zeit. ASP.NET Core verwendet sehr viele Threads und wir müssen nun den Thread finden, in dem der Code unserer Anwendung ausgeführt wird. In diesem Fall habe ich ihn hier gefunden:

Wir sehen, dass hier eine Methode des Datenbank Repository ausgeführt wird. Im Vergleich zu anderen Methoden benötigt diese Methode sehr viel Zeit.

Weiter unten sehen wir, dass die Methode auf das Entity Framework zugreift und noch weiter unten, wie das Entity Framework die Daten von der Datenbank erhält. Das System wartet also darauf, dass die Datenbank die Daten liefert und blockiert den Thread, bis dies der Fall ist. Dies ist wahrscheinlich die Ursache des Problems.

Das Beheben des Problems

Um das Problem zu lösen, untersuchen wir die Controller-Aktionen und versuchen zu verstehen, was die Threads in der Anwendung blockiert. Die Analyse zeigt, dass es mehrere Aufrufe an das Datenbank-Repository gibt, die nicht asynchron ausgeführt werden.

Der Unterschied zwischen einem synchronen und einem asynchronen Aufruf ist relativ einfach zu verstehen. Bei einem synchronen Aufruf wird die Anfrage in einem Thread bearbeitet und blockiert diesen Thread, bis der Aufruf vollständig abgearbeitet ist. Wenn nun viele Anfragen an die Datenbank gestellt werden, die eine längere Zeit in Anspruch nehmen, brauchen die Threads entsprechend lange, um die Ergebnisse zurückzugeben.

Ein asynchroner Aufruf verhält sich etwas anders. In dem Moment, in dem eine Operation längere Zeit in Anspruch nimmt, wird der Thread „freigegeben“ und kann bereits mit der Bearbeitung der nächsten Anfrage beginnen. Im Hintergrund läuft dann die Anfrage an die Datenbank und sobald diese abgeschlossen ist, wird das Ergebnis abgeholt und an den Aufrufer zurückgegeben. Auf diese Weise können wenige Threads eine große Anzahl von Anfragen in angemessener Zeit bearbeiten.

In diesem speziellen Fall sah der Code ungefähr so aus (kein echter Anwendungscode, nur zur Demonstration):

	
	//Code of controller action
		[HttpGet]
		[Route("{culture:required}/mutual-funds/{identifier:required}")]
		public async Task<ActionResult<PageDataDto?>> GetDataAsync(string culture, string identifier, CancellationToken cancellationToken)
		{
		    PageDataDto? result =
		        await _service.CreatePageDataDto();
		    return Ok(result);
		}
		//===========================================================================
		//Service method code
		public async Task<PageDataDto?> CreatePageDataDto(…)
		{
		    //Code omitted
		    //…
		    var data1 = _repostory.Method1(…);
		    var data2 = _repostory.Method2(…);
		    //Code omitted
		    //…
		    var data10 = _repostory.Method10(…);
		    //Code omitted
		    //…
		    return result;
		}
	

Nach der Recherche habe ich den Code umgeschrieben und alle Repository-Methoden auf asynchronen Code umgestellt. Dadurch werden die Threads nicht mehr blockiert und stehen für weitere Anfragen zur Verfügung:

	
	//Service method code
		public async Task<PageDataDto?> CreatePageDataDtoAsync(CancellationToken cancellationToken)
		{
		    //Code ausgeführt auf Thread 1
		    //…
		    var data2 = await _repostory.Method1Async(..., cancellationToken);
		    //Thread 1 wurde freigelassen
		    //Code kann auf dem anderen Thread ausgeführt sein
		    //…
		    return result;
		}
	

Nach diesen Änderungen ist die Performance um ein Vielfaches besser geworden:

Und hier ist die Thread-Anzahl nach der Optimierung:

Diese Ergebnisse zeigen, dass das Problem erfolgreich gelöst wurde.

Ihr möchtet mehr über spannende Themen aus der adesso-Welt erfahren? Dann werft auch einen Blick in unsere bisher erschienenen Blog-Beiträge.