Closed Bug 1855189 Opened 2 years ago Closed 7 months ago

Intermittent dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py | single tracking bug

Categories

(Core :: Storage: IndexedDB, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=430335488&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/f0BM7H39QD6gP0KXFe3x3A/runs/0/artifacts/public/logs/live_backing.log


DEBUG: Completed blocker Transaction (6) for phase content-prefs.sqlite#0: waiting for clients
[task 2023-09-26T10:50:55.665Z] 10:50:55     INFO -  1695725455664	Marionette	DEBUG	2 -> [0,24,"WebDriver:ExecuteScript",{"script":"const [idb, store, key, value] = arguments;\n                window.wrappedJSObject.addDataIntoIDB(idb, store, key, value);","args":["IDBTest","IDBTestStore","textKey","test_IDB_Encryption_PBM"],"newSandbox":true,"sandbox":"default","line":94,"filename":"tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py"}]
[task 2023-09-26T10:50:55.677Z] 10:50:55     INFO -  1695725455677	RemoteAgent	TRACE	WebDriverProcessData actor created for PID 29952
[task 2023-09-26T10:50:55.687Z] 10:50:55     INFO -  1695725455687	Marionette	TRACE	[14] MarionetteCommands actor created for window id 6442450945
[task 2023-09-26T10:50:55.711Z] 10:50:55     INFO -  1695725455711	Marionette	DEBUG	2 <- [1,24,null,{"value":null}]
[task 2023-09-26T10:50:55.713Z] 10:50:55     INFO -  1695725455712	Marionette	DEBUG	2 -> [0,25,"Marionette:GetContext",{}]
[task 2023-09-26T10:50:55.714Z] 10:50:55     INFO -  1695725455713	Marionette	DEBUG	2 <- [1,25,null,{"value":"content"}]
[task 2023-09-26T10:50:55.715Z] 10:50:55     INFO -  1695725455715	Marionette	DEBUG	2 -> [0,26,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-09-26T10:50:55.716Z] 10:50:55     INFO -  1695725455716	Marionette	DEBUG	2 <- [1,26,null,{"value":null}]
[task 2023-09-26T10:50:55.718Z] 10:50:55     INFO -  1695725455717	Marionette	DEBUG	2 -> [0,27,"WebDriver:ExecuteAsyncScript",{"script":"const [url, resolve] = arguments;\n\n                    function getOrigin() {\n                        return new Promise((res ... Origin()\n                        .then((result) => resolve(result))\n                        .catch((error) => resolve(null));","args":["http://127.0.0.1:43470^privateBrowsingId=1"],"newSandbox":false,"sandbox":"default","scriptTimeout":null,"line":158,"filename":"tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py"}]
[task 2023-09-26T10:50:55.720Z] 10:50:55     INFO -  1695725455720	Marionette	TRACE	[12] MarionetteCommands actor created for window id 26
[task 2023-09-26T10:50:55.748Z] 10:50:55     INFO -  1695725455747	Marionette	DEBUG	2 <- [1,27,null,{"value":null}]
[task 2023-09-26T10:50:55.751Z] 10:50:55     INFO -  1695725455750	Marionette	DEBUG	2 -> [0,28,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-26T10:50:55.751Z] 10:50:55     INFO -  1695725455750	Marionette	DEBUG	2 <- [1,28,null,{"value":null}]
[task 2023-09-26T10:50:55.753Z] 10:50:55     INFO -  1695725455753	Marionette	DEBUG	2 -> [0,29,"Marionette:GetContext",{}]
[task 2023-09-26T10:50:55.754Z] 10:50:55     INFO -  1695725455753	Marionette	DEBUG	2 <- [1,29,null,{"value":"content"}]
[task 2023-09-26T10:50:55.756Z] 10:50:55     INFO -  1695725455755	Marionette	DEBUG	2 -> [0,30,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-09-26T10:50:55.756Z] 10:50:55     INFO -  1695725455756	Marionette	DEBUG	2 <- [1,30,null,{"value":null}]
[task 2023-09-26T10:50:55.758Z] 10:50:55     INFO -  1695725455758	Marionette	DEBUG	2 -> [0,31,"WebDriver:TakeScreenshot",{"id":null,"full":true,"hash":false,"scroll":true}]
[task 2023-09-26T10:50:55.923Z] 10:50:55     INFO -  1695725455922	Marionette	DEBUG	2 <- [1,31,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQQCAYAAAC9RfbYAAAgAElEQVR4XuzdCbgkZ1kv8O9MSILJJGEJkE0SFiGAICJgcr1XUQQBJYhRFAIRL1sIKGHxkU1ikM3LL ... QIECAAAECBAgQIECAAAECBAgUAQdg0ZMlQIAAAQIECBAgQIAAAQIECBAgcC7gADwfSD0CBAgQIECAAAECBAgQIECAAAECRWCHVRroUvdOtAAAAABJRU5ErkJggg=="}]
[task 2023-09-26T10:50:55.933Z] 10:50:55     INFO -  1695725455933	Marionette	DEBUG	2 -> [0,32,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-26T10:50:55.933Z] 10:50:55     INFO -  1695725455933	Marionette	DEBUG	2 <- [1,32,null,{"value":null}]
[task 2023-09-26T10:50:55.935Z] 10:50:55     INFO -  1695725455935	Marionette	DEBUG	2 -> [0,33,"Marionette:GetContext",{}]
[task 2023-09-26T10:50:55.935Z] 10:50:55     INFO -  1695725455935	Marionette	DEBUG	2 <- [1,33,null,{"value":"content"}]
[task 2023-09-26T10:50:55.937Z] 10:50:55     INFO -  1695725455937	Marionette	DEBUG	2 -> [0,34,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-26T10:50:55.937Z] 10:50:55     INFO -  1695725455937	Marionette	DEBUG	2 <- [1,34,null,{"value":null}]
[task 2023-09-26T10:50:55.939Z] 10:50:55     INFO -  1695725455938	Marionette	DEBUG	2 -> [0,35,"WebDriver:GetPageSource",{}]
[task 2023-09-26T10:50:55.941Z] 10:50:55     INFO -  1695725455940	Marionette	DEBUG	2 <- [1,35,null,{"value":"<html><head>\n\t\t<script>\n\t\t\tasync function ensureIDB(name, ver, store) {\n\t\t\t\treturn new Promise((resolve, reject) => {\n\t\t\t\t\tle ... \n\t\t\t\t}));\n\n\t\t\t\tcloseIDB(db)\n\t\t\t};\n\n\t\t\tfunction closeIDB(db) {\n\t\t\t\tdb.close();\n\t\t\t}\n\t\t</script>\n\t</head>\n<body>\n</body></html>"}]
[task 2023-09-26T10:50:55.942Z] 10:50:55     INFO -  1695725455942	Marionette	DEBUG	2 -> [0,36,"Marionette:SetContext",{"value":"content"}]
[task 2023-09-26T10:50:55.942Z] 10:50:55     INFO -  1695725455942	Marionette	DEBUG	2 <- [1,36,null,{"value":null}]
[task 2023-09-26T10:50:56.017Z] 10:50:56     INFO - TEST-UNEXPECTED-FAIL | dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py IDBEncryptionPBM.test_ensure_encrpted_sqlite_data | AssertionError
[task 2023-09-26T10:50:56.017Z] 10:50:56     INFO - Traceback (most recent call last):
[task 2023-09-26T10:50:56.017Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 197, in run
[task 2023-09-26T10:50:56.018Z] 10:50:56     INFO -     testMethod()
[task 2023-09-26T10:50:56.018Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 97, in test_ensure_encrpted_sqlite_data
[task 2023-09-26T10:50:56.019Z] 10:50:56     INFO -     self.ensureInvariantHolds(lambda _: self.sqliteWALReleased())
[task 2023-09-26T10:50:56.019Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 184, in ensureInvariantHolds
[task 2023-09-26T10:50:56.020Z] 10:50:56     INFO -     message=f"operation did not yield success even after waiting {maxWaitTime}s time",
[task 2023-09-26T10:50:56.020Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/venv/lib/python3.7/site-packages/marionette_driver/wait.py", line 131, in until
INFO -     rv = condition(self.marionette)
[task 2023-09-26T10:50:56.021Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 97, in <lambda>
[task 2023-09-26T10:50:56.022Z] 10:50:56     INFO -     self.ensureInvariantHolds(lambda _: self.sqliteWALReleased())
[task 2023-09-26T10:50:56.022Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 175, in sqliteWALReleased
[task 2023-09-26T10:50:56.023Z] 10:50:56     INFO -     if not os.path.exists(self.getIDBStoragePath()):
[task 2023-09-26T10:50:56.023Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 117, in getIDBStoragePath
[task 2023-09-26T10:50:56.024Z] 10:50:56     INFO -     self.marionette.absolute_url("")[:-1] + "^privateBrowsingId=1"
[task 2023-09-26T10:50:56.024Z] 10:50:56     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/dom/indexedDB/test/marionette/test_IDB_encryption_PBM.py", line 161, in getFullOriginMetadata
[task 2023-09-26T10:50:56.024Z] 10:50:56     INFO -     assert res is not None
[task 2023-09-26T10:50:56.025Z] 10:50:56     INFO - TEST-INFO took 1800ms
[task 2023-09-26T10:50:56.026Z] 10:50:56     INFO -  1695725455945	Marionette	DEBUG	2 -> [0,37,"WebDriver:SetTimeouts",{"script":30000}]
[task 2023-09-26T10:50:56.026Z] 10:50:56     INFO -  1695725455945	Marionette	DEBUG	2 <- [1,37,null,{"value":null}]
[task 2023-09-26T10:50:56.027Z] 10:50:56     INFO -  1695725455946	Marionette	DEBUG	2 -> [0,38,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2023-09-26T10:50:56.027Z] 10:50:56     INFO -  1695725455946	Marionette	DEBUG	2 <- [1,38,null,{"value":null}]
[task 2023-09-26T10:50:56.028Z] 10:50:56     INFO -  1695725455947	Marionette	DEBUG	2 -> [0,39,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2023-09-26T10:50:56.029Z] 10:50:56     INFO -  1695725455947	Marionette	DEBUG	2 <- [1,39,null,{"value":null}]
[task 2023-09-26T10:50:56.029Z] 10:50:56     INFO -  1695725455948	Marionette	DEBUG	2 -> [0,40,"Marionette:GetContext",{}]
[task 2023-09-26T10:50:56.030Z] 10:50:56     INFO -  1695725455948	Marionette	DEBUG	2 <- [1,40,null,{"value":"content"}]
[task 2023-09-26T10:50:56.030Z] 10:50:56     INFO -  1695725455949	Marionette	DEBUG	2 -> [0,41,"Marionette:SetContext",{"value":"chrome"}]
[task 2023-09-26T10:50:56.031Z] 10:50:56     INFO -  1695725455949	Marionette	DEBUG	2 <- [1,41,null,{"value":null}]
[task 2023-09-26T10:50:56.032Z] 10:50:56     INFO -  1695725455950	Marionette	DEBUG	2 -> [0,42,"WebDriver:ExecuteScript",{"script":"const { Preferences } = ChromeUtils.importESModule(\n                  \"resource://gre/modules/Preferences.sys.mjs\"\n           ... guments[2];\n\n                prefs = new Preferences({defaultBranch: defaultBranch});\n                prefs.set(pref, value);","args":["dom.indexedDB.privateBrowsing.enabled",true,false],"newSandbox":true,"sandbox":"default","line":903,"filename":"../../venv/lib/python3.7/site-packages/marionette_driver/marionette.py"}]
[task 2023-09-26T10:50:56.032Z] 10:50:56     INFO -  1695725455954	Marionette	DEBUG	2 <- [1,42,null,{"value":null}]
<...>
Duplicate of this bug: 1831652
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago7 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.