Laden...

Laufzeit asynchroner Funktion beim ersten Aufruf langsamer

Erstellt von johnnycc vor 5 Jahren Letzter Beitrag vor 5 Jahren 2.103 Views
J
johnnycc Themenstarter:in
9 Beiträge seit 2018
vor 5 Jahren
Laufzeit asynchroner Funktion beim ersten Aufruf langsamer

Die asynchrone Funktion foo wird 6 Mal aufgerufen und mit .Result auf das Ergebnis gewartet.

using System;
using System.Threading.Tasks;
using System.Diagnostics;

public class Program
{
	public static void Main(string[] args)
	{
		Stopwatch sm = new Stopwatch();
		
		sm.Start();
		var result1 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 1 : " + sm.Elapsed.ToString());
		
		sm.Reset();
		sm.Start();
		var result2 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 2 : " + sm.Elapsed.ToString());
		
		sm.Reset();
		sm.Start();
		var result3 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 3 : " + sm.Elapsed.ToString());
		
		sm.Reset();
		sm.Start();
		var result4 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 4 : " + sm.Elapsed.ToString());
		
		sm.Reset();
		sm.Start();
		var result5 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 5 : " + sm.Elapsed.ToString());
		
		sm.Reset();
		sm.Start();
		var result6 = foo().Result;
		sm.Stop();
		Console.WriteLine("duration 6 : " + sm.Elapsed.ToString());
	}

	public static async Task<int> foo()
	{
		await Task.Run(() =>
		{
			var x = 0;
			for (int i = 0; i < 100; i++)
			{
				x++;
			}
		});
		return 42;
	}
}

Der erste Aufruf dauert immer länger. Z.B.:

duration 1 : 00:00:00.0016609
duration 2 : 00:00:00.0001197
duration 3 : 00:00:00.0001045
duration 4 : 00:00:00.0000632
duration 5 : 00:00:00.0000636
duration 6 : 00:00:00.0000635

Was ist der Grund?

T
2.219 Beiträge seit 2008
vor 5 Jahren

Kann sein, dass beim ersten Aufruf ein Thread für den Task reserviert wird der dann auch wiederverwendet wird für die anderen Tasks und er deshalb etwas mehr Zeit braucht.
Alle weiteren Durchläufe können dann auf den reservierten Thread laufen.

Kann aber auch sein, dass der JIT Compiler kurz den Code optimiert.
Wäre aber bei solchem Test Code egal was beim ersten Aufruf hier zeit frisst.

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 5 Jahren

Es könnte an dem TaskScheduler liegen, aber natürlich auch an der Schleife.
So eine Schleife ist so ziemlich der größte potentieller Messfehler solch einer Angelegenheit.
Es ist überhaupt nicht garantiert, dass die Schleife immer die gleiche Zeit benötigt; der Code wird schließlich zur Laufzeit optimiert.

Viel besser und genauere Ergebnisse liefert an dieser Stelle ein Delay.

await Task.Run(async () => { await Task.Delay(200); });

Mit dem Delay unterscheiden sich zumindest bei mir die Ergebnisse kaum noch.

Zudem ist async/await bzw. asynchroner Code auch überhaupt nicht dafür da, dass Code schneller wird - das ist überhaupt nicht das Ziel und aufgrund des Overheads roh auch überhaupt nicht möglich.

PS: .Result ist ein absoluter Pitfall und man sollte sich dessen Verwendung erst gar nicht angewöhnen.
Wenn eine asynchrone Methode doch synchron aufgerufen werden soll, dann verwendet man foo().GetAwaiter().GetResult().

Ansonsten: Consolenanwendungen haben auch ein Async Main von Haus aus (seit C# 7).

W
872 Beiträge seit 2005
vor 5 Jahren

Für solche Aufgaben solltest Du benchmarkdotnet nehmen.
StopWatch ist auch nicht sauber für das Messen von Microbenchmarks.

6.911 Beiträge seit 2009
vor 5 Jahren

Hallo johnnycc,

Der erste Aufruf dauert immer länger. Z.B.:

.NET basiert aktuell auf einem JIT (just in time compiler), der den vom C#-Compiler generierten IL-Code erst zu ausführbaren Maschinencode übersetzen muss. Dieses Übersetzung IL -> Maschinencode basiert beim ersten Aufruf*.
D.h. die Methode foo muss vom JIT verarbeitet werden, genauso wie Task.Run, etc. Eben alles das bisher noch nicht geJITet wurde.

Weiters ist in .NET vieles auf "lazy-initialisation" getrimmt. D.h. -- ähnlich wie beim JITen -- dass beim ersten Zugriff die Ressourcen, die benötigt werden, bereitgestellt werden. Dies hat den Vorteil gegenüber "eager-initialisation", bei dem alle Ressourcen unmittelbar beim Start zur Verfügung gestellt werden, dass nur jenes bereitgestellt wird, das auch tatsächlich benötigt wird -- das sogenannte "you pay for what you play".
Hier ist es bei Task.Run, das dem TaskScheduler anweist den übergebenen Delegaten auszuführen, nicht anders. Kurz: die benötigte TPL-Infrastruktur wird beim ersten Aufruf bereitgestellt. Für die folgenden Aufrufe sind diese Schritte nicht mehr nötig.

Aus diesen Gründen sollten bei Messungen eine Warmlaufphase eingebaut werden, um diesen "Start-Overhead" zu eliminieren. Tools wie das zitierte ttps://benchmarkdotnet.org/ machen das genau so.

* mit .NET Core 2.2 wird ein Tiered-Jitting der Standard werden, d.h. der IL-Code wird ohne Optimierungen nach Maschinencode übersetzt und falls die Runtime bemerkt dass eine Methode "heiß" ist, so wird diese erneut kompiliert, aber mit vielen Optimierungen, und anschließend diese optimierte Version verwendet. Unterm Strich soll das schnellere Startzeiten der Anwendung bringen und im Betrieb bessere Laufzeiten, da eben besser optmierter Code verwendet werden kann. Der JIT muss bis dato immer die Balance zwischen Schnelligkeit der Kompilierung und Optimierung (zeitaufwändig) treffen.

Hallo weismat,

StopWatch ist auch nicht sauber für das Messen von Microbenchmarks.

Warum? https://benchmarkdotnet.org/ misst intern auch mit der Stopwatch.
Der Vorteil von BDN ist dass es mehrere Messungen durchführt (inkl. Warmup, etc.) und dann statistische Aussagen liefert, so dass Messfehler (Standardabweichung, ...) ins Ergebnis einfließen können.
Das lässt sich selbst auch umsetzen...nur wenn es das mit BDN schon gibt kann auch das fertige getestete Tool verwendet werden, zumals die Verwendung recht einfach ist.

Hallo Abt,

aber natürlich auch an der Schleife.
So eine Schleife ist so ziemlich der größte potentieller Messfehler solch einer Angelegenheit.
Es ist überhaupt nicht garantiert, dass die Schleife immer die gleiche Zeit benötigt; der Code wird schließlich zur Laufzeit optimiert.

Mag sein dass ich dich hier falsch verstanden habe, aber eine for-Schleife ist so ziemlich das exakteste in solch einer Angelegenheit 😉
Tiered JITing außer Acht gelassen: ist der Code, der die Schleife beinhaltet, einmal durch den JIT gelaufen, so bleibt dieser Maschinencode bis ans Ende des Prozesses auch gleich. Somit sind es immer die exakt gleichen Anweisungen die in der Schleife ausgeführt werden.
Mögliche Unsicherheiten für die Messungen kommen hier nur den CPU-Instructioncache ins Spiel, aber bei so einem kleinen Schleifenrumpf ist mit ziemlicher Sicherheit davon auszugehen, dass hier kein Cachemiss auftreten wird beim Rücksprung an den Schleifenbeginn.

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 5 Jahren

Somit sind es immer die exakt gleichen Anweisungen die in der Schleife ausgeführt werden.

Nur, dass Anweisungen selbst nichts (real genaues) über die Laufzeit aussagen; daher stimme ich Dir nicht zu, dass die Schleife immer die gleiche Zeit benötigen würde. Jedenfalls nicht in einer wahrscheinlichen Theorie.
Eine Schleife ist durch das potentielle Risiko des unterschiedlichen Laufzeitverhaltens einfach kein geeignetes Werkzeug für eine zuverlässige Laufzeitmessung; vor allem nicht im Mikro-Bereich.

Natürlich ist bei dieser Schleife hier der Range deutlich geringer und damit das Potential geringer; es bleibt jedoch ein vergleichsweise schlechtes Beispiel von simulierter Arbeit bei solch einer Overhead-Messung.

4.931 Beiträge seit 2008
vor 5 Jahren

Der Code sollte zumindestens irgendetwas (sinnvolles) mit der Variablen x nach der Schleife machen, sonst kann es sein, daß diese komplett wegeliminiert wird.

6.911 Beiträge seit 2009
vor 5 Jahren

Hallo Abt,

Anweisungen selbst nichts (real genaues) über die Laufzeit aussagen;

Das stimmt, da eben nicht davon ausgegangen werden kann, dass nur ein Prozess exklusiv alle Ressourcen besitzt und auch die CPU ihrerseits Optimierungen durchführen kann. Dem widerspreche ich ja nicht.
Sondern "dass eine Schleife der größte potentielle Messfehler sei" und "der Code zur Laufzeit optimiert werde", denn das stimmt beides nicht.

Letzteres nicht, da der JIT bzw. die Runtime von .NET nicht so arbeitet.
Durch Tiered-JITing (s.o.) wird sich das ändern, aber das ist momentan Preview.

Ersterers stimmt nicht, da die Schleife trivial und keine weiteren unbekannten Abhängigkeiten hat, die nicht vorhersehbar und stationär sind. In x64 Maschinencode ist es nur:


L0000: xor eax, eax
L0002: xor edx, edx
L0004: inc eax
L0006: inc edx
L0008: cmp edx, 0x64
L000b: jl L0004

Die CPU führt immer die gleichen Befehle und Sprünge aus. Die beiden inc werden wohl durch das Pipelining "gleichzeitig" ausgeführt werden und der Branchpredictor wird den Sprung auch korrekt (zu 99%, hier da i < 100) vorhersagen.
Wenn nun multi-tasking vom OS außer Acht gelassen wird, genauso wie automatische Takterhöhung der CPU, so ergibt sich dafür die gleiche Laufzeit bei jedem Durchlauf*. Die CPU hat alle Befehle dekodiert, usw. und es gibt keine Speicherzugriffe, da alle Variablen in Register gehalten werden und somit keine weiteren Latenzen die unterschiedlich sein können.

* der Branchpredictor gehört da noch berücksichtigt, daher wäre es bei Benchmarks auch wichtig eine Warmup-Phase zu haben, damit eben alles bereit ist für Messungen die stationäre Statistiken liefern sollen

Unabhängig davon geht es dem OT ja darum den Overhead des asynchronen Aufrufs zu ermitteln bzw. zu vergleichen. Daher sollte in der async-Methode auch so wenig wie möglich Arbeit getätigt werden, damit eben Aufruf-Overhead >> Arbeit ist. Sonst würde eher nur die Arbeit gemessen werden und der Overhead -> 0.
Daher ist der Vorschlag mit

  
await Task.Run(async () => { await Task.Delay(200); });  
  

auch suboptimal, da der Overhead untergeht und das erklärt auch warum sich die Ergebnisse bei dir kaum mehr unterscheiden.
Außerdem ist ein Task.Delay, das auf einem Timer basiert, wohl eine größere Messunsicherheit als eine for-Schleife.

Randnotiz:

Eine Schleife ist durch das potentielle Risiko des unterschiedlichen Laufzeitverhaltens einfach kein geeignetes Werkzeug für eine zuverlässige Laufzeitmessung; vor allem nicht im Mikro-Bereich. https://benchmarkdotnet.org verwendet gerade Schleifen um Mikrobenchmarks zu ermöglichen. Genauso alle anderen Benchmark-Tools, die den Namen verdienen.

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!"