Bug 44132 - Thread.Sleep () overhead too big
Summary: Thread.Sleep () overhead too big
Status: RESOLVED FIXED
Alias: None
Product: Runtime
Classification: Mono
Component: io-layer (show other bugs)
Version: unspecified
Hardware: PC Mac OS
: --- normal
Target Milestone: ---
Assignee: Bugzilla
URL:
Depends on:
Blocks:
 
Reported: 2016-09-09 01:24 UTC by Zoltan Varga
Modified: 2016-09-14 00:49 UTC (History)
4 users (show)

See Also:
Tags:
Is this bug a regression?: ---
Last known good build:


Attachments

Description Zoltan Varga 2016-09-09 01:24:44 UTC
From:

http://lists.dot.net/pipermail/mono-devel-list/2016-September/043813.html

Testcase:

<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
using System;
using System.Threading;
using System.Diagnostics;
using System.Threading.Tasks;
using System.Reflection;

namespace TestSleep
{
	class MainClass
	{
		public static void Main (string[] args)
		{
			Console.WriteLine (GetMonoVersion ());
			Console.WriteLine ("Sleep performance test. Press enter to exit.");

			using(var performanceCounter = new PerformanceCounter ("Process", "% Processor Time", GetInstanceName(Process.GetCurrentProcess()), false))
			using(var ctSource = new CancellationTokenSource ())
			{
				var thread = new Thread (RunWithSleep) 
				{
					Name = "Dummy Sleep Thread"
				};
				thread.Start (ctSource.Token);

				var readLine = Task.Run (() => Console.ReadLine());
				while (!readLine.IsCompleted)
				{ 
					Console.Write("\rCPU Time: " + performanceCounter.NextValue() + "%");
					Thread.Sleep(TimeSpan.FromSeconds(1));
				}

				ctSource.Cancel ();
				thread.Join ();
			}
		}

		/**
		 * This Thread starts to sleep for one millisecond continously 
		 * and cause high CPU usage in Mono version >= 4.4.
		 */
		static void RunWithSleep(object cancellationToken)
		{
			Console.WriteLine ("Starting 'Dummy Sleep Thread'");
			var cancel = (CancellationToken)cancellationToken;
			while(!cancel.IsCancellationRequested)
			{
				Thread.Sleep(1);
			}

			Console.WriteLine ("'Dummy Sleep Thread' done");
		}

		static string GetInstanceName(Process process)
		{
			PerformanceCounterCategory processCategory = new PerformanceCounterCategory("Process");
			string[] instanceNames = processCategory.GetInstanceNames();
			foreach (string name in instanceNames)
			{
				if (name.StartsWith(process.Id.ToString()))
				{
					return name;
				}
			}

			throw new Exception ("Failed to find instance name");
		}

		static string GetMonoVersion()
		{
			Type type = Type.GetType("Mono.Runtime");
			if (type != null)
			{
				MethodInfo displayName = type.GetMethod("GetDisplayName", BindingFlags.NonPublic | BindingFlags.Static);
				if (displayName != null)
					return displayName.Invoke (null, null).ToString();
			}

			return "Unknown Version";
		}
	}
}
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Comment 1 Zoltan Varga 2016-09-09 01:28:40 UTC
The overhead of the current interruptable sleep code is probably too big for short waits.
Comment 2 Emil 2016-09-09 11:24:43 UTC
I found the commit that is causing this bug:
https://github.com/mono/mono/commit/089c47f1c07bf250d76c36e04675569fc6f5b4ba#diff-e7e458b6256eaa730c145f14a666652aR1141

I tried to revert the commit, and that fixed the bug in my example.

The reasoning behind it, is that this line compares 100ns ticks https://github.com/mono/mono/commit/089c47f1c07bf250d76c36e04675569fc6f5b4ba#diff-e7e458b6256eaa730c145f14a666652aR1144

While the '(end - now) / 10 / 1000' expression may result in 0 ms if 'end - now' is less than a ms. 
https://github.com/mono/mono/commit/089c47f1c07bf250d76c36e04675569fc6f5b4ba#diff-e7e458b6256eaa730c145f14a666652aR1155

So what happens, is that the last millisecond of a sleep, is spin waited, since 'mono_coop_cond_timedwait' is called with zero as the time to wait. Theoretically the worst case is 10000 iterations. So this isn't only a problem for small waits, it's a general problem, where long sleeps also may get a CPU spike in the near end of its wait.
Comment 3 Emil 2016-09-09 14:36:35 UTC
Made a pull-request with the most simple approach
https://github.com/mono/mono/pull/3544
Comment 4 Rodrigo Kumpera 2016-09-14 00:49:30 UTC
PR was merged, I think it's safe to close this bug.

Notice (2018-05-21): bugzilla.xamarin.com will be switching to read-only mode on Thursday, 2018-05-25 22:00 UTC.

Please join us on Visual Studio Developer Community and GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs and copy them to the new locations as needed for follow-up. The See Also field on each Bugzilla bug will be updated with a link to its new location when applicable.

After Bugzilla is read-only, if you have new information to add for a bug that does not yet have a matching issue on Developer Community or GitHub, you can create a follow-up issue in the new location. Copy and paste the title and description from this bug, and then add your new details. You can get a pre-formatted version of the title and description here:

In special cases you might also want the comments:

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.

Note You need to log in before you can comment on or make changes to this bug.