Intermittent dom/media/tests/crashtests/812785.html | load failed: timed out waiting for reftest-wait to be removed

RESOLVED WORKSFORME

Status

()

Core
WebRTC: Audio/Video
P2
normal
RESOLVED WORKSFORME
5 years ago
3 years ago

People

(Reporter: RyanVM, Assigned: jib)

Tracking

({intermittent-failure, regression})

Trunk
x86_64
Mac OS X
intermittent-failure, regression
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [WebRTC][blocking-webrtc+])

Attachments

(1 attachment)

(Reporter)

Description

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=20907436&tree=Mozilla-Inbound

Rev4 MacOSX Lion 10.7 mozilla-inbound debug test crashtest on 2013-03-20 16:49:54 PDT for push e70bea1fd166
slave: talos-r4-lion-027

16:55:20     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccapi.c:1423: SIPCC-CC_API: 7/9, cc_int_onhook: UI -> GSM: ONHOOK
16:55:20     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccapi.c:1423: SIPCC-CC_API: 6/8, cc_int_onhook: UI -> GSM: ONHOOK
16:55:20     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
16:55:20     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
16:55:57     INFO -  WARNING: 1 sort operation has occurred for the SQL statement '0x105172000'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 110
16:55:57     INFO -  WARNING: 1 sort operation has occurred for the SQL statement '0x11a86e010'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 110
16:55:57     INFO -  WARNING: 1 sort operation has occurred for the SQL statement '0x10c4966e0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 110
16:55:57     INFO -  WARNING: 1 sort operation has occurred for the SQL statement '0x11a85c1c0'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 110
17:00:09     INFO -  REFTEST TEST-UNEXPECTED-FAIL | file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html | load failed: timed out waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: START file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
17:00:09     INFO -  REFTEST INFO | Saved log: Initializing canvas snapshot
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 2 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 307 36
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 307 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
17:00:09     INFO -  REFTEST INFO | Saved log: Initializing canvas snapshot
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 308 36
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 2 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 307 36
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 307 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
17:00:09     INFO -  REFTEST INFO | Saved log: Initializing canvas snapshot
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/talos-slave/test/build/tests/reftest/tests/dom/media/tests/crashtests/812785.html
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 2 rects
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 8 0 307 36
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 307 0 612 41
17:00:09     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
17:00:09     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
17:00:09     INFO -  REFTEST INFO | Loading a blank page
17:00:09     INFO -  ++DOMWINDOW == 30 (0x117eda718) [serial = 1248] [outer = 0x10c46f358]
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccapi.c:1423: SIPCC-CC_API: 6/10, cc_int_onhook: UI -> GSM: ONHOOK
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] sm.c:46: SIPCC-FSM: sm_process_event: DEF 10  : 0x1032042c0: sm entry: (CALL_SENT:ONHOOK)
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmdef.c:6083: SIPCC-FSM: fsmdef_ev_onhook: Entered.
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmdef.c:1771: SIPCC-FSM: 6/10, fsmdef_release: Entered. cause= NORMAL
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmdef.c:8569: SIPCC-FSM: fsmdef_notify_hook_event: Entered.
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] ccapi.c:1423: SIPCC-CC_API: 6/10, cc_int_onhook: GSM -> SIP: ONHOOK
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] fsm.c:346: SIPCC-FSM: 6/10, fsm_change_state: DEF: CALL_SENT -> IDLE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:397: SIPCC-DCSM: dcsm_update_gsm_state: 10 : DCSM_READY --> DCSM_READY
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmdef.c:1084: SIPCC-FSM: 0/0, fsmdef_init_dcb: call_not_counted_in_mnc_bt = FALSE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] fsm.c:346: SIPCC-FSM: 0/10, fsm_change_state: DEF: IDLE -> IDLE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:397: SIPCC-DCSM: dcsm_update_gsm_state: 10 : DCSM_READY --> DCSM_READY
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] sm.c:65: SIPCC-GSM: 6/10, sm_process_event: DEF   :(CALL_SENT:ONHOOK )
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 10  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x141c23dc0
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 10  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x0
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] fsm.c:346: SIPCC-FSM: 0/10, fsm_change_state: CNF: IDLE -> IDLE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:337: SIPCC-DCSM: dcsm_update_gsm_state: 10: Not handling for CNF
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 10  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x141c23df0
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] fsm.c:346: SIPCC-FSM: 0/10, fsm_change_state: B2BCNF: IDLE -> IDLE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:337: SIPCC-DCSM: dcsm_update_gsm_state: 10: Not handling for B2BCNF
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 10  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x141c23e20
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmxfr.c:501: SIPCC-FSM: fsmxfr_cleanup: Entered.
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmxfr.c:451: SIPCC-FSM: fsmxfr_remove_fcb: Entered.
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] fsm.c:346: SIPCC-FSM: 0/10, fsm_change_state: XFR: IDLE -> IDLE
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:337: SIPCC-DCSM: dcsm_update_gsm_state: 10: Not handling for XFR
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsm.c:157: SIPCC-GSM_DBG_PTR: FSM 10  : fsm_get_fcb_by_call_id_and_type    : fcb= 0x0
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] ui.c:795: SIPCC-UI_API: ui_mnc_reached: line 6: Max number of calls reached =0
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccprovider.c:1502: SIPCC-SIP_CC_PROV: ccappUpdateSessionData: Call_STATE:. state=1, attr=0, cause=5, instance=0
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|CC_SIPCCService] CC_SIPCCService.cpp:724: onCallEvent(CCAPI_CALL_EV_STATE, 6000A, [ONHOOK|]
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccapi_call.c:56: SIPCC-SIP_CC_PROV: CCAPI_Call_releaseCallInfo: ref=0x17ea6ff0: count=2
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|def] ccapi.c:1423: SIPCC-CC_API: 7/11, cc_int_onhook: UI -> GSM: ONHOOK
17:00:09     INFO -  147308544[11b589e50]: [CCAPP Task|CC_SIPCCService] CC_SIPCCService.cpp:691: onLineEvent(CCAPI_LINE_EV_CAPSET_CHANGED, 6, [453053496|OOS]
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] sm.c:46: SIPCC-FSM: sm_process_event: DEF 11  : 0x103201220: sm entry: (IDLE:ONHOOK)
17:00:09     INFO -  207319040[14333f660]: [GSM Task|fsm_sm] fsmdef.c:2206: SIPCC-FSM: default - ignoring.
17:00:09     INFO -  207319040[14333f660]: [GSM Task|def] sm.c:65: SIPCC-GSM: 7/11, sm_process_event: DEF   :(IDLE:ONHOOK )
FWIW, this means we timed out on our crash test does a PC handshake, reloads the page, repeats again a few more times, and finishes only after 5 executions take place.
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Hmm...this definitely has to be a recent regression.
Keywords: regression
Whiteboard: [WebRTC] → [WebRTC][blocking-webrtc+]
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Ok, it appears that in the 'bad' case here, we never got a success callback from SetLocalDescription() (or error callback).  I'll attach some differences from the bad log and a good log from the same changeset.

Assigning to jib, but if anyone else (adam, ethan, etc) wants to look at it, it might be useful. This might be related to some other mochitest failed-to-exit bugs.  Ethan, you might want to at least eyeball the differences leading up to the failure; there's a lot of sipcc debugs in there that may mean more to you than others.
Assignee: nobody → jib
Priority: -- → P2
Created attachment 728776 [details]
log snippets showing difference between good and bad runs
This bug hasn't been seen since the 22nd, and only was seen from the 20th to 22nd.  Since then, on the 25th we landed a major orange fix (DISPATCH_SYNC removal) that might well be related (it could cause lots of odd/impossible JS results due to re-entrancy and was a timing bug).

Closing as works-for-me unless/until it shows up again.
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → WORKSFORME
Comment hidden (Treeherder Robot)
You need to log in before you can comment on or make changes to this bug.