Closed Bug 1579622 Opened 6 years ago Closed 6 years ago

Intermittent devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | The badge has the expected text - Got 3, expected 2

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=265506313&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/IBzxwqYlRWaAcNumLMT7Hw/runs/0/artifacts/public/logs/live_backing.log


[task 2019-09-07T11:10:21.388Z] 11:10:21 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | The message has the expected indent -
[task 2019-09-07T11:10:21.389Z] 11:10:21 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | Message includes the expected "simple message 2" content - "simple message 2 content-task.js line 62 > eval:4:21" -
[task 2019-09-07T11:10:21.389Z] 11:10:21 INFO - Log a second storage blocked message to check that it creates another group
[task 2019-09-07T11:10:21.390Z] 11:10:21 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “http://example.com/browser/devtools/client/webconsole/test/browser/test-image.png?4-1567854617949” was blocked because we are blocking all third-party storage access requests and content blocking is enabled." {file: "http://example.org/browser/devtools/client/webconsole/test/browser/test-warning-groups.html" line: 0}]
[task 2019-09-07T11:10:21.391Z] 11:10:21 INFO - Console message: [JavaScript Warning: "Request to access cookie or storage on “http://example.com/browser/devtools/client/webconsole/test/browser/test-image.png?4-1567854617949” was blocked because we are blocking all third-party storage access requests and content blocking is enabled." {file: "http://example.org/browser/devtools/client/webconsole/test/browser/test-warning-groups.html" line: 0}]
[task 2019-09-07T11:10:21.392Z] 11:10:21 INFO - Buffered messages logged at 11:10:21
[task 2019-09-07T11:10:21.393Z] 11:10:21 INFO - Matched a message with text: "Request to access cookie or storage on “<URL>” was blocked because we are blocking all third-party storage access requests and content blocking is enabled.", all messages received.
[task 2019-09-07T11:10:21.394Z] 11:10:21 INFO - Buffered messages finished
[task 2019-09-07T11:10:21.395Z] 11:10:21 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | The badge has the expected text - Got 3, expected 2
[task 2019-09-07T11:10:21.396Z] 11:10:21 INFO - Stack trace:
[task 2019-09-07T11:10:21.397Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:test_is:1595
[task 2019-09-07T11:10:21.398Z] 11:10:21 INFO - chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js:testContentBlockingMessage:136
[task 2019-09-07T11:10:21.399Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1350
[task 2019-09-07T11:10:21.399Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1385
[task 2019-09-07T11:10:21.399Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1213
[task 2019-09-07T11:10:21.400Z] 11:10:21 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:805
[task 2019-09-07T11:10:21.400Z] 11:10:21 INFO - Expand the second warning group
[task 2019-09-07T11:10:21.400Z] 11:10:21 INFO - GECKO(1159) | [Parent 1159, Main Thread] ###!!! ASSERTION: Unexpected UpdateTransformLayer hint: '!(aChange & nsChangeHint_UpdateTransformLayer) || aFrame->IsTransformed() || aFrame->StyleDisplay()->HasTransformStyle()', file /builds/worker/workspace/build/src/layout/base/RestyleManager.cpp, line 1210
[task 2019-09-07T11:10:21.400Z] 11:10:21 INFO - GECKO(1159) | #01: mozilla::RestyleManager::DoProcessPendingRestyles(mozilla::ServoTraversalFlags) [xpcom/ds/nsTArray.h:347]
[task 2019-09-07T11:10:21.400Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.401Z] 11:10:21 INFO - GECKO(1159) | #02: mozilla::PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush) [layout/base/PresShell.cpp:4127]
[task 2019-09-07T11:10:21.401Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.401Z] 11:10:21 INFO - GECKO(1159) | #03: nsRefreshDriver::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/PresShell.h:0]
[task 2019-09-07T11:10:21.401Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.401Z] 11:10:21 INFO - GECKO(1159) | #04: mozilla::RefreshDriverTimer::TickRefreshDrivers(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp, nsTArray<RefPtr<nsRefreshDriver> >&) [layout/base/nsRefreshDriver.cpp:344]
[task 2019-09-07T11:10:21.402Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.402Z] 11:10:21 INFO - GECKO(1159) | #05: mozilla::RefreshDriverTimer::Tick(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:367]
[task 2019-09-07T11:10:21.402Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.402Z] 11:10:21 INFO - GECKO(1159) | #06: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::TickRefreshDriver(mozilla::layers::BaseTransactionId<mozilla::VsyncIdType>, mozilla::TimeStamp) [layout/base/nsRefreshDriver.cpp:729]
[task 2019-09-07T11:10:21.402Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.403Z] 11:10:21 INFO - GECKO(1159) | #07: mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::ParentProcessVsyncNotifier::Run() [layout/base/nsRefreshDriver.cpp:526]
[task 2019-09-07T11:10:21.403Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.403Z] 11:10:21 INFO - GECKO(1159) | #08: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1214]
[task 2019-09-07T11:10:21.403Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.403Z] 11:10:21 INFO - GECKO(1159) | #09: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:486]
[task 2019-09-07T11:10:21.404Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.404Z] 11:10:21 INFO - GECKO(1159) | #10: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:88]
[task 2019-09-07T11:10:21.404Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.404Z] 11:10:21 INFO - GECKO(1159) | #11: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:315]
[task 2019-09-07T11:10:21.404Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.405Z] 11:10:21 INFO - GECKO(1159) | #12: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
[task 2019-09-07T11:10:21.405Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.405Z] 11:10:21 INFO - GECKO(1159) | #13: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:139]
[task 2019-09-07T11:10:21.405Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.405Z] 11:10:21 INFO - GECKO(1159) | #14: nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:277]
[task 2019-09-07T11:10:21.406Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.406Z] 11:10:21 INFO - GECKO(1159) | #15: XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:4585]
[task 2019-09-07T11:10:21.406Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.406Z] 11:10:21 INFO - GECKO(1159) | #16: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:4720]
[task 2019-09-07T11:10:21.406Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO - GECKO(1159) | #17: XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:4801]
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO - GECKO(1159) | #18: _fini
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO - GECKO(1159) | #19: libc.so.6 + 0x20830
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO - GECKO(1159) | #20: _fini
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO -
[task 2019-09-07T11:10:21.411Z] 11:10:21 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | Got the expected number of messages - Got 7, expected 6
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - Stack trace:
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:test_is:1595
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/head.js:checkConsoleOutputForWarningGroup:1373
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochitests/content/browser/devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js:testContentBlockingMessage:147
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1350
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1385
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1213
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:805
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - Checking "▶︎⚠ The resource at “<URL>” was blocked because content blocking is enabled."
[task 2019-09-07T11:10:21.412Z] 11:10:21 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js | There's a collapsed arrow -

entering test: TEST-START | devtools/client/webconsole/test/browser/browser_webconsole_warning_group_multiples.js

Ehsan, would you have an idea why we sometimes get the same tracking protection warning message when the test is run with Fission?
I don't see anything clear in devtools code that would explain this, so maybe this is related to the platform code that emit the message?

Flags: needinfo?(ehsan)

The warning is definitely emitted from platform code, but it could be triggered from anything in Gecko. The way to find out what's the culprit is to set a breakpoint on ReportBlockingToConsole() and backtrack where the console notification is coming from by seeing where the call is coming from. This is probably easiest to debug in an intermittent test using Pernosco or rr.

Flags: needinfo?(ehsan)
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: