BUG? Unstable HighResolutionTimer upon app startup

General JUCE discussion
1

JUCE 8.0.8, macOS Sequoia

I have a GUI app that uses a 1 ms HighResolutionTimer to drive the generation of music via MIDI. Years ago I posted about problems with the HighResolutionTimer and @anthony and @oli1 were very helpful in rectifying those and bringing it back to being stable and reliable.

However, I have noticed something concerning. I don’t know if this is a recent thing, but if you start the HighResolutionTimer right at the launch of the app, it exhibits unstable behavior.

I’ve created a demo project that prints to the console the first 100 callbacks to hiResTimerCallback().

There is also a button that will stop and restart the timer (once the app is running), again printing out the same information.

HiResTimerTestStartup.zip (18.1 KB)

The debug printout shows the difference between the count of callbacks (ms) vs the realtime value (minus start time) rounded to ms. Ideally, the difference should be 0.

When you start the timer in the app’s Constructor, here is the output - unstable:

first callback - set start time
callbackCount ms 001, realtime 00.000 987, rounded 001, difference 0
callbackCount ms 002, realtime 00.001 988, rounded 002, difference 0
callbackCount ms 003, realtime 00.002 985, rounded 003, difference 0
callbackCount ms 004, realtime 00.003 987, rounded 004, difference 0
callbackCount ms 005, realtime 00.004 982, rounded 005, difference 0
callbackCount ms 006, realtime 00.005 985, rounded 006, difference 0
callbackCount ms 007, realtime 00.006 982, rounded 007, difference 0
callbackCount ms 008, realtime 00.007 979, rounded 008, difference 0
callbackCount ms 009, realtime 00.025 398, rounded 025, difference 16 *
callbackCount ms 010, realtime 00.025 449, rounded 025, difference 15 *
callbackCount ms 011, realtime 00.025 467, rounded 025, difference 14 *
callbackCount ms 012, realtime 00.025 483, rounded 025, difference 13 *
callbackCount ms 013, realtime 00.025 493, rounded 025, difference 12 *
callbackCount ms 014, realtime 00.025 503, rounded 026, difference 12 *
callbackCount ms 015, realtime 00.025 515, rounded 026, difference 11 *
callbackCount ms 016, realtime 00.025 524, rounded 026, difference 10 *
callbackCount ms 017, realtime 00.025 534, rounded 026, difference 9 *
callbackCount ms 018, realtime 00.025 544, rounded 026, difference 8 *
callbackCount ms 019, realtime 00.025 553, rounded 026, difference 7 *
callbackCount ms 020, realtime 00.025 562, rounded 026, difference 6 *
callbackCount ms 021, realtime 00.025 571, rounded 026, difference 5 *
callbackCount ms 022, realtime 00.025 581, rounded 026, difference 4 *
callbackCount ms 023, realtime 00.025 590, rounded 026, difference 3 *
callbackCount ms 024, realtime 00.025 600, rounded 026, difference 2 *
callbackCount ms 025, realtime 00.025 609, rounded 026, difference 1 *
callbackCount ms 026, realtime 00.025 986, rounded 026, difference 0
callbackCount ms 027, realtime 00.026 982, rounded 027, difference 0
callbackCount ms 028, realtime 00.027 981, rounded 028, difference 0
callbackCount ms 029, realtime 00.028 984, rounded 029, difference 0
callbackCount ms 030, realtime 00.029 985, rounded 030, difference 0
callbackCount ms 031, realtime 00.030 986, rounded 031, difference 0
callbackCount ms 032, realtime 00.031 984, rounded 032, difference 0
callbackCount ms 033, realtime 00.032 984, rounded 033, difference 0
callbackCount ms 034, realtime 00.033 981, rounded 034, difference 0
callbackCount ms 035, realtime 00.034 982, rounded 035, difference 0
callbackCount ms 036, realtime 00.035 997, rounded 036, difference 0
callbackCount ms 037, realtime 00.036 984, rounded 037, difference 0
callbackCount ms 038, realtime 00.037 985, rounded 038, difference 0
callbackCount ms 039, realtime 00.038 988, rounded 039, difference 0
callbackCount ms 040, realtime 00.039 985, rounded 040, difference 0
callbackCount ms 041, realtime 00.056 338, rounded 056, difference 15 *
callbackCount ms 042, realtime 00.056 381, rounded 056, difference 14 *
callbackCount ms 043, realtime 00.056 392, rounded 056, difference 13 *
callbackCount ms 044, realtime 00.056 408, rounded 056, difference 12 *
callbackCount ms 045, realtime 00.056 423, rounded 056, difference 11 *
callbackCount ms 046, realtime 00.056 435, rounded 056, difference 10 *
callbackCount ms 047, realtime 00.056 444, rounded 056, difference 9 *
callbackCount ms 048, realtime 00.056 454, rounded 056, difference 8 *
callbackCount ms 049, realtime 00.056 463, rounded 056, difference 7 *
callbackCount ms 050, realtime 00.056 472, rounded 056, difference 6 *
callbackCount ms 051, realtime 00.056 481, rounded 056, difference 5 *
callbackCount ms 052, realtime 00.056 491, rounded 056, difference 4 *
callbackCount ms 053, realtime 00.056 502, rounded 057, difference 4 *
callbackCount ms 054, realtime 00.056 520, rounded 057, difference 3 *
callbackCount ms 055, realtime 00.056 529, rounded 057, difference 2 *
callbackCount ms 056, realtime 00.056 538, rounded 057, difference 1 *
callbackCount ms 057, realtime 00.056 986, rounded 057, difference 0
callbackCount ms 058, realtime 00.057 985, rounded 058, difference 0
callbackCount ms 059, realtime 00.058 984, rounded 059, difference 0
callbackCount ms 060, realtime 00.059 982, rounded 060, difference 0
callbackCount ms 061, realtime 00.060 989, rounded 061, difference 0
callbackCount ms 062, realtime 00.061 984, rounded 062, difference 0
callbackCount ms 063, realtime 00.062 984, rounded 063, difference 0
callbackCount ms 064, realtime 00.063 987, rounded 064, difference 0
callbackCount ms 065, realtime 00.064 984, rounded 065, difference 0
callbackCount ms 066, realtime 00.065 985, rounded 066, difference 0
callbackCount ms 067, realtime 00.066 983, rounded 067, difference 0
callbackCount ms 068, realtime 00.067 984, rounded 068, difference 0
callbackCount ms 069, realtime 00.068 988, rounded 069, difference 0
callbackCount ms 070, realtime 00.069 983, rounded 070, difference 0
callbackCount ms 071, realtime 00.070 986, rounded 071, difference 0
callbackCount ms 072, realtime 00.071 992, rounded 072, difference 0
callbackCount ms 073, realtime 00.072 986, rounded 073, difference 0
callbackCount ms 074, realtime 00.073 983, rounded 074, difference 0
callbackCount ms 075, realtime 00.074 985, rounded 075, difference 0
callbackCount ms 076, realtime 00.075 984, rounded 076, difference 0
callbackCount ms 077, realtime 00.076 981, rounded 077, difference 0
callbackCount ms 078, realtime 00.077 984, rounded 078, difference 0
callbackCount ms 079, realtime 00.078 982, rounded 079, difference 0
callbackCount ms 080, realtime 00.079 983, rounded 080, difference 0
callbackCount ms 081, realtime 00.080 989, rounded 081, difference 0
callbackCount ms 082, realtime 00.081 985, rounded 082, difference 0
callbackCount ms 083, realtime 00.082 983, rounded 083, difference 0
callbackCount ms 084, realtime 00.083 983, rounded 084, difference 0
callbackCount ms 085, realtime 00.084 985, rounded 085, difference 0
callbackCount ms 086, realtime 00.085 983, rounded 086, difference 0
callbackCount ms 087, realtime 00.086 983, rounded 087, difference 0
callbackCount ms 088, realtime 00.087 985, rounded 088, difference 0
callbackCount ms 089, realtime 00.088 984, rounded 089, difference 0
callbackCount ms 090, realtime 00.089 984, rounded 090, difference 0
callbackCount ms 091, realtime 00.090 982, rounded 091, difference 0
callbackCount ms 092, realtime 00.091 983, rounded 092, difference 0
callbackCount ms 093, realtime 00.092 981, rounded 093, difference 0
callbackCount ms 094, realtime 00.093 984, rounded 094, difference 0
callbackCount ms 095, realtime 00.094 983, rounded 095, difference 0
callbackCount ms 096, realtime 00.095 982, rounded 096, difference 0
callbackCount ms 097, realtime 00.114 466, rounded 114, difference 17 *
callbackCount ms 098, realtime 00.114 506, rounded 115, difference 17 *
callbackCount ms 099, realtime 00.114 517, rounded 115, difference 16 *
callbackCount ms 100, realtime 00.114 527, rounded 115, difference 15 *

Here’s what happens when you place startTimer(1) in Application::initialize() - it’s worse!:

first callback - set start time
callbackCount ms 001, realtime 00.000 978, rounded 001, difference 0
callbackCount ms 002, realtime 00.001 981, rounded 002, difference 0
callbackCount ms 003, realtime 00.002 981, rounded 003, difference 0
callbackCount ms 004, realtime 00.003 980, rounded 004, difference 0
callbackCount ms 005, realtime 00.004 980, rounded 005, difference 0
callbackCount ms 006, realtime 00.005 980, rounded 006, difference 0
callbackCount ms 007, realtime 00.006 978, rounded 007, difference 0
callbackCount ms 008, realtime 00.007 978, rounded 008, difference 0
callbackCount ms 009, realtime 00.008 982, rounded 009, difference 0
callbackCount ms 010, realtime 00.009 982, rounded 010, difference 0
callbackCount ms 011, realtime 00.025 500, rounded 026, difference 15 *
callbackCount ms 012, realtime 00.025 536, rounded 026, difference 14 *
callbackCount ms 013, realtime 00.025 548, rounded 026, difference 13 *
callbackCount ms 014, realtime 00.025 558, rounded 026, difference 12 *
callbackCount ms 015, realtime 00.025 567, rounded 026, difference 11 *
callbackCount ms 016, realtime 00.025 585, rounded 026, difference 10 *
callbackCount ms 017, realtime 00.025 595, rounded 026, difference 9 *
callbackCount ms 018, realtime 00.025 604, rounded 026, difference 8 *
callbackCount ms 019, realtime 00.025 612, rounded 026, difference 7 *
callbackCount ms 020, realtime 00.025 621, rounded 026, difference 6 *
callbackCount ms 021, realtime 00.025 629, rounded 026, difference 5 *
callbackCount ms 022, realtime 00.025 638, rounded 026, difference 4 *
callbackCount ms 023, realtime 00.025 646, rounded 026, difference 3 *
callbackCount ms 024, realtime 00.025 655, rounded 026, difference 2 *
callbackCount ms 025, realtime 00.025 663, rounded 026, difference 1 *
callbackCount ms 026, realtime 00.025 975, rounded 026, difference 0
callbackCount ms 027, realtime 00.026 979, rounded 027, difference 0
callbackCount ms 028, realtime 00.027 980, rounded 028, difference 0
callbackCount ms 029, realtime 00.028 978, rounded 029, difference 0
callbackCount ms 030, realtime 00.029 980, rounded 030, difference 0
callbackCount ms 031, realtime 00.030 990, rounded 031, difference 0
callbackCount ms 032, realtime 00.031 997, rounded 032, difference 0
callbackCount ms 033, realtime 00.032 980, rounded 033, difference 0
callbackCount ms 034, realtime 00.033 982, rounded 034, difference 0
callbackCount ms 035, realtime 00.034 981, rounded 035, difference 0
callbackCount ms 036, realtime 00.035 981, rounded 036, difference 0
callbackCount ms 037, realtime 00.036 981, rounded 037, difference 0
callbackCount ms 038, realtime 00.037 981, rounded 038, difference 0
callbackCount ms 039, realtime 00.038 980, rounded 039, difference 0
callbackCount ms 040, realtime 00.039 980, rounded 040, difference 0
callbackCount ms 041, realtime 00.040 976, rounded 041, difference 0
callbackCount ms 042, realtime 00.041 980, rounded 042, difference 0
callbackCount ms 043, realtime 00.042 979, rounded 043, difference 0
callbackCount ms 044, realtime 00.043 976, rounded 044, difference 0
callbackCount ms 045, realtime 00.044 980, rounded 045, difference 0
callbackCount ms 046, realtime 00.045 979, rounded 046, difference 0
callbackCount ms 047, realtime 00.046 978, rounded 047, difference 0
callbackCount ms 048, realtime 00.047 978, rounded 048, difference 0
callbackCount ms 049, realtime 00.048 977, rounded 049, difference 0
callbackCount ms 050, realtime 00.049 977, rounded 050, difference 0
callbackCount ms 051, realtime 00.050 978, rounded 051, difference 0
callbackCount ms 052, realtime 00.051 978, rounded 052, difference 0
callbackCount ms 053, realtime 00.052 977, rounded 053, difference 0
callbackCount ms 054, realtime 00.053 976, rounded 054, difference 0
callbackCount ms 055, realtime 00.055 288, rounded 055, difference 0
callbackCount ms 056, realtime 00.055 990, rounded 056, difference 0
callbackCount ms 057, realtime 00.056 976, rounded 057, difference 0
callbackCount ms 058, realtime 00.165 193, rounded 165, difference 107 *
callbackCount ms 059, realtime 00.165 235, rounded 165, difference 106 *
callbackCount ms 060, realtime 00.165 246, rounded 165, difference 105 *
callbackCount ms 061, realtime 00.165 254, rounded 165, difference 104 *
callbackCount ms 062, realtime 00.165 285, rounded 165, difference 103 *
callbackCount ms 063, realtime 00.165 297, rounded 165, difference 102 *
callbackCount ms 064, realtime 00.165 306, rounded 165, difference 101 *
callbackCount ms 065, realtime 00.165 315, rounded 165, difference 100 *
callbackCount ms 066, realtime 00.165 325, rounded 165, difference 99 *
callbackCount ms 067, realtime 00.165 337, rounded 165, difference 98 *
callbackCount ms 068, realtime 00.165 346, rounded 165, difference 97 *
callbackCount ms 069, realtime 00.165 356, rounded 165, difference 96 *
callbackCount ms 070, realtime 00.165 365, rounded 165, difference 95 *
callbackCount ms 071, realtime 00.165 374, rounded 165, difference 94 *
callbackCount ms 072, realtime 00.165 383, rounded 165, difference 93 *
callbackCount ms 073, realtime 00.165 392, rounded 165, difference 92 *
callbackCount ms 074, realtime 00.165 401, rounded 165, difference 91 *
callbackCount ms 075, realtime 00.165 410, rounded 165, difference 90 *
callbackCount ms 076, realtime 00.165 419, rounded 165, difference 89 *
callbackCount ms 077, realtime 00.207 724, rounded 208, difference 131 *
callbackCount ms 078, realtime 00.207 747, rounded 208, difference 130 *
callbackCount ms 079, realtime 00.207 757, rounded 208, difference 129 *
callbackCount ms 080, realtime 00.207 767, rounded 208, difference 128 *
callbackCount ms 081, realtime 00.207 776, rounded 208, difference 127 *
callbackCount ms 082, realtime 00.207 785, rounded 208, difference 126 *
callbackCount ms 083, realtime 00.207 794, rounded 208, difference 125 *
callbackCount ms 084, realtime 00.207 804, rounded 208, difference 124 *
callbackCount ms 085, realtime 00.207 813, rounded 208, difference 123 *
callbackCount ms 086, realtime 00.207 822, rounded 208, difference 122 *
callbackCount ms 087, realtime 00.207 831, rounded 208, difference 121 *
callbackCount ms 088, realtime 00.207 840, rounded 208, difference 120 *
callbackCount ms 089, realtime 00.207 849, rounded 208, difference 119 *
callbackCount ms 090, realtime 00.207 858, rounded 208, difference 118 *
callbackCount ms 091, realtime 00.208 292, rounded 208, difference 117 *
callbackCount ms 092, realtime 00.208 311, rounded 208, difference 116 *
callbackCount ms 093, realtime 00.208 322, rounded 208, difference 115 *
callbackCount ms 094, realtime 00.208 331, rounded 208, difference 114 *
callbackCount ms 095, realtime 00.208 340, rounded 208, difference 113 *
callbackCount ms 096, realtime 00.208 350, rounded 208, difference 112 *
callbackCount ms 097, realtime 00.208 359, rounded 208, difference 111 *
callbackCount ms 098, realtime 00.208 368, rounded 208, difference 110 *
callbackCount ms 099, realtime 00.208 378, rounded 208, difference 109 *
callbackCount ms 100, realtime 00.208 387, rounded 208, difference 108 *

However, here’s what happens when you delay the call to startTimer with Timer::callAfterDelay(), i.e.

HiResTimerTestApplication::HiResTimerTestApplication()
{
    juce::Timer::callAfterDelay(1000, [this] {
        startTimer (1);
    });
}

Perfect!

first callback - set start time
callbackCount ms 001, realtime 00.000 978, rounded 001, difference 0
callbackCount ms 002, realtime 00.001 983, rounded 002, difference 0
callbackCount ms 003, realtime 00.002 984, rounded 003, difference 0
callbackCount ms 004, realtime 00.003 982, rounded 004, difference 0
callbackCount ms 005, realtime 00.004 986, rounded 005, difference 0
callbackCount ms 006, realtime 00.005 981, rounded 006, difference 0
callbackCount ms 007, realtime 00.006 981, rounded 007, difference 0
callbackCount ms 008, realtime 00.007 982, rounded 008, difference 0
callbackCount ms 009, realtime 00.008 982, rounded 009, difference 0
callbackCount ms 010, realtime 00.009 981, rounded 010, difference 0
callbackCount ms 011, realtime 00.010 979, rounded 011, difference 0
callbackCount ms 012, realtime 00.011 977, rounded 012, difference 0
callbackCount ms 013, realtime 00.012 977, rounded 013, difference 0
callbackCount ms 014, realtime 00.013 979, rounded 014, difference 0
callbackCount ms 015, realtime 00.014 979, rounded 015, difference 0
callbackCount ms 016, realtime 00.015 977, rounded 016, difference 0
callbackCount ms 017, realtime 00.016 978, rounded 017, difference 0
callbackCount ms 018, realtime 00.017 979, rounded 018, difference 0
callbackCount ms 019, realtime 00.018 976, rounded 019, difference 0
callbackCount ms 020, realtime 00.019 980, rounded 020, difference 0
callbackCount ms 021, realtime 00.020 982, rounded 021, difference 0
callbackCount ms 022, realtime 00.021 977, rounded 022, difference 0
callbackCount ms 023, realtime 00.022 977, rounded 023, difference 0
callbackCount ms 024, realtime 00.023 976, rounded 024, difference 0
callbackCount ms 025, realtime 00.024 980, rounded 025, difference 0
callbackCount ms 026, realtime 00.025 977, rounded 026, difference 0
callbackCount ms 027, realtime 00.026 980, rounded 027, difference 0
callbackCount ms 028, realtime 00.027 977, rounded 028, difference 0
callbackCount ms 029, realtime 00.028 978, rounded 029, difference 0
callbackCount ms 030, realtime 00.029 980, rounded 030, difference 0
callbackCount ms 031, realtime 00.030 977, rounded 031, difference 0
callbackCount ms 032, realtime 00.031 976, rounded 032, difference 0
callbackCount ms 033, realtime 00.032 975, rounded 033, difference 0
callbackCount ms 034, realtime 00.033 976, rounded 034, difference 0
callbackCount ms 035, realtime 00.034 979, rounded 035, difference 0
callbackCount ms 036, realtime 00.035 976, rounded 036, difference 0
callbackCount ms 037, realtime 00.036 976, rounded 037, difference 0
callbackCount ms 038, realtime 00.037 980, rounded 038, difference 0
callbackCount ms 039, realtime 00.038 982, rounded 039, difference 0
callbackCount ms 040, realtime 00.039 981, rounded 040, difference 0
callbackCount ms 041, realtime 00.040 982, rounded 041, difference 0
callbackCount ms 042, realtime 00.041 988, rounded 042, difference 0
callbackCount ms 043, realtime 00.042 982, rounded 043, difference 0
callbackCount ms 044, realtime 00.043 983, rounded 044, difference 0
callbackCount ms 045, realtime 00.044 982, rounded 045, difference 0
callbackCount ms 046, realtime 00.045 982, rounded 046, difference 0
callbackCount ms 047, realtime 00.046 982, rounded 047, difference 0
callbackCount ms 048, realtime 00.047 983, rounded 048, difference 0
callbackCount ms 049, realtime 00.048 982, rounded 049, difference 0
callbackCount ms 050, realtime 00.049 983, rounded 050, difference 0
callbackCount ms 051, realtime 00.050 982, rounded 051, difference 0
callbackCount ms 052, realtime 00.051 982, rounded 052, difference 0
callbackCount ms 053, realtime 00.052 980, rounded 053, difference 0
callbackCount ms 054, realtime 00.053 983, rounded 054, difference 0
callbackCount ms 055, realtime 00.054 983, rounded 055, difference 0
callbackCount ms 056, realtime 00.055 978, rounded 056, difference 0
callbackCount ms 057, realtime 00.056 976, rounded 057, difference 0
callbackCount ms 058, realtime 00.057 979, rounded 058, difference 0
callbackCount ms 059, realtime 00.058 977, rounded 059, difference 0
callbackCount ms 060, realtime 00.059 983, rounded 060, difference 0
callbackCount ms 061, realtime 00.060 982, rounded 061, difference 0
callbackCount ms 062, realtime 00.061 985, rounded 062, difference 0
callbackCount ms 063, realtime 00.062 986, rounded 063, difference 0
callbackCount ms 064, realtime 00.063 982, rounded 064, difference 0
callbackCount ms 065, realtime 00.064 985, rounded 065, difference 0
callbackCount ms 066, realtime 00.065 983, rounded 066, difference 0
callbackCount ms 067, realtime 00.066 980, rounded 067, difference 0
callbackCount ms 068, realtime 00.067 978, rounded 068, difference 0
callbackCount ms 069, realtime 00.068 978, rounded 069, difference 0
callbackCount ms 070, realtime 00.069 982, rounded 070, difference 0
callbackCount ms 071, realtime 00.070 983, rounded 071, difference 0
callbackCount ms 072, realtime 00.071 983, rounded 072, difference 0
callbackCount ms 073, realtime 00.072 985, rounded 073, difference 0
callbackCount ms 074, realtime 00.073 980, rounded 074, difference 0
callbackCount ms 075, realtime 00.074 982, rounded 075, difference 0
callbackCount ms 076, realtime 00.075 981, rounded 076, difference 0
callbackCount ms 077, realtime 00.076 980, rounded 077, difference 0
callbackCount ms 078, realtime 00.077 978, rounded 078, difference 0
callbackCount ms 079, realtime 00.078 982, rounded 079, difference 0
callbackCount ms 080, realtime 00.079 982, rounded 080, difference 0
callbackCount ms 081, realtime 00.080 981, rounded 081, difference 0
callbackCount ms 082, realtime 00.081 986, rounded 082, difference 0
callbackCount ms 083, realtime 00.082 982, rounded 083, difference 0
callbackCount ms 084, realtime 00.083 985, rounded 084, difference 0
callbackCount ms 085, realtime 00.084 983, rounded 085, difference 0
callbackCount ms 086, realtime 00.085 982, rounded 086, difference 0
callbackCount ms 087, realtime 00.086 982, rounded 087, difference 0
callbackCount ms 088, realtime 00.087 983, rounded 088, difference 0
callbackCount ms 089, realtime 00.088 981, rounded 089, difference 0
callbackCount ms 090, realtime 00.089 983, rounded 090, difference 0
callbackCount ms 091, realtime 00.090 983, rounded 091, difference 0
callbackCount ms 092, realtime 00.091 984, rounded 092, difference 0
callbackCount ms 093, realtime 00.092 979, rounded 093, difference 0
callbackCount ms 094, realtime 00.093 982, rounded 094, difference 0
callbackCount ms 095, realtime 00.094 982, rounded 095, difference 0
callbackCount ms 096, realtime 00.095 980, rounded 096, difference 0
callbackCount ms 097, realtime 00.096 982, rounded 097, difference 0
callbackCount ms 098, realtime 00.097 982, rounded 098, difference 0
callbackCount ms 099, realtime 00.098 979, rounded 099, difference 0
callbackCount ms 100, realtime 00.099 982, rounded 100, difference 0

You can also just click the “Reset Timer” button to stop and restart the timer, and it prints out the same PERFECT output.

I suppose I can delay the start of the HighResolutionTimer in my app, but I wonder if this is a problem that can be improved. Would appreciate some advice from @anthony as to whether I should just hack in a delay to start it or hope it can be fixed. Thanks!

2

To be honest adding the delay is probably going to be the right solution. There is likely some early initialisation that’s taking up resources and the OS is prioritising accordingly. If there is a specific change that you think has caused this maybe you could use your simple app to detect it and perform a git bisect to find where the issue was introduced?

3

One thought, I don’t think you mention the OS this is happening on, is it on all OS’s?

4

Thanks for the quick reply. At the top I mentioned macOS Sequoia.

The weird part is it goes out of sync than appears to catch back up….

5

Ah sorry I missed that.

Yeah I think that’s expected. IIRC if the timer misses anything it should catch back up so no callbacks are dropped.

6

But if you start the Timer in Application::initialize(), it’s worse and it does the above where at 57 callbacks it’s fine but the next callback there has been a jump in the wall clock of 107 ms, after which it doesn’t get back in sync (as shown above in the second example).

I would think initialize() would be called when resources are allocated, vs. the Constructor. Maybe not.

Thanks for the advice. I can certainly just delay the startup. It’s easier than trying to find out where this may or may not have crept in…

7

To be clear initialise() doesn’t mean everything has been initialised it means it’s time to start initialising your app. Some things will be up and running, like the MessageManager but there will be more that will be lazy initialised the first time you use it, or caches that won’t have anything in yet, and probably plenty you need to initialise yourself. Obviously in your example most of this is mitigated by removing it all. I also tried removing some other things (such as removing all text drawing), unfortunately it made no difference.

In thinking about it more I also wondered if we just need to give time for the HighResolutionTimer thread to startup. I played with adding an extra callback to notify when the timer thread is ready but that turns out to have its own issues and also didn’t seem to change much.

It seems in the end the wait sometimes hangs. I tried removing the wait in favour of a busy loop and the result was the same!! Maybe the OS scheduler takes a little time before it starts servicing that new thread with the priority we’ve requested?

It seems this is just another example demonstrating that you really need to be ready for the callbacks to arrive at any time. I think we’ve discussed this before, but there can never be any guarantees about the accuracy of these callbacks. If delaying on startup works for you I would go with that.

If you want to try and get something even more accurate you could try spinning up your own realtime thread and spinning on a loop that checks the time and a condition (to exit) and see if you get any better results. Maybe that way you could eliminate any need for locks or condition variables. It might mean your app consumes a lot more CPU cycles and energy though.

1 Like
8

Ok - thanks for taking the time to look into it further! I’m just going to delay the startup by 1 second since it seems to work consistently, and it doesn’t seem to affect the rest of my app’s startup sequence negatively.

1 Like