Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

TImer: Future.delayed can complete before the duration elapses on Dartium #15487

Closed
whesse opened this issue Dec 6, 2013 · 5 comments
Closed
Labels
closed-obsolete Closed as the reported issue is no longer relevant library-async P2 A bug or feature request we're likely to work on type-bug Incorrect behavior (everything from a crash to more subtle misbehavior)

Comments

@whesse
Copy link
Member

whesse commented Dec 6, 2013

A Future.delayed with a duration of 0.05 seconds completes after 0.0498 seconds, according to Stopwatch. The co19 test LibTest/async/Future/Future.delayed_A01_t02 tests for this.
Either Stopwatch is imprecise, the test is wrong, or Future.delayed can complete early:

FAILED: none-dartium release_ia32 co19/LibTest/async/Future/Future.delayed_A01_t02
Expected: Pass
Actual: RuntimeError
CommandOutput[dartium]:

stdout:
events:
  [
    .....
        {
              type: print
              value: Uncaught Error: Expect.isTrue(false, 'delay=0:00:00.050000, elapsed=0:00:00.049807') fails.
              timestamp: 0.188
        },
        {
              type: print
              value: Stack Trace:
                    #­0 Expect._fail (http://127.0.0.1:49591/root_dart/tests/co19/src/Utils/expect.dart:287:5)
                    #­1 Expect.isTrue (http://127.0.0.1:49591/root_dart/tests/co19/src/Utils/expect.dart:30:10)
                    #­2 check.<anonymous closure> (http://127.0.0.1:49591/root_dart/tests/co19/src/LibTest/async/Future/Future.delayed_A01_t02.dart:27:18)
                    #­3 Future.Future.delayed.<anonymous closure> (dart:async/future.dart:201)
                    #­4 _Future._propagateToListeners.<anonymous closure> (dart:async/future_impl.dart:453)
                    #­5 _rootRun (dart:async/zone.dart:683)
                    #­6 _RootZone.run (dart:async/zone.dart:832)
                    #­7 _Future._propagateToListeners (dart:async/future_impl.dart:445)
                    #­8 _Future._complete (dart:async/future_impl.dart:303)
                    #­9 _SyncCompleter.complete (dart:async/future_impl.dart:44)
                    #­10 Future.Future.delayed.<anonymous closure> (dart:async/future.dart:203)
                    #­11 _createTimer.<anonymous closure> (dart:async-patch/timer_patch.dart:11)
                    #­12 _Timer._Timer.<anonymous closure> (file:///E:/b/build/slave/dartium-win-full-be/build/src/dart/tools/dom/src/native_DOMImplementation.dart:546)
                    
                    
              timestamp: 0.203
        },

@lrhn
Copy link
Member

lrhn commented Dec 6, 2013

It looks most like a problem with Stopwatch. It's not just Dartium, I have the same problem running on the standalone VM.

If I time with both the difference between two new DateTime.now()'s and a stopwatch, the stopwatch shows less than the difference.
Example:

import "dart:async";
main() {
  int ctr = 0;
  test() {
    const d = const Duration(milliseconds: 500);
    Stopwatch sw = new Stopwatch();
    sw.start();
    var now = new DateTime.now();
    new Timer(d, () {
      var now2 = new DateTime.now();  // Even time the DateTime.now before sw.elapsed!
      var e = sw.elapsed;
      sw.stop();
      var delta = now2.difference(now);
      if (e < d || delta < d) {
        ++ctr;
        print("SW: $e, DT: $delta, expected: $d, ");
      } 
      if (ctr < 10) test();
    });
  }
  test();
}

It prints lines like:
SW: 0:00:00.499924, DT: 0:00:00.500000, expected: 0:00:00.500000,
meaning that Stopwatch lacks behind the DateTime.now difference.


Removed Library-Async label.
Added Library-Core label.
Changed the title to: "StopWatch: Future.delayed can complete before the duration elapses on Dartium".

@lrhn
Copy link
Member

lrhn commented Dec 6, 2013

It is likely that this is simply a precision problem.
The stopwatch is running in micro-seconds, but Timer and DateTime.now only uses milliseconds.

Assume that a 500 ms timer is scheduled at second X.000400. The timer uses milliseconds, so it gets the current time as X.000, adds 500 ms to get X.500, and schedules a timer event at that time.
A stopwatch started at the same time records X.000400 as start.
Then, say at X.500026, the timer triggers. When the stopwatch is checked, and it reports only 499674 microseconds elapsed.

So, this is an artifact of the current setup. With millisecond granularity, everything is correct (the timer is early, but by less than its granularity).
With microsecond granularity, everything is also correct.
Mixing the two means a rounding error can be detected.

If possible, we should change the timer so it rounds the start time up, not down (if that is what it does, that part is guesswork).

@lrhn
Copy link
Member

lrhn commented Dec 6, 2013

Which means that it is really a timer problem, not stopwatch, so switching it back to Library-Async.


Removed Library-Core label.
Added Library-Async, Area-Library labels.

@lrhn
Copy link
Member

lrhn commented Dec 11, 2013

Removed Area-Library label.
Added Area-Dartium label.
Changed the title to: "TImer: Future.delayed can complete before the duration elapses on Dartium".

@kevmoo kevmoo added P2 A bug or feature request we're likely to work on type-bug Incorrect behavior (everything from a crash to more subtle misbehavior) and removed triaged labels Feb 29, 2016
@floitschG floitschG added the closed-obsolete Closed as the reported issue is no longer relevant label Aug 24, 2017
@floitschG
Copy link
Contributor

The given Dart program doesn't print anything anymore on the VM.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
closed-obsolete Closed as the reported issue is no longer relevant library-async P2 A bug or feature request we're likely to work on type-bug Incorrect behavior (everything from a crash to more subtle misbehavior)
Projects
None yet
Development

No branches or pull requests

4 participants