Closed Bug 874435 Opened 11 years ago Closed 10 years ago

Intermittent test_osfile_front.xul | test_info: file has changed between the start of the test and now | test_info: file 2 was accessed between the start of the test and now | test_info: file 2 has changed between the start of the test and now

Categories

(Toolkit Graveyard :: OS.File, defect)

Product:
Toolkit Graveyard
Component:
OS.File
Platform:
x86
Linux
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, 3 obsolete files)

Rounding up/down in all cases, v2
5.53 KB, patch
Yoric
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=23184266&tree=Mozilla-Inbound

Ubuntu VM 12.04 mozilla-inbound debug test mochitest-other on 2013-05-20 19:12:29 PDT for push c750d5d003dd
slave: tst-linux32-ec2-318

19:28:09     INFO -  16468 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: correct size( 261 ==? 261)
19:28:09     INFO -  16469 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":false,"description":"test_info: file has changed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)"}
19:28:09     INFO -  16470 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file has changed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)
19:28:09     INFO -  16471 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":true,"description":"test_info: info acquired 2"}
19:28:09     INFO -  16472 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: info acquired 2
19:28:09     INFO -  16473 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":true,"description":"test_info: file is not a directory 2"}
19:28:09     INFO -  16474 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file is not a directory 2
19:28:09     INFO -  16475 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":true,"description":"test_info: file is not a link 2"}
19:28:09     INFO -  16476 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file is not a link 2
19:28:09     INFO -  16477 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"is","outcome":true,"description":"test_info: correct size 2","a":"261","b":"261"}
19:28:09     INFO -  16478 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: correct size 2( 261 ==? 261)
19:28:09     INFO -  16479 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":true,"description":"test_info: file 2 was created between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Wed Dec 31 1969 16:00:00 GMT-0800 (PST)"}
19:28:09     INFO -  16480 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file 2 was created between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Wed Dec 31 1969 16:00:00 GMT-0800 (PST)
19:28:09     INFO -  16481 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":false,"description":"test_info: file 2 was accessed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)"}
19:28:09     INFO -  16482 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file 2 was accessed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)
19:28:09     INFO -  16483 INFO TEST-PASS | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | MAIN: onmessage {"kind":"ok","condition":false,"description":"test_info: file 2 has changed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)"}
19:28:09     INFO -  16484 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/toolkit/components/osfile/tests/mochi/test_osfile_front.xul | test_info: file 2 has changed between the start of the test and now - Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:07 GMT-0700 (PDT), Mon May 20 2013 19:28:06 GMT-0700 (PDT)
Assignee: nobody → dteller

        Attachment #753684 -
        Flags: review?(nfroyd)

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
  
Comment on attachment 753684 [details] [diff] [review]
Assuming 2.5s of file system time precision instead of 1s

Review of attachment 753684 [details] [diff] [review]:
-----------------------------------------------------------------

Sigh.  OK, r=me; apologies for the PTO-induced latency.

        Attachment #753684 -
        Flags: review?(nfroyd) → review+

    
    

    
  
https://hg.mozilla.org/mozilla-central/rev/54460bb48e05
Status: NEW → RESOLVED
Closed: 11 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla24

    
    

    
      
  

    
  
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
  
Yoric, any other ideas for how to fix this? It seems that increasing the length of time hasn't made a huge difference.
Flags: needinfo?(dteller)

    
    

    
  
Mmmh... that's weird. Comment 12 suggests that the patch has landed, but the logs seem to disagree: http://hg.mozilla.org/mozilla-central/filelog/b8c7acba4b40/toolkit/components/osfile/tests/mochi/worker_test_osfile_front.js

What am I missing?
Flags: needinfo?(dteller)

    
    

    
  
You tell me. Looks like the change is present on m-c tip.
https://hg.mozilla.org/mozilla-central/file/tip/toolkit/components/osfile/tests/mochi/worker_test_osfile_front.js#l652
Flags: needinfo?(dteller)

    
    

    
      
  
Depends on: 899436
Flags: needinfo?(dteller)

    
    

    
  


  
This probably won't be sufficient to fix the issue, but it might remove one of the errors.

        Attachment #783062 -
        Flags: review?(nfroyd)

    
    

    
  
Comment on attachment 783062 [details] [diff] [review]
Fixing lastAccessDate/lastModificationDate typo

Review of attachment 783062 [details] [diff] [review]:
-----------------------------------------------------------------

Doh.  And I reviewed the initial fix.

::: toolkit/components/osfile/tests/mochi/worker_test_osfile_front.js
@@ +704,4 @@
>    ok(birth.getTime() <= stopMs,
>        "test_info: file 2 was created between the start of the test and now - " + start +  ", " + stop + ", " + birth);
>  
> +  let access = stat.lastAccessDate;

Hm.  I guess it depends whether the filesystem maintains atime on Unix.  We can try it, I guess.

Fortunately on Windows these seem to be the same.  Please trigger several try runs with this fix to see if it does work.

        Attachment #783062 -
        Flags: review?(nfroyd) → review+

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

        Attachment #753684 -
        Attachment is obsolete: true

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  
Keywords: checkin-needed
Whiteboard: [leave open]

    
    

    
      
  

    
    

    
  
https://hg.mozilla.org/integration/fx-team/rev/25c96d376081
Keywords: checkin-needed
Whiteboard: [leave open] → [leave open][fixed-in-fx-team]

    
    

    
  
https://hg.mozilla.org/mozilla-central/rev/25c96d376081
Whiteboard: [leave open][fixed-in-fx-team] → [leave open]

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
  
I guess comment 72 was right.
Flags: needinfo?(dteller)

    
    

    
  
I'm tempted to add a 10 seconds wait between the start of the test and the writes just to have some padding.
Flags: needinfo?(dteller)

    
    

    
      
  

    
    

    
  

      
      
      
      

        Attached patch
          
          
        Rounding up/down in all cases (obsolete)
        — 
          — Splinter Review
      

    


  
Ah, as it turns out, the rounding up/down we had added for the start of the test had not been propagated to the rest of the test. Given that it's the end of the test that is failing, doing so might solve the issue.

        Attachment #783062 -
        Attachment is obsolete: true

    
    

    
      
  

    
    

    
      
  

    
    

    
  
Comment on attachment 799452 [details] [diff] [review]
Rounding up/down in all cases

Review of attachment 799452 [details] [diff] [review]:
-----------------------------------------------------------------

The browser_observableobject.js bits are not part of this patch, I assume?

r=me with suggested changes for filesystemSlopMs or whatever you'd like to call it.

::: toolkit/components/osfile/tests/mochi/worker_test_osfile_front.js
@@ +650,5 @@
>    let stop = new Date();
>  
> +  // Test that the date information provided by the file system is
> +  // *roughly* correct (i.e., within 3 seconds).
> +  let startMs = start.getTime() - 3000;

Since we're using this in sort-of-widely-separated places now, let's give a name to 3000; filesystemSlopMs or something like that, and explain why we have it (the comment about file system precision vs. Date precision is valuable and we shouldn't lose it).  Then the startMs/stopMs blocks don't need extra comments.

@@ +694,5 @@
>    ok(!stat.isDir, "test_info: file is not a directory 2");
>    ok(!stat.isSymLink, "test_info: file is not a link 2");
>    is(stat.size.toString(), size, "test_info: correct size 2");
>  
>    stop = new Date();

I guess we don't need a new |start| for this test, eh?

        Attachment #799452 -
        Flags: review?(nfroyd) → review+

    
    

    
      
  

    
    

    
  


  
Applied feedback

        Attachment #799452 -
        Attachment is obsolete: true

        Attachment #800641 -
        Flags: review+

    
  
Target Milestone: mozilla24 → ---

    
    

    
  
https://hg.mozilla.org/integration/fx-team/rev/108a505b0a73
Keywords: checkin-needed
Whiteboard: [leave open] → [leave open][fixed-in-fx-team]

    
    

    
      
  

    
    

    
  
https://hg.mozilla.org/mozilla-central/rev/108a505b0a73

This has [leave open] on it. Should it?
Whiteboard: [leave open][fixed-in-fx-team] → [leave open]

    
    

    
      
  

    
    

    
  
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #117)
> https://hg.mozilla.org/mozilla-central/rev/108a505b0a73
> 
> This has [leave open] on it. Should it?

Probably not.
Note: comment 116 and comment 118 don't include the patch.
Status: REOPENED → RESOLVED
Closed: 11 years ago → 10 years ago
Resolution: --- → FIXED
Whiteboard: [leave open]

    
  

          status-firefox24:
          --- → affected

          status-firefox25:
          --- → affected

          status-firefox26:
          --- → fixed
Target Milestone: --- → mozilla26

    
  
Product: Toolkit → Toolkit Graveyard

          You need to log in
          before you can comment on or make changes to this bug.