Closed Bug 1633686 Opened 5 years ago Closed 5 years ago

Intermittent browser/base/content/test/performance/browser_startup_syncIPC.js | unexpected PCompositorWidget::Msg_Initialize sync IPC before becoming idle -

Categories

(Core :: Graphics: Layers, defect, P5)

Product:
Core
Component:
Graphics: Layers
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1580390

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: aiakab [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=299736004&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SLc_DY99TA-itzrbEKbjQQ/runs/0/artifacts/public/logs/live_backing.log

[task 2020-04-28T06:21:52.973Z] 06:21:52 INFO - TEST-START | browser/base/content/test/performance/browser_startup_syncIPC.js
[task 2020-04-28T06:21:52.998Z] 06:21:52 INFO - TEST-INFO | started process screenshot
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - TEST-INFO | screenshot: exit 0
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - Buffered messages logged at 06:21:52
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - Entering test bound
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - whitelisted sync IPC before first paint:
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - PLayerTransaction::Msg_GetTextureFactoryIdentifier - at most 3 times
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - PCompositorBridge::Msg_NotifyChildCreated - at most 2 times
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - PCompositorBridge::Msg_MapAndNotifyChildCreated - at most 2 times
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - PCompositorBridge::Msg_FlushRendering - at most 1 times
[task 2020-04-28T06:21:53.078Z] 06:21:53 INFO - PCompositorBridge::Msg_Initialize - at most 3 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - PCompositorWidget::Msg_Initialize - at most 3 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - PGPU::Msg_AddLayerTreeIdMapping - at most 5 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - PCompositorBridge::Msg_MakeSnapshot - at most 1 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - PCompositorBridge::Msg_WillClose - at most 2 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - PAPZInputBridge::Msg_ProcessUnhandledEvent - at most 1 times
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PLayerTransaction::Msg_GetTextureFactoryIdentifier allowed 1 more times before first paint -
[task 2020-04-28T06:21:53.079Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_NotifyChildCreated allowed 2 more times before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_MapAndNotifyChildCreated happened as many times as expected before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_FlushRendering happened as many times as expected before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_Initialize allowed 1 more times before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorWidget::Msg_Initialize allowed 1 more times before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PGPU::Msg_AddLayerTreeIdMapping happened as many times as expected before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_MakeSnapshot allowed 1 more times before first paint -
[task 2020-04-28T06:21:53.080Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_WillClose allowed 2 more times before first paint -
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PAPZInputBridge::Msg_ProcessUnhandledEvent happened as many times as expected before first paint -
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - whitelisted sync IPC before handling user events:
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PLayerTransaction::Msg_GetTextureFactoryIdentifier - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PCompositorBridge::Msg_Initialize - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PCompositorWidget::Msg_Initialize - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PCompositorBridge::Msg_WillClose - at most 2 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PCompositorBridge::Msg_MakeSnapshot - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PAPZInputBridge::Msg_ProcessUnhandledEvent - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - PAPZInputBridge::Msg_ReceiveMouseInputEvent - at most 1 times
[task 2020-04-28T06:21:53.081Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PLayerTransaction::Msg_GetTextureFactoryIdentifier happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_Initialize happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorWidget::Msg_Initialize happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_WillClose happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PCompositorBridge::Msg_MakeSnapshot happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PAPZInputBridge::Msg_ProcessUnhandledEvent happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.082Z] 06:21:53 INFO - TEST-PASS | browser/base/content/test/performance/browser_startup_syncIPC.js | sync IPC PAPZInputBridge::Msg_ReceiveMouseInputEvent happened as many times as expected before handling user events -
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - whitelisted sync IPC before becoming idle:
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - PCompositorBridge::Msg_NotifyChildCreated - at most 1 times
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - PAPZInputBridge::Msg_ProcessUnhandledEvent - at most 1 times
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - PAPZInputBridge::Msg_ReceiveMouseInputEvent - at most 1 times
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - PCompositorBridge::Msg_MapAndNotifyChildCreated - at most 1 times
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - PCompositorBridge::Msg_WillClose - at most 2 times
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - Buffered messages finished
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup_syncIPC.js | unexpected PCompositorWidget::Msg_Initialize sync IPC before becoming idle -
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - Stack trace:
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - chrome://mochikit/content/browser-test.js:test_ok:1269
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - chrome://mochitests/content/browser/browser/base/content/test/performance/browser_startup_syncIPC.js:null:345
[task 2020-04-28T06:21:53.083Z] 06:21:53 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1039
[task 2020-04-28T06:21:53.084Z] 06:21:53 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2020-04-28T06:21:53.084Z] 06:21:53 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:904
[task 2020-04-28T06:21:53.084Z] 06:21:53 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-04-28T06:21:53.084Z] 06:21:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-04-28T06:21:53.084Z] 06:21:53 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/performance/browser_startup_syncIPC.js | unexpected PCompositorBridge::Msg_Initialize sync IPC before becoming idle -

Hey Arthur, seems this was filed in the wrong component, can you update it please? Thanks!

Flags: needinfo?(aiakab)

Hi Ptrick, sure. Thank you for letting me know.

Product: Chat Core → Core
Version: trunk → unspecified
Flags: needinfo?(aiakab)

Do we need more annotations for intermittent sync IPC message issues?

Component: General → Graphics: WebRender
Flags: needinfo?(sotaro.ikeda.g)
Flags: needinfo?(kats)

This is on a non-WebRender run, so moving to Layers. Looks like the three events:

PCompositorBridge::Msg_Initialize
PCompositorWidget::Msg_Initialize
PLayerTransaction::Msg_GetTextureFactoryIdentifier

happened in the "before idle" phase rather than the "before first paint" phase where they were expected to occur. Not sure why, but maybe ccov runs are really slow and so whatever window that was got delayed. If this happens again we can consider updating the annotations. So far it's only occurred once, not sure it's worth the effort to update the annotations.

Component: Graphics: WebRender → Graphics: Layers
Flags: needinfo?(kats)
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → DUPLICATE
Flags: needinfo?(sotaro.ikeda.g)
You need to log in before you can comment on or make changes to this bug.