nanoFramework ESP32 Thread.Sleep weird behaviour

Question

I have the following program running on an ESP32 as a test:

using System;
using System.Diagnostics;
using System.Threading;
using nanoFramework.Hardware.Esp32;

namespace NFApp2
{
    public class Program
    {
        private static long Counter;
        private static long Ticks;
        public static void Main()
        {
            Ticks = 5000;

            Thread CountThread = new Thread(new ThreadStart(CountFunction));
            CountThread.Start();

            while (true)
            {
                Thread.Sleep(1000);
                Debug.WriteLine(string.Format("Ticks =  {0}, Count = {1}", Ticks, Counter));
                Counter = 0;
                Ticks += 100;
            }
        }

        private static void CountFunction()
        {
            while (true)
            {
                Thread.Sleep(new TimeSpan(Ticks));
                Counter++;
            }
        }
    }
}

Basically a thread is started that sleeps for some time (Ticks) and then increases a counter by 1. Every second the count is printed and reset and the sleep time of the thread is increased by 100 ticks.

When running this I get the following output:

Ticks =  5000, Count = 3445
Ticks =  5100, Count = 3435
Ticks =  5200, Count = 3405
Ticks =  5300, Count = 3405
Ticks =  5400, Count = 3403
Ticks =  5500, Count = 3406
Ticks =  5600, Count = 3405
Ticks =  5700, Count = 3404
Ticks =  5800, Count = 3403
Ticks =  5900, Count = 3403
Ticks =  6000, Count = 3403
Ticks =  6100, Count = 3406
Ticks =  6200, Count = 3402
Ticks =  6300, Count = 3404
Ticks =  6400, Count = 3403
Ticks =  6500, Count = 3403
Ticks =  6600, Count = 3405
Ticks =  6700, Count = 3406
Ticks =  6800, Count = 3403
Ticks =  6900, Count = 3401
Ticks =  7000, Count = 3403
Ticks =  7100, Count = 3403
Ticks =  7200, Count = 3403
Ticks =  7300, Count = 3407
Ticks =  7400, Count = 3403
Ticks =  7500, Count = 3403
Ticks =  7600, Count = 3404
Ticks =  7700, Count = 3402
Ticks =  7800, Count = 3404
Ticks =  7900, Count = 3406
Ticks =  8000, Count = 3402
Ticks =  8100, Count = 3402
Ticks =  8200, Count = 3403
Ticks =  8300, Count = 3403
Ticks =  8400, Count = 3404
Ticks =  8500, Count = 3407
Ticks =  8600, Count = 3403
Ticks =  8700, Count = 3403
Ticks =  8800, Count = 3403
Ticks =  8900, Count = 3403
Ticks =  9000, Count = 3403
Ticks =  9100, Count = 3407
Ticks =  9200, Count = 3502
Ticks =  9300, Count = 3403
Ticks =  9400, Count = 3403
Ticks =  9500, Count = 3402
Ticks =  9600, Count = 3404
Ticks =  9700, Count = 3407
Ticks =  9800, Count = 3403
Ticks =  9900, Count = 3403
Ticks =  10000, Count = 100
Ticks =  10100, Count = 100
Ticks =  10200, Count = 100
Ticks =  10300, Count = 101
Ticks =  10400, Count = 100
Ticks =  10500, Count = 100
Ticks =  10600, Count = 99
Ticks =  10700, Count = 101
Ticks =  10800, Count = 99
Ticks =  10900, Count = 100
Ticks =  11000, Count = 100
Ticks =  11100, Count = 100
Ticks =  11200, Count = 100
Ticks =  11300, Count = 100
Ticks =  11400, Count = 100
Ticks =  11500, Count = 100
Ticks =  11600, Count = 100
Ticks =  11700, Count = 100
Ticks =  11800, Count = 100
Ticks =  11900, Count = 100
Ticks =  12000, Count = 100
Ticks =  12100, Count = 100
Ticks =  12200, Count = 100
Ticks =  12300, Count = 100
Ticks =  12400, Count = 101
Ticks =  12500, Count = 99
Ticks =  12600, Count = 100

I know the timing will never be exact but I would expect the count to slowly drop as the thread function takes longer to execute..... but it doesn't, it stays araound 3404. And after a while an even weider thing happens when the sleeptime reaches 10000, the count suddenly drops to around 100 and stays there.

Maybe I'm doing something wrong or my expectations are wrong.

Some help would be great!

Cheers, Robert.

score 2 · Accepted Answer · answered Apr 01 '22 at 05:39

2

I think your error is that the constructor new TimeSpan(int) does not take milliseconds, but multiples of the high-resolution tick value, which is 100ns. And since Thread.Sleep() has a minimal resolution of 1ms, a timespan of less than 1ms doesn't wait at all. Therefore, as long as Ticks is less than 10.000, your loop runs as fast as it can (apparently about 3400 times per second). As soon as Ticks is larger than 10.000 (which corresponds to a wait time of 1ms) things change: Now the loop waits regularly, and you get about 100 iterations per second. This is now likely since the minimal wait time of Thread.Sleep() is 10ms (a value that varies with hardware).

answered Apr 01 '22 at 05:39

PMF

14,535
3
23
49

1

Some extra information to the above: - On nanoFramework the thread switching occurs every 20ms. - When calling Thread.Sleep() anything below that value is not guaranteed to give you a precise timing. - If you need to use really small "sleep" you're better using SpinWait(). – José Simões Apr 01 '22 at 07:18
@JoséSimões Thanks for the clarification. From the output above, I thought it must be 10, like the default on Windows or Linux is as well. But I didn't check the code. – PMF Apr 01 '22 at 08:20
Thanks for the clarification! It all makes sense now! – Robert Apr 05 '22 at 05:35

nanoFramework ESP32 Thread.Sleep weird behaviour

1 Answers1