1576042 - Perma Android 4.3 M-1proc toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"args":[{"url":"

Status: RESOLVED FIXED

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2019-08-23T00:40:48.243Z] 00:40:48 INFO - 135 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"args":["ready"]}, Actual: {"args":["ready"]}
[task 2019-08-23T00:40:48.243Z] 00:40:48 INFO - Buffered messages logged at 00:40:45
[task 2019-08-23T00:40:48.245Z] 00:40:48 INFO - 136 INFO onExtensionActivity {"id":"[e-mail]","viewType":"background","timeStamp":"2019-08-23T00:40:45.736Z","type":"api_event","name":"webRequest.onBeforeRequest","data":{"args":[{"requestId":"20","url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","originUrl":"moz-extension://3f78545d-d5e6-4ef7-9134-0ae1ba52cb12/","method":"GET","type":"main_frame","timeStamp":1566520845360,"frameId":0,"parentFrameId":-1,"proxyInfo":{"connectionIsolationKey":"","failoverTimeout":1800,"host":"10.0.2.2","port":8854,"proxyAuthorizationHeader":"","proxyDNS":false,"type":"http","username":""},"ip":null,"frameAncestors":[],"urlClassification":{"firstParty":[],"thirdParty":[]},"tabId":2,"incognito":false}],"result":{"cancel":false}}}
[task 2019-08-23T00:40:48.245Z] 00:40:48 INFO - 137 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | type matches - Expected: api_event, Actual: api_event
[task 2019-08-23T00:40:48.245Z] 00:40:48 INFO - 138 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | name matches - Expected: webRequest.onBeforeRequest, Actual: webRequest.onBeforeRequest
[task 2019-08-23T00:40:48.246Z] 00:40:48 INFO - Buffered messages finished
[task 2019-08-23T00:40:48.247Z] 00:40:48 INFO - 139 INFO TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"args":[{"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","method":"GET","type":"main_frame","frameId":0,"parentFrameId":-1,"ip":null,"frameAncestors":[],"incognito":false}],"result":{"cancel":false}}, Actual: {"args":[{"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","method":"GET","type":"main_frame","frameId":0,"parentFrameId":-1,"ip":null,"frameAncestors":[],"urlClassification":{"firstParty":[],"thirdParty":[]},"incognito":false}],"result":{"cancel":false}}
[task 2019-08-23T00:40:48.248Z] 00:40:48 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-08-23T00:40:48.248Z] 00:40:48 INFO - testHandler@SimpleTest/ExtensionTestUtils.js:59:18
[task 2019-08-23T00:40:48.248Z] 00:40:48 INFO - testResult@SimpleTest/ExtensionTestUtils.js:73:18
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 140 INFO onExtensionActivity {"id":"[e-mail]","timeStamp":"2019-08-23T00:40:49.572Z","type":"content_script","name":"moz-extension://feb07c2c-ff67-4c12-bbdc-753b31f2db45/content_script.js","data":{"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 141 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | type matches - Expected: content_script, Actual: content_script
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 142 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | content script name matches
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 143 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}, Actual: {"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 144 INFO onExtensionActivity {"id":"[e-mail]","timeStamp":"2019-08-23T00:40:49.627Z","type":"content_script","name":"moz-extension://feb07c2c-ff67-4c12-bbdc-753b31f2db45/registered_script.js","data":{"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 145 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | type matches - Expected: content_script, Actual: content_script
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 146 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | content script name matches
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 147 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}, Actual: {"url":"http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/file_sample.html","tabId":2}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 148 INFO onExtensionActivity {"id":"[e-mail]","timeStamp":"2019-08-23T00:40:50.630Z","type":"api_call","name":"test.sendMessage","data":{"args":["registered_script"],"tabId":2}}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 149 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | type matches - Expected: api_call, Actual: api_call
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 150 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | name matches - Expected: test.sendMessage, Actual: test.sendMessage
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 151 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"args":["registered_script"],"tabId":2}, Actual: {"args":["registered_script"],"tabId":2}
[task 2019-08-23T00:40:58.962Z] 00:40:58 INFO - 152 INFO onExtensionActivity {"id":"[e-mail]","timeStamp":"2019-08-23T00:40:54.462Z","type":"api_call","name":"test.sendMessage","data":{"args":["content_script"],"tabId":2}}
[task 2019-08-23T00:40:58.963Z] 00:40:58 INFO - 153 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | type matches - Expected: api_call, Actual: api_call
[task 2019-08-23T00:40:58.963Z] 00:40:58 INFO - 154 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | name matches - Expected: test.sendMessage, Actual: test.sendMessage
[task 2019-08-23T00:40:58.963Z] 00:40:58 INFO - 155 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | message matches - Expected: {"args":["content_script"],"tabId":2}, Actual: {"args":["content_script"],"tabId":2}
[task 2019-08-23T00:40:58.964Z] 00:40:58 INFO - 156 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | activity
[task 2019-08-23T00:40:58.964Z] 00:40:58 INFO - 157 INFO TEST-PASS | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | test result correct
[task 2019-08-23T00:40:58.964Z] 00:40:58 INFO - 158 INFO add_task | Leaving test test_api
[task 2019-08-23T00:40:58.964Z] 00:40:58 INFO - 159 INFO TEST-OK | toolkit/components/extensions/test/mochitest/test_ext_activityLog.html | took 22202ms
[task 2019-08-23T00:41:09.496Z] 00:41:09 INFO - 160 INFO TEST-START | toolkit/components/extensions/test/mochitest/test_ext_background_canvas.html

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

This is a regression from bug 1564594 and causes toolkit/components/extensions/test/mochitest/test_ext_activityLog.html to fail. Thomas, please investigate.

The object in the test also contains "urlClassification":{"firstParty":[],"thirdParty":[]} now.

Comment 2

[Shane Caraveo (:mixedpuppy)]

Hrm, that shouldn't happen because the test extension is not privileged. IOW, for some reason, extensions are running privileged on android.

Comment 3

[Thomas Wisniewski [:twisniewski]]

It appears that by adding a webRequest.onBeforeRequest listener to the webcompat system addon (which matches all URLs, not just specific ones) there is an extra "urlClassification":{"firstParty":[],"thirdParty":[] key added to the object the test is listening for. I'll continue to investigating; I may have a simple workaround.

Comment 4

[Shane Caraveo (:mixedpuppy)]

I don't want to see a workaround here, urlClassification should only be available to privileged extensions. Something is happening that is leaking that into a non-privileged extension.

This might be my bug.

Comment 5

[Intermittent Failures Robot]

15 failures in 5073 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 15

Platform breakdown:

• android-em-4-3-armv7-api16: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1576042&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 6

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Fixed by bug 1576252.

Comment 7

[Alex Cornestean]

Hello,

Will this fix require manual validation? If yes, please provide some steps to reproduce in order to correctly test it and also, please set the "qe-verify+" flag. Otherwise, could the "qe-verify-" flag be added? Thanks!