Intermittent accessible/states/test_link.html | Test timed out, test_popup.xul | Can't get accessible for link_traversed (x2) | wrong state bits for 'link_traversed' !got '0', expected 'traversed' (followed by a hang)

RESOLVED FIXED in Firefox 18

Status

()

Core
Disability Access APIs
--
critical
RESOLVED FIXED
5 years ago
4 years ago

People

(Reporter: emorley, Assigned: surkov)

Tracking

(Blocks: 1 bug, {hang, intermittent-failure})

Trunk
mozilla19
x86
Windows XP
hang, intermittent-failure
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox18 fixed, firefox19 fixed)

Details

(Whiteboard: [qa-])

Attachments

(1 attachment, 1 obsolete attachment)

(Reporter)

Description

5 years ago
See also bug 757774.

Rev3 WINNT 5.1 mozilla-inbound opt test mochitest-other on 2012-08-14 06:42:52 PDT for push 1d43c660759d

slave: talos-r3-xp-070

https://tbpl.mozilla.org/php/getParsedLog.php?id=14371416&tree=Mozilla-Inbound

{
9247 INFO TEST-PASS | chrome://mochitests/content/a11y/accessible/states/test_link.html | wrong state bits for  'link_traversed' !
9248 INFO TEST-PASS | chrome://mochitests/content/a11y/accessible/states/test_link.html | state bits should not be present in ID  'link_traversed' !
9249 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/states/test_link.html | Test timed out.
9250 INFO TEST-END | chrome://mochitests/content/a11y/accessible/states/test_link.html | finished in 303446ms
9251 INFO TEST-START | chrome://mochitests/content/a11y/accessible/states/test_popup.xul
9252 INFO TEST-INFO | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | must wait for load
9253 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | Can't get accessible for link_traversed
9254 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | Can't get accessible for link_traversed
9255 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | wrong state bits for  'link_traversed' !got '0', expected 'traversed'
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | application timed out after 330 seconds with no output
Not taking screenshot here: see the one that was previously logged
INFO | automation.py | Application ran for: 0:13:10.625000
INFO | automation.py | Reading PID log: c:\docume~1\cltbld\locals~1\temp\tmpus2a9vpidlog
==> process 3192 launched child process 3944
INFO | automation.py | Checking for orphan process with PID: 3944
Downloading symbols from: http://ftp.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds/mozilla-inbound-win32/1344949411/firefox-17.0a1.en-US.win32.crashreporter-symbols.zip
PROCESS-CRASH | chrome://mochitests/content/a11y/accessible/states/test_popup.xul | application crashed (minidump found)
Crash dump filename: c:\docume~1\cltbld\locals~1\temp\tmpzwaefk\minidumps\865f7cbe-71e6-497c-bfdd-26926d5561c6.dmp
Operating system: Windows NT
                  5.1.2600 Service Pack 2
CPU: x86
     GenuineIntel family 6 model 23 stepping 10
     2 CPUs

Crash reason:  EXCEPTION_ACCESS_VIOLATION_WRITE
Crash address: 0x0

Thread 34 (crashed)
 0  crashinjectdll.dll!CrashingThread(void *) [crashinjectdll.cpp:1d43c660759d : 17 + 0x0]
    eip = 0x03411000   esp = 0x07ffffb8   ebp = 0x07ffffec   ebx = 0x00000000
    esi = 0x8f8e8d8c   edi = 0x8b8a8988   eax = 0x00000000   ecx = 0x07ffffb0
    edx = 0x7c90eb94   efl = 0x00010246
    Found by: given as instruction pointer in context
 1  kernel32.dll + 0xb50a
    eip = 0x7c80b50b   esp = 0x07ffffbc   ebp = 0x07ffffec
    Found by: stack scanning
}
(Reporter)

Comment 1

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=14378242&tree=Fx-Team
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Summary: Intermittent accessible/states/test_link.html | Test timed out. | Test timed out. | Can't get accessible for link_traversed (x2) | wrong state bits for 'link_traversed' !got '0', expected 'traversed' (followed by a hang) → Intermittent accessible/states/test_link.html | Test timed out, test_popup.xul | Can't get accessible for link_traversed (x2) | wrong state bits for 'link_traversed' !got '0', expected 'traversed' (followed by a hang)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 72

5 years ago
enabled logging: 2012-09-22 13:03:01 - https://hg.mozilla.org/mozilla-central/rev/a713d74f4cd2
(Assignee)

Comment 73

5 years ago
enable more logging: http://hg.mozilla.org/integration/mozilla-inbound/rev/e950ed8dc21f
Whiteboard: [orange] → [orange][leave open]
https://hg.mozilla.org/mozilla-central/rev/e950ed8dc21f
Assignee: nobody → surkov.alexander
Whiteboard: [orange][leave open] → [orange]
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Updated

5 years ago
Depends on: 794757
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Reporter)

Comment 123

5 years ago
Any more news on this now that we have the extra logging? :-)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 208

5 years ago
Created attachment 669037 [details] [diff] [review]
more logging

I think we handle document load complete of tab document before we handle document load complete of Firefox document, that makes the tab document is not loading event target. To make sure this is correct assumption I need more logging capabilities.
Attachment #669037 - Flags: review?(trev.saunders)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 211

5 years ago
Ok log:

A11Y DOCLOAD: document loaded; 02:50.695
  {
    DOM id: 0x91e97a0, acc id: 0xebaf308
    uri: chrome://browser/content/browser.xul
    docshell busy: 'busy', 'before page load'; chrome document
    docshell hierarchy, parent: (nil), root: 0xd66643c, is tab document: no;
    doc state: complete, not initial, showing, visible, active
    presshell: 0x9028b00, root scroll frame: (nil)
    load group: 0xd1c35f8, parent id: (nil)

    load type: normal;
    request spec: jar:file:///home/cltbld/talos-slave/test/build/firefox/omni.ja!/chrome/browser/content/browser/browser.xul
    request load flags: 790000; document uri; initial document uri; targeted; call content sniffers; classify uri;
    state flags: 20010, document is not loading
  }

A11Y DOCLOAD: document loaded *completely*; 02:51.043
  {
    DOM id: 0x91e97a0, acc id: 0xebaf308
    uri: chrome://browser/content/browser.xul
    document acc state: tree construction pending; tree constructed; DOM loaded; ready completely loaded
    document is load event target: false
  }

A11Y DOCLOAD: document loaded; 02:51.235
  {
    DOM id: 0xd9732b0, acc id: 0xd11ed40
    uri: http://www.example.com/
    docshell busy: 'busy', 'page loading'; content document
    docshell hierarchy, parent: 0xd66643c, root: 0xd66643c, is tab document: yes;
    doc state: complete, not initial, showing, visible, active
    presshell: 0xd977738, root scroll frame: 0xf7e0444
    load group: 0xe2ce328, parent id: 0x91e97a0
    parent uri: chrome://browser/content/browser.xul


    load type: normal;
    request spec: http://www.example.com/
    request load flags: 790000; document uri; initial document uri; targeted; call content sniffers; classify uri;
    state flags: 20010, document is not loading
  }

A11Y DOCLOAD: document loaded *completely*; 02:51.302
  {
    DOM id: 0xd9732b0, acc id: 0xd11ed40
    uri: http://www.example.com/
    document acc state: tree construction pending; tree constructed; DOM loaded; ready completely loaded
    document is load event target: true
  }

A11Y DOCEVENT: handled 'load complete' event; 02:51.302
  {
    DOM id: 0xd9732b0, acc id: 0xd11ed40
    uri: http://www.example.com/
    docshell busy: 'none'; content document
    docshell hierarchy, parent: 0xd66643c, root: 0xd66643c, is tab document: yes;
    doc state: complete, not initial, showing, visible, active
    presshell: 0xd977738, root scroll frame: 0xf7e0444
    load group: 0xe2ce328, parent id: 0x91e97a0
    parent uri: chrome://browser/content/browser.xul

  }
(Assignee)

Comment 212

5 years ago
NOT ok log:

A11Y DOCLOAD: document loaded; 47:41.689
  {
    DOM id: 17D86000, acc id: 1A9545C0
    uri: chrome://browser/content/browser.xul
    docshell busy: 'busy', 'before page load'; chrome document
    docshell hierarchy, parent: 00000000, root: 19038CA4, is tab document: no;
    doc state: complete, not initial, showing, visible, active
    presshell: 1AD7C400, root scroll frame: 00000000
    load group: 184B3300, parent id: 00000000

    load type: normal;
    request spec: jar:file:///c:/talos-slave/test/build/firefox/omni.ja!/chrome/browser/content/browser/browser.xul
    request load flags: 790000; document uri; initial document uri; targeted; call content sniffers; classify uri;
    state flags: 20010, document is not loading
  }

A11Y DOCLOAD: document loaded; 47:42.014
  {
    DOM id: 0E337000, acc id: 16C60B80
    uri: http://www.example.com/
    docshell busy: 'busy', 'page loading'; content document
    docshell hierarchy, parent: 19038CA4, root: 19038CA4, is tab document: yes;
    doc state: complete, not initial, showing, visible, active
    presshell: 0E307E00, root scroll frame: 18067858
    load group: 17DA2300, parent id: 17D86000
    parent uri: chrome://browser/content/browser.xul


    load type: normal;
    request spec: http://www.example.com/
    request load flags: 790000; document uri; initial document uri; targeted; call content sniffers; classify uri;
    state flags: 20010, document is not loading
  }

A11Y DOCLOAD: document loaded *completely*; 47:42.036
  {
    DOM id: 0E337000, acc id: 16C60B80
    uri: http://www.example.com/
    document acc state: tree construction pending; tree constructed; DOM loaded; ready completely loaded
    document is load event target: false
  }

A11Y DOCLOAD: document loaded *completely*; 47:42.048
  {
    DOM id: 17D86000, acc id: 1A9545C0
    uri: chrome://browser/content/browser.xul
    document acc state: tree construction pending; tree constructed; DOM loaded; ready completely loaded
    document is load event target: false
  }
(Assignee)

Comment 213

5 years ago
assumption from comment #208 was correct
(Assignee)

Comment 214

5 years ago
Created attachment 669052 [details] [diff] [review]
patch

tab document should be a target of document load events always (not depending whether Firefox document was loaded or not).
Attachment #669037 - Attachment is obsolete: true
Attachment #669037 - Flags: review?(trev.saunders)
Attachment #669052 - Flags: review?(trev.saunders)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment on attachment 669052 [details] [diff] [review]
patch

>+  printf("document acc state:");
>+  if (aDocument->HasLoadState(DocAccessible::eCompletelyLoaded))
>+    printf(" completely loaded;");
>+  else if (aDocument->HasLoadState(DocAccessible::eReady))
>+    printf(" ready;");
>+  else if (aDocument->HasLoadState(DocAccessible::eDOMLoaded))
>+    printf(" DOM loaded;");
>+  else if (aDocument->HasLoadState(DocAccessible::eTreeConstructed))
>+    printf(" tree constructed;");

why not put that space in the printf beore the if change, it would make more sense there so you have
printf("docstate: ");
if (x)
  printf("balh;");
else if (y)
  ...

>+  printf("    DOM id: %p, acc id: %p\n",
>+         static_cast<void*>(aDocument->GetDocumentNode()),
>+         static_cast<void*>(aDocument));

I find id funny word for pointer, why not just "DOM document %p accessible document %p" ?

> 
>         testStates("link_traversed", STATE_TRAVERSED);
>-        disableLogging();
>+        //disableLogging();

what's point of keeping it commented out?
Attachment #669052 - Flags: review?(trev.saunders) → review+
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Comment 247

5 years ago
(In reply to Trevor Saunders (:tbsaunde) from comment #243)

> why not put that space in the printf beore the if change, it would make more
> sense there so you have

artifact, when I didn't use 'else if'

> >+  printf("    DOM id: %p, acc id: %p\n",
> >+         static_cast<void*>(aDocument->GetDocumentNode()),
> >+         static_cast<void*>(aDocument));
> 
> I find id funny word for pointer, why not just "DOM document %p accessible
> document %p" ?

this one is artifact too, fixed

> >         testStates("link_traversed", STATE_TRAVERSED);
> >-        disableLogging();
> >+        //disableLogging();
> 
> what's point of keeping it commented out?

just keeping debugging stuff in case if the test will start failing again.
(Assignee)

Comment 248

5 years ago
http://hg.mozilla.org/integration/mozilla-inbound/rev/73ca717cde72
Comment hidden (Treeherder Robot)
(Assignee)

Updated

5 years ago
Target Milestone: --- → mozilla18
Comment hidden (Treeherder Robot)