Closed Bug 874425 Opened 12 years ago Closed 12 years ago

Intermittent test_osfile_async.xul | duration: Operation duration time was updated correctly with a numeric value., | duration: OS.File.writeAtomic: Operation duration time is non-negative

Categories

(Toolkit Graveyard :: OS.File, defect)

Product:
Toolkit Graveyard
Component:
OS.File
Platform:
x86
Windows XP
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox24 fixed, firefox25 fixed, firefox26 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla26
Tracking Flags:
Tracking Status
firefox24 --- fixed
firefox25 --- fixed
firefox26 --- fixed

People

(Reporter: RyanVM, Assigned: Yoric)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 4 obsolete files)

Wallpaper typo fix
1.41 KB, patch
Yoric
: review+
Details | Diff | Splinter Review
Appears to be a new failure on the iX test slaves (significantly faster than the rev3 Mac Minis they're replacing). https://tbpl.mozilla.org/php/getParsedLog.php?id=23188194&tree=Mozilla-Inbound Windows XP 32-bit mozilla-inbound pgo test mochitest-other on 2013-05-20 21:30:09 PDT for push c750d5d003dd slave: t-xp32-ix-046 22:35:14 INFO - 15492 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | system_shutdown: Log message observation promise was rejected as expected. 22:35:14 INFO - 15493 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | system_shutdown: Complete 22:35:14 INFO - 15494 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | duration: Entering 22:35:14 INFO - 15495 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | duration: This was a promise 22:35:14 INFO - 15496 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | duration: Gathered method duration time: -16 MS 22:35:14 INFO - 15497 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_async.xul | duration: Operation duration time was updated correctly with a numeric value.
So we have a negative duration. That's certainly unexpected. Investigating.
Trivial patch to add a little more logging.
Attachment #753695 - Flags: review+
Keywords: checkin-needed
Whiteboard: [leave open]
Summary: Intermittent test_osfile_async.xul | duration: Operation duration time was updated correctly with a numeric value. → Intermittent test_osfile_async.xul | duration: Operation duration time was updated correctly with a numeric value., | duration: OS.File.writeAtomic: Operation duration time is non-negative
No longer depends on: 903707
(In reply to David Rajchenbach Teller [:Yoric] <on PTO, I'll be back on Thursday, August 22nd> from comment #4) Is the extra logging providing any useful info?
Flags: needinfo?(dteller)
Not really. What we know: - this problem is not limited to one specific operation (it affects OS.File.{copy, read, writeAtomic}); - this problem appears limited to Windows; - when the problem appears, duration is always -15ms or -16ms; - when the problem does not appear, duration is always +1ms or +2ms. Given that this time is measured through two successive calls to Date.now() in the same thread, I'm a bit at a loss.
Flags: needinfo?(dteller)
Attached patch Yet more logging (obsolete) — — Splinter Review
Adding yet more logging...
Attachment #794237 - Flags: review+
I think Date isn't guaranteed to be monotonic. performance.now() usually provides higher resolution results and should also be monotonic. performance.now() is 0 sometime during the page load, and then only progresses.
Do we have performance.now() in workers?
Attachment #753695 - Attachment description: A little more logging to improve readability → A little more logging to improve readability (already checked in)
I confirm that performance.now() is not available in workers (just filed bug 908390). Also, it might be useful to add a sanity check and discard negative durations in the code.
Attachment #753695 - Attachment description: A little more logging to improve readability (already checked in) → A little more logging to improve readability
Attachment #753695 - Flags: checkin+
Attachment #794237 - Flags: checkin+
https://hg.mozilla.org/integration/fx-team/rev/816c1730c8ec
Keywords: checkin-needed
Whiteboard: [leave open] → [leave open][fixed-in-fx-team]
https://hg.mozilla.org/mozilla-central/rev/816c1730c8ec
Whiteboard: [leave open][fixed-in-fx-team] → [leave open]
Attached patch Wallpaper fix (obsolete) — — Splinter Review
Attachment #795425 - Flags: review?(nfroyd)
Comment on attachment 795425 [details] [diff] [review] Wallpaper fix Review of attachment 795425 [details] [diff] [review]: ----------------------------------------------------------------- r=me. Do you want the changes in main_test_osfile_async.js, or were those just debugging changes that got qref'd into your patch?
Attachment #795425 - Flags: review?(nfroyd) → review+
These changes are intentional, because I believe that they make sense. However, I should not have added them in the patch as they have already been checked-in by the previous patch.
Attached patch Wallpaper fix, v2 (obsolete) — — Splinter Review
Removing code that has already been checked in.
Assignee: nobody → dteller
Attachment #795425 - Attachment is obsolete: true
Attachment #795428 - Flags: review+
https://hg.mozilla.org/integration/fx-team/rev/487e7ea49182
Flags: in-testsuite+
Keywords: checkin-needed
Whiteboard: [leave open] → [fixed-in-fx-team]
https://hg.mozilla.org/mozilla-central/rev/487e7ea49182
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Whiteboard: [fixed-in-fx-team]
Target Milestone: --- → mozilla26
This test failed in this try push: https://tbpl.mozilla.org/?tree=Try&rev=e122cba93bab I'm not sure it's really a problem because this try push looks weird.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Ah, there's a typo in my fix.
Typo fix
Attachment #753695 - Attachment is obsolete: true
Attachment #794237 - Attachment is obsolete: true
Attachment #795428 - Attachment is obsolete: true
Attachment #797716 - Flags: review+
Flags: needinfo?(ryanvm)
https://hg.mozilla.org/mozilla-central/rev/f6d60cfe074c
Status: REOPENED → RESOLVED
Closed: 12 years ago → 12 years ago
Resolution: --- → FIXED
Product: Toolkit → Toolkit Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: