Logging data from structs in interval 10-15 ms in C#

Question

I have to prepare Logger class which will be saving data from 3 structs in interval of 10-15 ms. My approach to this problem is below:

    public class Logger
{
    // Variables
    private Task loggerTask;
    public bool IsActive { get; set; }

    // Constructor
    public Logger()
    {

    }

    private void Logging()
    {
#if DEBUG
            System.Diagnostics.Debug.WriteLine("Logging has been started.");
#endif

        FileStream fs = new FileStream($"./log {DateTime.Now.ToString("dd.MM HH.mm.ss")}.txt", FileMode.Create, FileAccess.Write);
        StreamWriter sw = new StreamWriter(fs, Encoding.Default);

        try
        {
            Queue<double> times = new Queue<double>();
            Queue<Attitude> attitudes = new Queue<Attitude>();
            Queue<LocalPositionNed> positions = new Queue<LocalPositionNed>();
            Queue<SetPositionTargetLocalNed> setpoints = new Queue<SetPositionTargetLocalNed>();

            // Logs data
            DateTime start = DateTime.Now;
            DateTime last = start;
            DateTime now;

            while (IsActive)
            {
                now = DateTime.Now;

                if ((now - last).TotalMilliseconds < 16)
                    continue;

                last = now;
                
                times.Enqueue((now - start).TotalMilliseconds);
                attitudes.Enqueue(GCS.Instance.Drone.Attitude);
                positions.Enqueue(GCS.Instance.Drone.LocalPositionNed);
                setpoints.Enqueue(GCS.Instance.Offboard.SetPoint);
            }

            // Save data
            for(int i = 0; i < times.Count; i++)
            {
                sw.WriteLine($"{times.ElementAt(i)}\t" +
                    $"{attitudes.ElementAt(i).Pitch}\t" +
                    $"{attitudes.ElementAt(i).Roll}\t" +
                    $"{attitudes.ElementAt(i).Yaw}\t" +
                    $"{attitudes.ElementAt(i).Pitchspeed}\t" +
                    $"{attitudes.ElementAt(i).Rollspeed}\t" +
                    $"{attitudes.ElementAt(i).Yawspeed}\t" +
                    $"{positions.ElementAt(i).X}\t" +
                    $"{positions.ElementAt(i).Y}\t" +
                    $"{positions.ElementAt(i).Z}\t" +
                    $"{positions.ElementAt(i).Vx}\t" +
                    $"{positions.ElementAt(i).Vy}\t" +
                    $"{positions.ElementAt(i).Vz}\t" +
                    $"{setpoints.ElementAt(i).Vx}\t" +
                    $"{setpoints.ElementAt(i).Vy}\t" +
                    $"{setpoints.ElementAt(i).Vz}\t");
            }

        }
        catch (Exception ex)
        {
#if DEBUG
                System.Diagnostics.Debug.WriteLine($"Logging exception: {ex.Message}");
#endif
        }
        finally
        {
            sw.Dispose();
            fs.Dispose();
        }

#if DEBUG
            System.Diagnostics.Debug.WriteLine("Logging has been ended.");
#endif
    }

    // Static method
    public void Start()
    {
        IsActive = true;

        loggerTask = new Task(Logging);
        loggerTask.Start();
    }
    public void Stop()
    {
        IsActive = false;
    }
}

I have problem with intervals, because they are varying about 5-8 ms. My project requires maximum varying of 1-2 ms. Does anyone have idea how I can improve my approach.

Thank you for your responses.

Since OS you are running this code at is most likely not a real-time OS - it cannot provide such hard timing guarantees. At any point OS might decide your process\thread had enough CPU time and switch to another process\thread, then return back to your process after unknown amount of time. — Evk, Nov 17 '20 at 10:44
Even 5-8ms isn't guaranteed - delays in the 10's of ms aren't uncommon, and whole seconds aren't unknown. You simply can't get that even of precision on a non-realtime OS like Windows. — canton7, Nov 17 '20 at 10:47
Okay, I understand. But there is an another question. How I can check which precision will be guaranteed by my OS system? — Marcin, Nov 17 '20 at 10:50
A non-realtime OS doesn't guarantee *any* precision. For a real-time OS, check the documentation. For example, RTLinux [apparently guarantees that a periodic task runs within 35us of its scheduled time](https://en.wikipedia.org/wiki/RTLinux). — canton7, Nov 17 '20 at 10:53
A simple solution is to change the priority of the application to a higher priority so you get more even data. You application is running at normal priority so the operating system tasks are running at higher priority than you application and given uneven responses. — jdweng, Nov 17 '20 at 11:14
I wouldn't call that a "solution" -- there are still no guarantees. It may *help*, but I wouldn't say it solves the problem. — canton7, Nov 17 '20 at 11:17

score 0 · Accepted Answer · answered Nov 17 '20 at 15:27

The biggest issue is probably using DateTime.Now, this has poor resolution and is not appropriate for this kind of task.

A simple alternative that would be more appropriate is a stopwatch.

        var delay = 16;
        var stopwatch = Stopwatch.StartNew();
        long current = 0;
        long previous;
        var next = stopwatch.ElapsedMilliseconds + delay;
        for (int i = 0; i < 100; i++)
        {

            while (next > stopwatch.ElapsedMilliseconds)
            {
                // Spin
            }

            next = stopwatch.ElapsedMilliseconds + delay;

            previous = current;
            current = stopwatch.ElapsedMilliseconds;
            var delta = current - previous;
            Console.WriteLine("Delta: " + delta);
        }

As mentioned in the comments, this does not provide any strong guarantees, merely a best effort. There are also better ways to do this that does not waste an entire thread doing nothing, for example using multi media timers. But it might be adequate for testing/debugging purposes as long as the load on the CPU is light.

Logging data from structs in interval 10-15 ms in C#

1 Answers1