very strange and severe multithread inconsistency problem c#

Question

I have a very simple watchdog program with 2 threads. One thread is updating a long variable and the other thread reads the variable. and alert if it was more than X seconds from the last update. The problem is that sometimes (happens once a day more or less) the second thread reads a stale value of the variable.

Sometimes it is stale value from 3 seconds ago (i.e. the first thread updated the long variable but after 3 seconds the other thread didn't get the new value)

I am using lock, in order to avoid multi thread caching problem. I also tried Volatile, Interlock, volatileRead etc but nothing helps. The class is initiated via VB 6 program via COM. The program is very simple, so i think that it is a bug in C# (maybe COM related). this is the program:

Can you help please?

public class WatchDog
{
    long lastDate = DateTime.Now.ToBinary();

    private object dateLock = new object();
    bool WatchdogActive = true;
    int WatchdogTimeoutAlert = 5;
    int WatchdogCheckInterval = 6000;

    private void WatchdogThread()
    {
        try
        {
            while (WatchdogActive)
            {
                lock (dateLock)
                {
                    DateTime lastHB = DateTime.FromBinary(lastDate);

                    if ((DateTime.Now.Subtract(lastHB).TotalSeconds > WatchdogTimeoutAlert))
                    {
                        Console.WriteLine(" last Date is " + lastDate);

                    }
                }
                Thread.Sleep(WatchdogCheckInterval);
            }
        }
        catch (Exception Ex)
        {
        }
    }

    private void OnHeartbeatArrive(long heartbeatTime)
    {
        lock (dateLock)
        {
            lastDate = heartbeatTime;
            Console.WriteLine(" Got Heartbeat lastDate " + lastDate);
        }
    }
}

You may need to give some information on how `OnHeartbeatArrive()` is invoked and in particular how the `heartbeatTime` passed to it is determined. — Michael Burr, Dec 27 '10 at 08:40
To be clear, does the posted code, with the WriteLine() statements, demonstrate the problem? — H H, Dec 27 '10 at 08:59
@michael When i get a message from the server via TCP, i call OnHeartbeatArrive with DateTime.Now.ToBinary(). Note that i print the same variable. I see that it changed its value from the updating thread, but i see an old value in the reading thread. — ofer alper, Dec 27 '10 at 09:00
@Henk: Yes. i used the console writeLine to see the value of the variable after the update and in the read and then i noticed that the reader thread reads an old value even 3 seconds! after the update thread updated the value and print it. — ofer alper, Dec 27 '10 at 09:03
What IDE are you using. Are you starting the program from the IDE? — Lorenz Lo Sauer, Sep 09 '12 at 04:45

score 3 · Answer 1 · answered Dec 27 '10 at 09:30

3

        while (WatchdogActive)

That doesn't work, WatchdogActive isn't declared volatile. In the Release build the variable is very likely to get stored in a CPU register, it never sees the update that some other thread makes to the variable. In other words, the watch dog will still be active, even though you turned it off.

You should use a ManualResetEvent here, its WaitOne(int) method automatically takes care of the Sleep() and gives you a much quicker thread termination as a bonus.

Some strange inconsistencies. You quote a failure at 3 seconds but you only check for >= 5 seconds. The Sleep() is longer than the check, making it possible to miss failures. You seem to like empty catch blocks, always giving great opportunities for code failing to work without any diagnostic. I'm guessing we're not looking at the real code, that makes it difficult to see subtle threading problems. Do work from the assumption that this is not a bug in C#.

answered Dec 27 '10 at 09:30

Hans Passant

922,412
146
1,693
2,536

of course it is possible. The reader thread is indeed checking every 5 seconds. But the flow is as follow: The update thread is updating the value at time X -2 and X. The reader thread wakes at X + 3 but doesn't get the most updated value. It gets the value of X - 2. – ofer alper Dec 27 '10 at 09:41
of course it is possible. The reader thread is indeed checking every 5 seconds. But the flow is as follow: The update thread is updating the value at time X -2 and X. The reader thread wakes at X + 3 but doesn't get the most updated value. It gets the value of X - 2. The code is almost identical to the real code as i said it is very simple. Not sure what you meant that the WatchdogActive isn't volatile. In most cases it works fine but it happens once a day. I will be happy to know that it is not c# com related bug, but i am running out of ideas. – ofer alper Dec 27 '10 at 09:48
How do you know this? Are you staring at the console window the whole day to see X? Or is this actually getting logged? Loggers have their own locking. Make the code snippet an *exact* copy of the real code. – Hans Passant Dec 27 '10 at 10:00
I print all the time but i don't watch it the whole day :) . The trigger is the alert that i get from the watchdog. When i get the alerts i see all the prints (all the updates) and i see the print of the reader thread. Yes i am using a logger but i can't see how it can explain the above. The logger time is in exact correlation to the DateTime.Now. Also it happens after 3 seconds so it is not likely to be a problem of logger. – ofer alper Dec 27 '10 at 10:12

Bonshington · Answer 2 · 2010-12-27T09:49:30.713

0

normally i use lock() to volatile object that is on 'left side' in this case, use

volatile object lastDate = DateTime.Now.ToBinary();
...
lock(lastDate){...}

And why u pass 'long' instead of DateTime?

edited Dec 27 '10 at 09:49

answered Dec 27 '10 at 09:43

Bonshington

3,970
2
25
20

Try it: "volatile not valid for type long..." – H H Dec 27 '10 at 09:47
i tried all the option. I tried working with volatile + lock, i tried working with DateTime, i tried reading and writing with VolatileRead, i tried reading and writing with Interlock. Nothing worked. Actually i started with DateTime, i changed it to long just to verify it is not DateTime problem related – ofer alper Dec 27 '10 at 09:54
perhaps use Stack. for checking, use .Peek() and dont forget to clear stack to free up resource – Bonshington Jan 24 '11 at 08:10

very strange and severe multithread inconsistency problem c#

2 Answers2

Linked