1581999 - Perma [tier2] devtools/client/webreplay/mochitest/browser_dbg_rr_logpoint-03.js | Test timed out -

Status: RESOLVED FIXED

(Core Graveyard :: Web Replay, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: opoprus [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=267137620&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/HKa9fJXkTg6kZSYgnfb_Rw/runs/0/artifacts/public/logs/live_backing.log

---

Treeherder link: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=267146930&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception%2Cusercancel%2Crunnable&fromchange=941fd5bb51f703a22899c46873c29c11cd4f9f7c&searchStr=os%2Cx%2C10.14%2Cshippable%2Copt%2Cmochitests%2Ctest-macosx1014-64-shippable%2Fopt-mochitest-devtools-webreplay-e10s%2Cm%28dt-wr%29

Failure log: [task 2019-09-17T23:03:27.779Z] 23:03:27 INFO - TEST-INFO | started process screencapture
[task 2019-09-17T23:03:27.945Z] 23:03:27 INFO - TEST-INFO | screencapture: exit 0
[task 2019-09-17T23:03:27.945Z] 23:03:27 INFO - Buffered messages logged at 23:00:27
[task 2019-09-17T23:03:27.945Z] 23:03:27 INFO - Entering test bound
[task 2019-09-17T23:03:27.945Z] 23:03:27 INFO - Waiting for event: 'RecordingFinished' on [object ParentProcessMessageManager].
[task 2019-09-17T23:03:27.946Z] 23:03:27 INFO - Buffered messages logged at 23:00:28
[task 2019-09-17T23:03:27.946Z] 23:03:27 INFO - Console message: [JavaScript Error: "ReferenceError: Services is not defined" {file: "chrome://global/content/browser-child.js" line: 26}]
[task 2019-09-17T23:03:27.946Z] 23:03:27 INFO - Buffered messages logged at 23:00:30
[task 2019-09-17T23:03:27.946Z] 23:03:27 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/devtools/client/webreplay/mochitest/examples/doc_events.html" line: 0}]
[task 2019-09-17T23:03:27.946Z] 23:03:27 INFO - Got event: 'RecordingFinished' on [object ParentProcessMessageManager].
[task 2019-09-17T23:03:27.947Z] 23:03:27 INFO - Buffered messages logged at 23:00:32
[task 2019-09-17T23:03:27.947Z] 23:03:27 INFO - Waiting for state change: paused
[task 2019-09-17T23:03:27.947Z] 23:03:27 INFO - Finished waiting for state change: paused
[task 2019-09-17T23:03:27.947Z] 23:03:27 INFO - Buffered messages logged at 23:01:12
[task 2019-09-17T23:03:27.947Z] 23:03:27 INFO - Longer timeout required, waiting longer... Remaining timeouts: 3
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - Buffered messages logged at 23:01:57
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - Longer timeout required, waiting longer... Remaining timeouts: 2
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - Buffered messages logged at 23:02:11
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - Console message: [JavaScript Error: "getScreenshot(http://example.com/browser/devtools/client/webreplay/mochitest/examples/doc_rr_basic.html) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - asyncmaybeCacheScreenshot@resource://activity-stream/lib/Screenshots.jsm:112:37
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - _fetchScreenshot@resource://activity-stream/lib/TopSitesFeed.jsm:527:23
[task 2019-09-17T23:03:27.948Z] 23:03:27 INFO - _fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:515:16
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:408:16
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - asyncrefresh@resource://activity-stream/lib/TopSitesFeed.jsm:431:30
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - onAction@resource://activity-stream/lib/TopSitesFeed.jsm:771:14
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:63:17
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:39:54
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:27:24
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - notify@resource://gre/modules/Timer.jsm:62:17
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO -
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - Buffered messages logged at 23:02:42
[task 2019-09-17T23:03:27.949Z] 23:03:27 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
[task 2019-09-17T23:03:27.950Z] 23:03:27 INFO - Buffered messages finished
[task 2019-09-17T23:03:27.950Z] 23:03:27 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webreplay/mochitest/browser_dbg_rr_logpoint-03.js | Test timed out -
[task 2019-09-17T23:03:27.950Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.52] SetPauseState RESUMING_FORWARD {"checkpoint":9,"progress":34}
[task 2019-09-17T23:03:27.950Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.52] SetPauseState RUNNING {"checkpoint":9,"progress":34} #0
[task 2019-09-17T23:03:27.952Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.52] SendManifest #0 {"kind":"resume","breakpoints":[],"pauseOnDebuggerStatement":true}
[task 2019-09-17T23:03:27.952Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.53] SendManifest #1 {"kind":"restoreSnapshot","numSnapshots":0}
[task 2019-09-17T23:03:27.952Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] ManifestFinished #1 {"restoredSnapshot":true,"point":{"checkpoint":9,"progress":34}}
[task 2019-09-17T23:03:27.953Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Statistics:
[task 2019-09-17T23:03:27.953Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Total recording time: 477.2872849997366
[task 2019-09-17T23:03:27.953Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Unscanned fraction: 0
[task 2019-09-17T23:03:27.953Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Average scan delay: 2153.25933707918
[task 2019-09-17T23:03:27.954Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Average scanning overhead: 4.079742277234543
[task 2019-09-17T23:03:27.954Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Saved checkpoints: 7
[task 2019-09-17T23:03:27.954Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Memory Generic: 102400
[task 2019-09-17T23:03:27.954Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Memory Snapshots: 87846912
[task 2019-09-17T23:03:27.956Z] 23:03:27 INFO - GECKO(1646) | [ReplayControl 179.55] Memory ScriptHits: 36864
[task 2019-09-17T23:03:28.328Z] 23:03:28 INFO - Removing tab.
[task 2019-09-17T23:03:28.328Z] 23:03:28 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2019-09-17T23:03:28.329Z] 23:03:28 INFO - Got event: 'TabClose' on [object XULElement].
[task 2019-09-17T23:03:28.345Z] 23:03:28 INFO - Tab removed and finished closing
[task 2019-09-17T23:03:28.430Z] 23:03:28 INFO - GECKO(1646) | MEMORY STAT | vsize 7835MB | residentFast 520MB | heapAllocated 151MB
[task 2019-09-17T23:03:28.430Z] 23:03:28 INFO - TEST-OK | devtools/client/webreplay/mochitest/browser_dbg_rr_logpoint-03.js | took 180735ms
[task 2019-09-17T23:03:28.463Z] 23:03:28 INFO - checking window state

Comment 1

[Brian Hackett [Laid off!]]

Attachment: Bug 1581999 - Fix event logging while replaying, r=jlast.

Comment 2

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/06f79f0a1cd5
Fix event logging while replaying, r=jlast.

Comment 3

[Intermittent Failures Robot]

20 failures in 845 pushes (0.024 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 20

Platform breakdown:

• macosx1014-64-shippable: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1581999&startday=2019-09-17&endday=2019-09-17&tree=all

Comment 4

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/06f79f0a1cd5

Comment 5

[Intermittent Failures Robot]

25 failures in 4350 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 25

Platform breakdown:

• macosx1014-64-shippable: 25

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1581999&startday=2019-09-16&endday=2019-09-22&tree=all