Hysteresis effect on threadpool hill-climbing

[sebastienros]

We have noticed a periodic pattern on the threadpool hill-climbing logic, which uses either n-cores or n-cores + 20 with an hysteresis effect that switches every 3-4 weeks:

The main visible impact is on performance results, here is an example with JsonPlatform mean latency, but some scenarios are also impacted in throughput:

This happens independently of the runtime version, meaning that using an older runtime/aspnet/sdk doesn't change the "current" value of the TP threads.

It is also independent of the hardware, and happens on all machines (Linux only) on the same day. These machines have auto-updates disabled. Here are ARM64 (32 cores), AMD (48 cores), INTEL (28 cores):

Disabling hill-climbing restores the better perf in this case, so it is believe that fixing this variation will actually have a negative impact on perf for these scenarios.

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[KevinCathcart]

The whole period of square wave sounds an awful lot like it is around 49.7 days. That is how long it takes GetTickCount() to wrap around. On POSIX platforms the platform abstraction layer implements this, and the value returned for that is based not on uptime but on wall clock time, which matches with all machines changing on the same day.

In managed code GetTickCount is exposed as Environment.TickCount a signed integer. The pasted chart's Y axis is provides no precision but it looks the capped thread counts at cpu count is happening when Environment.ThreadCount is negative, and the +20 is happening when it is positive.

If I am right, the change over dates would be (give or take a day or so due to timezones, what time of day data was taken, etc):
Thu Jan 14 2021
Sun Feb 07 2021
Thu Mar 04 2021
Mon Mar 29 2021
Fri Apr 23 2021

What is unclear to me is where the bug is. All the TickCount usages in the portable thread pool code appear at first glance to be doing the right thing. But if these dates match up, then this sort of thing is pretty clearly the cause. It could potentially be a different api from Environment.TickCount that is also derived from GetTickCount().

Hope this helps.

[sebastienros]

@KevinCathcart I can confirm the dates match the ones you provided.

[KevinCathcart]

Ok, found a bug that could definitely be causing this:

runtime/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.cs

Lines 328 to 335 in 59d9d0d

	private bool ShouldAdjustMaxWorkersActive(int currentTimeMs)
	{
	// We need to subtract by prior time because Environment.TickCount can wrap around, making a comparison of absolute times unreliable.
	int priorTime = Volatile.Read(ref _separated.priorCompletedWorkRequestsTime);
	int requiredInterval = _separated.nextCompletedWorkRequestsTime - priorTime;
	int elapsedInterval = currentTimeMs - priorTime;
	if (elapsedInterval >= requiredInterval)
	{

currentTimeMs is Environment.TickCount, which in this case happens to be negative.

The if clause controls if the hill climbing is even run.

_separated.priorCompletedWorkRequestsTime and _separated.nextCompletedWorkRequestsTime start out as zero on process start, and only get updated if the hill climbing code is run.

Therefore, requiredInterval = 0 - 0 and elapsedInterval = negativeNumber - 0. This causes the if statement to become
if (negativeNumber - 0 >= 0 - 0) which returns false, so the hill climbing code is not run, and therefore the variables never get updated, and remain zero. The native version of the thread pool code does all math with unsigned numbers which would avoid such a bug, and it's equivalent part is not even quite the same math in the first place.

The easy fix here is probably to use unsigned arithmetic, but alternatively having the two fields get initialized to Environment.TickCount probably also works.

[danmoseley]

@jkoritzinsky

[jkoritzinsky]

cc: @kouvel

[kouvel]

Nice find, thanks! I'll put up a PR to fix it.

[sebastienros]

@KevinCathcart you passed the interview, start on Monday?

[GSPP]

In my estimation, essentially all uses of Environment.TickCount in the BCL are bugs and should be changed. Using TickCount makes the framework brittle for use in very long-running processes.

On POSIX platforms the platform abstraction layer implements this, and the value returned for that is based not on uptime but on wall clock time, which matches with all machines changing on the same day.

Is it true that in a freshly started .NET process, Environment.TickCount can be negative? That sounds like a significant breaking change. It also seems to be not good regardless of the breaking.

[jkotas]

Is it true that in a freshly started .NET process, Environment.TickCount can be negative?

Yes. It is like that since .NET Framework 1.0 and documentation explicitly mentions it. Nothing really broke here. I agree that it is a trap one has to be careful about.