1454627 - Failed to request permissions inside the handler of the menu item

Status: RESOLVED FIXED

(WebExtensions :: Frontend, defect)

Description

[eight04]

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:60.0) Gecko/20100101 Firefox/60.0
Build ID: 20180412172954

Steps to reproduce:

I encountered this bug while developing an extension:

1. Create a webextension.
2. In the background page, create a menu item and call permissions.request() from the onclick handler.

Demo:
https://github.com/eight04/webextension-test/tree/permission


Actual results:

An error occurred:
Error: permissions.request may only be called from a user input handler

If the handler is registered through menus.onClicked ("Test 2" in the demo):
Error: An unexpected error occurred


Expected results:

Quote from MDN:

> The request can only be made inside the handler for a user action, such as
> ... selecting its context menu item

https://developer.mozilla.org/en-US/Add-ons/WebExtensions/API/permissions/request

Comment 1

[u554753]

I'm not exactly certain if this is the correct component, so please correct if this is not the case. Thanks.

Comment 3

[Tomislav Jovanovic :zombie]

See bug 1422605 comment 17, this is a another related issue.

Comment 4

[Rob Wu [:robwu]]

This is because the onclick handler lacks a withHandlingUserInput call:
https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/browser/components/extensions/child/ext-menus.js#30-36

(the withHandlingUserInput call that the onClicked handler does have: https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/browser/components/extensions/child/ext-menus.js#170-178 )
(since Firefox 56 - bug 1369577)

Comment 5

[Rob Wu [:robwu]]

Attachment: Bug 1454627 - Re-enable browser_ext_user_events.js (bug 1381305)

Re-enable the test that was disabled in bug 1381305 and fix the
underlying issue that caused th intermittent failure in the first place.

Review commit: https://reviewboard.mozilla.org/r/259964/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/259964/

Comment 6

[Rob Wu [:robwu]]

Attachment: Bug 1454627 - Run "onclick" event of menu with user input

Review commit: https://reviewboard.mozilla.org/r/259966/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/259966/

Comment 7

[Shane Caraveo (:mixedpuppy)]

Comment on attachment 8995565 [details]
Bug 1454627 - Re-enable browser_ext_user_events.js (bug 1381305)

https://reviewboard.mozilla.org/r/259964/#review267312

Comment 8

[Shane Caraveo (:mixedpuppy)]

Comment on attachment 8995566 [details]
Bug 1454627 - Run "onclick" event of menu with user input

https://reviewboard.mozilla.org/r/259966/#review267324

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9661870b7453
Re-enable browser_ext_user_events.js (bug 1381305) r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/3285f664c261
Run "onclick" event of menu with user input r=mixedpuppy

Comment 10

[Cristina Coroiu [:ccoroiu]]

Backed out 2 changesets (bug 1454627) for frequently failing browser-chrome at browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js

Backout: https://hg.mozilla.org/integration/autoland/rev/01a86884bacb78670e48f1a2660e33f65e062b19

Failure push: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=3285f664c26122df3903d7a99eddf2cca8953f72

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=190986279&repo=autoland&lineNumber=34848

15:51:41     INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | request() succeeded when called from context menu in onClicked - 
15:51:41     INFO - Buffered messages finished
15:51:41     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Test timed out - 
15:51:41     INFO - Not taking screenshot here: see the one that was previously logged
15:51:41     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | no tasks awaiting on messages - Got ["request"], expected []
15:51:41     INFO - Stack trace:
15:51:41     INFO - chrome://mochikit/content/browser-test.js:test_is:1305
15:51:41     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:31
15:51:41     INFO - chrome://mochikit/content/browser-test.js:nextTest:705
15:51:41     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1200
15:51:41     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
15:51:41     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:996
15:51:41     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
15:51:41     INFO - Not taking screenshot here: see the one that was previously logged
15:51:41     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Extension left running at test shutdown - 
15:51:41     INFO - Stack trace:
15:51:41     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
15:51:41     INFO - chrome://mochikit/content/browser-test.js:nextTest:705
15:51:41     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1200
15:51:41     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
15:51:41     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:996
15:51:41     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
15:51:41     INFO - Console message: Warning: attempting to write 27955 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
15:51:41     INFO - GECKO(2079) | MEMORY STAT | vsize 5617MB | residentFast 744MB | heapAllocated 144MB
15:51:41     INFO - TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | took 90399ms
15:51:41     INFO - Not taking screenshot here: see the one that was previously logged
15:51:41     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Found a tab after previous test timed out: about:addons - 
15:51:41     INFO - GECKO(2079) | ++DOCSHELL 0x117624000 == 1 [pid = 2084] [id = {0b274640-dfea-0e4b-b2c3-bb5f727706cc}]
15:51:41     INFO - GECKO(2079) | ++DOMWINDOW == 1 (0x12938c400) [pid = 2084] [serial = 207] [outer = 0x0]
15:51:41     INFO - GECKO(2079) | ++DOMWINDOW == 2 (0x1176ef400) [pid = 2084] [serial = 208] [outer = 0x12938c400]
15:51:41     INFO - checking window state

Comment 11

[Rob Wu [:robwu]]

Attachment: Bug 1454627 - Fix timing issue in browser_ext_user_events.js

Review commit: https://reviewboard.mozilla.org/r/260472/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/260472/

Comment 12

[Shane Caraveo (:mixedpuppy)]

Comment on attachment 8996336 [details]
Bug 1454627 - Fix timing issue in browser_ext_user_events.js

https://reviewboard.mozilla.org/r/260472/#review267550

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/22de883763ac
Re-enable browser_ext_user_events.js (bug 1381305) r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/44b38de7dc3d
Run "onclick" event of menu with user input r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/38d9cbe6e3d2
Fix timing issue in browser_ext_user_events.js r=mixedpuppy

Comment 14

[Bogdan Tara[:bogdan_tara | bogdant]]

Backed out 3 changesets (Bug 1454627) for test-oop-extensions/browser_ext_user_events.js failures.

Push with failures:https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=38d9cbe6e3d20e9099807a00bf1335a8451a9764

Backout link: https://hg.mozilla.org/integration/autoland/rev/c6b4c044da81ae4276028bedc442f28f5ebb1453

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=191224490&repo=autoland&lineNumber=32281

13:46:28     INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | notification panel open - 
13:46:28     INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | request() did not throw when called from context menu in onClicked - 
13:46:28     INFO - TEST-PASS | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | request() succeeded when called from context menu in onClicked - 
13:46:28     INFO - Buffered messages finished
13:46:28     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Test timed out - 
13:46:28     INFO - Not taking screenshot here: see the one that was previously logged
13:46:28     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | no tasks awaiting on messages - Got ["request"], expected []
13:46:28     INFO - Stack trace:
13:46:28     INFO - chrome://mochikit/content/browser-test.js:test_is:1305
13:46:28     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:31
13:46:28     INFO - chrome://mochikit/content/browser-test.js:nextTest:705
13:46:28     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1200
13:46:28     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
13:46:28     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:996
13:46:28     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
13:46:28     INFO - Not taking screenshot here: see the one that was previously logged
13:46:28     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Extension left running at test shutdown - 
13:46:28     INFO - Stack trace:
13:46:28     INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
13:46:28     INFO - chrome://mochikit/content/browser-test.js:nextTest:705
13:46:28     INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1200
13:46:28     INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1162
13:46:28     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:996
13:46:28     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
13:46:28     INFO - Console message: Warning: attempting to write 28115 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
13:46:28     INFO - GECKO(2001) | MEMORY STAT | vsize 5635MB | residentFast 755MB | heapAllocated 144MB
13:46:28     INFO - TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | took 90419ms
13:46:28     INFO - Not taking screenshot here: see the one that was previously logged
13:46:28     INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_user_events.js | Found a tab after previous test timed out: about:addons - 
13:46:28     INFO - GECKO(2001) | ++DOCSHELL 0x11195f800 == 1 [pid = 2006] [id = {fcb56f42-f989-9540-b028-305965070ed0}]
13:46:28     INFO - GECKO(2001) | ++DOMWINDOW == 1 (0x11ced1600) [pid = 2006] [serial = 206] [outer = 0x0]
13:46:28     INFO - GECKO(2001) | ++DOMWINDOW == 2 (0x10a9f2800) [pid = 2006] [serial = 207] [outer = 0x11ced1600]

Comment 15

[Bogdan Tara[:bogdan_tara | bogdant]]

https://hg.mozilla.org/mozilla-central/rev/22de883763ac
https://hg.mozilla.org/mozilla-central/rev/44b38de7dc3d
https://hg.mozilla.org/mozilla-central/rev/38d9cbe6e3d2

Comment 16

[Rob Wu [:robwu]]

Comment on attachment 8996336 [details]
Bug 1454627 - Fix timing issue in browser_ext_user_events.js

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/260472/diff/1-2/

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/64e2944b635b
Re-enable browser_ext_user_events.js (bug 1381305) r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/50114fce0886
Run "onclick" event of menu with user input r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/3a4b606f79ae
Fix timing issue in browser_ext_user_events.js r=mixedpuppy

Comment 18

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/64e2944b635b
https://hg.mozilla.org/mozilla-central/rev/50114fce0886
https://hg.mozilla.org/mozilla-central/rev/3a4b606f79ae

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/30a17d2d7779
https://hg.mozilla.org/releases/mozilla-beta/rev/5c573fbddd4b
https://hg.mozilla.org/releases/mozilla-beta/rev/fd81c0f6fb7f

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr60/rev/7f50df7d3dff
https://hg.mozilla.org/releases/mozilla-esr60/rev/e9ebf293f7d2
https://hg.mozilla.org/releases/mozilla-esr60/rev/c757271f3a16