Bug 2947 - Timer isn't time stable across runs
Summary: Timer isn't time stable across runs
Status: IN_PROGRESS
Alias: None
Product: Class Libraries
Classification: Mono
Component: System (show other bugs)
Version: 2.10.x
Hardware: PC Windows
: --- normal
Target Milestone: Untriaged
Assignee: Jérémie Laval
URL:
Depends on:
Blocks:
 
Reported: 2012-01-17 18:05 UTC by Fabien GIGANTE
Modified: 2013-01-11 16:53 UTC (History)
5 users (show)

See Also:
Tags: TPL Parallel invoke timer callback
Is this bug a regression?: ---
Last known good build:


Attachments

Description Fabien GIGANTE 2012-01-17 18:05:27 UTC
Using Parallel.Invoke inside a Timer Callback results in a deadlock situation.

The problem is simply demonstrated by the following code sample (I made it as short as possible). With MS.NET, the program displays about ten times "Hello world", as exits gracefully. With Mono, it hangs after two lines displayed.

---

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

namespace Test
{
  static class Program
  {
    static void Main(string[] args)
    {
      using (new Timer(x => { Parallel.Invoke(() => { Console.WriteLine("Hello world"); }); }, null, 0, 100)) Thread.Sleep(1000);
    }
  }
}
Comment 1 Jérémie Laval 2012-02-03 10:40:28 UTC
Hello,

Your program works fine for me on master. Could you confirm it's still happening for you with it?

Thanks in advance.
Comment 2 Fabien GIGANTE 2012-02-03 14:52:26 UTC
Bonsoir Jérémie,

I made additionnal tests with 2.10.8.
I reproduce the same issue on both Windows and MacOS.
I reproduce either when compiling with MS.NET or mono.

I also tried mono C# shell. Interestingly, the behavior is slightly different. Instead of hanging after a couple lines, it returns prematurely to the shell, but continues in the background. Strange.

csharp> using System;
csharp> using System.Threading;
csharp> using System.Threading.Tasks;
csharp> using (new Timer(x => Parallel.Invoke(() => Console.WriteLine("Hello")), null, 0, 100)) Thread.Sleep(1000);
Hello
Hello
Hello
csharp> Hello
Hello
Hello
Hello
...

I can try the "master" version. Can I get a binary distribution somewhere (preferably Windows), or do I need to build mono from source code first?
Comment 3 Fabien GIGANTE 2012-02-03 17:15:58 UTC
OK, I switched to Ubuntu OS, where the problem was also reproduced with 2.10.8.

Then I built mono from git master (easier than on Windows).

And... The problem is fixed. :-) Tada!

However, I have noticed a different issue. The timer is now very slow : I specified an interval of 100ms, but it is triggered only every 500ms or so. That's weird. But that's a different bug. I'll close this one.

Merci Jérémie.
Comment 4 Fabien GIGANTE 2012-02-03 17:40:20 UTC
Me again.

I made further investigations on what I thought to be a new problem. But indeed, it seems very closely related to the previous one. So I think it's better to reopen the same bug. Of course, tell me if you prefer to proceed otherwise.

Here's the new program I made:

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

	namespace Test
	{
	  static class Program
	  {
	    static void Main(string[] args)
	    {
	      using (new Timer(x => Console.WriteLine("Hi"), null, 0, 100)) Thread.Sleep(1000);
	      Console.WriteLine("Was 'Hi' written ~10 times?");
	      using (new Timer(x => Parallel.Invoke(() => Console.WriteLine("Hello")), null, 0, 100)) Thread.Sleep(1000);
	      Console.WriteLine("Was 'Hello' written ~10 times?");
	      using (new Timer(x => Console.WriteLine("Bye"), null, 0, 100)) Thread.Sleep(1000);
	      Console.WriteLine("Was 'Bye' written ~10 times?");
	    }
	  }
	}

As you will see below, the output is very different from what we would expect. This first timer behaves correctly. The second one is very slow, doesn't stop immediately when disposed, and seems to mess things up because... The third timer isn't even called at all. :-(

Program's output :

	fabien@fabien-VirtualBox:~$ mono Program.exe
	Hi
	Hi
	Hi
	Hi
	Hi
	Hi
	Hi
	Hi
	Hi
	Hi
	Was 'Hi' written ~10 times?
	Hello
	Hello
	Was 'Hello' written ~10 times?
	Hello
	Hello
	Was 'Bye' written ~10 times?
Comment 5 Fabien GIGANTE 2012-02-03 17:43:52 UTC
Output of the same Program with MS.NET :

Hi
Hi
Hi
Hi
Hi
Hi
Hi
Hi
Hi
Hi
Was 'Hi' written ~10 times?
Hello
Hello
Hello
Hello
Hello
Hello
Hello
Hello
Hello
Hello
Was 'Hello' written ~10 times?
Bye
Bye
Bye
Bye
Bye
Bye
Bye
Bye
Bye
Bye
Was 'Bye' written ~10 times?
Comment 6 Jérémie Laval 2012-02-04 03:22:24 UTC
Hey,

I changed the bug title and assigned it to someone who may have a better idea of what's going on.
Comment 7 Fabien GIGANTE 2012-02-04 08:48:12 UTC
I would like to state again the important fact that the problem only occurs when using Using Parallel.Invoke inside a Timer Callback.

Also it is quite stable across runs, but the behavior is consistently wrong, as described in my previous comment. It really seems like Parallel.Invoke is messing things up.

Also, I checked with 2.10.5, it was working just fine, back then.
Comment 8 Fabien GIGANTE 2012-02-05 05:44:15 UTC
I made further investigations. Please find my finding below. I seems that the problem only occurs after Task.WaitAll() is called.

static class Program
  {
    static void DoTask1()
    {
      Action action = () => Console.Write("1 ");
      Task task = Task.Factory.StartNew(action);
      task.Wait();
    }
    static void DoTask2()
    {
      Action action = () => Console.Write("2 ");
      Task[] tasks = { Task.Factory.StartNew(action) };
      Task.WaitAll(tasks);
    }
    static void Main(string[] args)
    {
      Console.Write("Simple Timer: ");
      using (new Timer(x => Console.Write("0 "), null, 0, 100)) Thread.Sleep(1000);
      Console.Write("\nTask Timer: ");
      using (new Timer(x => DoTask1(), null, 0, 100)) Thread.Sleep(1000);
      Console.Write("\nTaskArray Timer: ");
      using (new Timer(x => DoTask2(), null, 0, 100)) Thread.Sleep(1000);
      Console.Write("\nSimple Timer: ");
      using (new Timer(x => Console.Write("3 "), null, 0, 100)) Thread.Sleep(1000);
      Console.WriteLine("\nThe End");
    }
  }
}

Expected results:

Simple Timer: 0 0 0 0 0 0 0 0 0 0 
Task Timer: 1 1 1 1 1 1 1 1 1 1 
TaskArray Timer: 2 2 2 2 2 2 2 2 2 2 
Simple Timer: 3 3 3 3 3 3 3 3 3 3 
The End

Observed results (you might need to run the program several times to reproduce):
fabien@fabien-VirtualBox:~$ mono Program.exe
Simple Timer: 0 0 0 0 0 0 0 0 0 0 
Task Timer: 1 1 1 1 1 1 1 1 1 1 
TaskArray Timer: 
Simple Timer: 
The End
Comment 9 Jérémie Laval 2012-02-05 05:59:42 UTC
Yes I have noticed it too. I'm investigating.
Comment 10 Rodrigo Kumpera 2013-01-11 16:53:57 UTC
Any news here?

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