I was wondering what is the effect of heavy computation on Timer.periodc which often happens when making bots doing at an heavy task and at the same time running a job at a regular interval.
So I made this code but the results confused me.
import 'dart:async';
void main() {
asyncAwait();
}
int now() => DateTime.now().millisecondsSinceEpoch;
void asyncAwait() {
int x = 0;
int previousElapase = now();
final programStart = now();
Timer.periodic(Duration(seconds: 1), (timer) {
x++;
final stepStart = now();
final step = stepStart - previousElapase;
print("$x at ${stepStart - programStart}ms Diff: ${x == 1 ? null : step}");
previousElapase = stepStart;
if (x == 5) {
print("Timer cancelled");
timer.cancel();
}
});
final start = now();
int i = 0;
while (i++ < 10000000000);
print("Heavy computation took in ${now() - start}");
}
On my system dart (2.13.0), here is the output
dart main.dart
Heavy computation took in 5988
1 at 5997ms Diff: null
2 at 6005ms Diff: 8 // Suspicious, confusing
3 at 7007ms Diff: 1002
4 at 8007ms Diff: 1000
5 at 9007ms Diff: 1000
Timer cancelled
My issue is here:
2 at 6005ms Diff: 8 // Suspicious, confusing
Why the second iteration happens (almost) immediately after the first ?
Can someone explain me what the compiler does step by step ?
My expectation is as follow
Schedule first at: 1000ms
Do heavy computation
Now is: 5988ms
[print Heavy computation took in 5988]
Now is: 5997ms
Now is same/after first schedule so add Timer periodic call back at the bottom of the Event loop Queue
Schedule second at: 6997ms
Do first task on event loop queue
[print 1 at 5997ms Diff: null]
Nothing to do, wait for next schedule of 6997ms
Now is 6997ms
Now is same/after second schedule so add Timer periodic call back at the bottom of the Event loop Queue
Schedule third at: 7997ms
Do second task on event loop queue
[print 2 at 6997ms Diff: 1000]
Nothing to do, wait for next schedule of 7997ms
and so on ...
At least that's how I think I understand how TimerPeriodic interacts with the Event, can someone correct me ?
I even rewrote the same program Javascript since it is single-threaded and I confirm that my expectation is correct (at least in Js)
let now = ()=> new Date().getTime();
let x = 0;
let previousElapase = now();
let programStart = now();
let timer = setInterval(()=> {
x++;
let stepStart = now();
let step = stepStart - previousElapase;
console.log(`${x} at ${stepStart - programStart}ms Diff: ${x === 1 ? null : step}`);
previousElapase = stepStart;
if (x === 5) {
console.log(`Timer cancelled`);
clearInterval(timer);
}
}, 1000);
let start = now();
let i = 0;
while (i++ < 10000000000);
console.log(`Heavy computation took in ${now() - start}`);
JavaScript output:
Heavy computation took in 11249
1 at 11256ms Diff: null
2 at 12258ms Diff: 1002
3 at 13262ms Diff: 1004
4 at 14264ms Diff: 1002
5 at 15265ms Diff: 1001
Timer cancelled