Intermittent Assertion failure: thisDB->mCommonMetadata.version() == otherDB->mCommonMetadata.version(), at /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp:22580
Categories
(Core :: Storage: IndexedDB, defect, P5)
Tracking
()
People
(Reporter: intermittent-bug-filer, Assigned: CosminS)
References
Details
(Keywords: intermittent-failure)
Attachments
(2 files)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 8•6 years ago
|
||
Nowadays this seems to be more a ccov build issue.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 18•6 years ago
|
||
Over the last 7 days there are 38 failures present on this bug. These happen on linux64, linux32 and linux64-ccov.
Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=240904982&repo=autoland&lineNumber=39434
[task 2019-04-17T11:09:33.170Z] 11:09:33 INFO - [Parent 5006, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 400
[task 2019-04-17T11:09:33.178Z] 11:09:33 INFO - 1555499373173 Marionette DEBUG Accepted connection 1 from 127.0.0.1:59962
[task 2019-04-17T11:09:33.182Z] 11:09:33 INFO - 1555499373180 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-04-17T11:09:33.192Z] 11:09:33 INFO - [Parent 5006, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 400
[task 2019-04-17T11:09:33.212Z] 11:09:33 INFO - [Parent 5006, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 400
[task 2019-04-17T11:09:33.228Z] 11:09:33 INFO - [Parent 5006, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 400
[task 2019-04-17T11:09:33.237Z] 11:09:33 INFO - [Parent 5006, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 400
[task 2019-04-17T11:09:33.414Z] 11:09:33 INFO - 1555499373405 Marionette TRACE [4294967297] Frame script loaded
[task 2019-04-17T11:09:33.418Z] 11:09:33 INFO - 1555499373414 Marionette TRACE [4294967297] Frame script registered
[task 2019-04-17T11:09:33.454Z] 11:09:33 INFO - 1555499373448 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"61dcdb28-17c5-418f-a201-2da5fae2433a","capabilities":{"browserName":"firefox","browserVersion":"68.0a ... 8hJ3.tmpdrjO0Uexternal","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-04-17T11:09:33.482Z] 11:09:33 INFO - 1555499373478 Marionette DEBUG 1 -> [0,2,"WebDriver:DeleteSession",{}]
[task 2019-04-17T11:09:33.490Z] 11:09:33 INFO - 1555499373487 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2019-04-17T11:09:33.494Z] 11:09:33 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestSwitchProfileWithWorkspace.test_clone_existing_profile | took 11337ms
[task 2019-04-17T11:09:33.495Z] 11:09:33 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestSwitchProfileWithWorkspace.test_new_named_profile
[task 2019-04-17T11:09:33.503Z] 11:09:33 INFO - 1555499373496 Marionette DEBUG Closed connection 1
[task 2019-04-17T11:09:33.504Z] 11:09:33 INFO - 1555499373501 Marionette DEBUG Accepted connection 2 from 127.0.0.1:59964
[task 2019-04-17T11:09:33.512Z] 11:09:33 INFO - 1555499373510 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-04-17T11:09:33.520Z] 11:09:33 INFO - Assertion failure: thisDB->mCommonMetadata.version() == otherDB->mCommonMetadata.version(), at /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp:20913
[task 2019-04-17T11:09:33.520Z] 11:09:33 INFO - #01: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2d339c2]
[task 2019-04-17T11:09:33.520Z] 11:09:33 INFO - #02: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2d24c5d]
[task 2019-04-17T11:09:33.520Z] 11:09:33 INFO - #03: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2d20cd2]
[task 2019-04-17T11:09:33.522Z] 11:09:33 INFO - #04: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6eead2]
[task 2019-04-17T11:09:33.522Z] 11:09:33 INFO - #05: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6f1370]
[task 2019-04-17T11:09:33.523Z] 11:09:33 INFO - #06: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc61410]
[task 2019-04-17T11:09:33.523Z] 11:09:33 INFO - #07: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc19715]
[task 2019-04-17T11:09:33.533Z] 11:09:33 INFO - #08: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc19672]
[task 2019-04-17T11:09:33.534Z] 11:09:33 INFO - #09: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6ec2ed]
[task 2019-04-17T11:09:33.534Z] 11:09:33 INFO - #10: ???[/builds/worker/workspace/build/application/firefox/libnspr4.so +0x292b9]
[task 2019-04-17T11:09:33.535Z] 11:09:33 INFO - #11: ???[/lib/i386-linux-gnu/libpthread.so.0 +0x6295]
[task 2019-04-17T11:09:33.535Z] 11:09:33 INFO - 1555499373527 Marionette TRACE [4294967297] Frame script loaded
[task 2019-04-17T11:09:33.539Z] 11:09:33 INFO - ExceptionHandler::GenerateDump cloned child 5136
[task 2019-04-17T11:09:33.539Z] 11:09:33 INFO - ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-04-17T11:09:33.540Z] 11:09:33 INFO - ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-04-17T11:09:33.556Z] 11:09:33 INFO - 1555499373546 Marionette TRACE [4294967297] Frame script registered
[task 2019-04-17T11:09:33.575Z] 11:09:33 INFO - [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-04-17T11:09:33.578Z] 11:09:33 INFO - [Child 5113, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-04-17T11:09:33.578Z] 11:09:33 INFO - Exiting due to channel error.
[task 2019-04-17T11:09:33.578Z] 11:09:33 INFO - Exiting due to channel error.
[task 2019-04-17T11:09:33.579Z] 11:09:33 INFO - Exiting due to channel error.
[task 2019-04-17T11:09:33.601Z] 11:09:33 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestSwitchProfileWithWorkspace.test_new_named_profile | IOError: Process has been unexpectedly closed (Exit code: 11) (Reason: No data received over socket)
[task 2019-04-17T11:09:33.601Z] 11:09:33 INFO - Traceback (most recent call last):
[task 2019-04-17T11:09:33.602Z] 11:09:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 140, in run
[task 2019-04-17T11:09:33.603Z] 11:09:33 INFO - self.setUp()
[task 2019-04-17T11:09:33.604Z] 11:09:33 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py", line 227, in setUp
[task 2019-04-17T11:09:33.605Z] 11:09:33 INFO - super(TestSwitchProfileWithWorkspace, self).setUp()
[task 2019-04-17T11:09:33.606Z] 11:09:33 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py", line 63, in setUp
[task 2019-04-17T11:09:33.606Z] 11:09:33 INFO - super(ExternalProfileMixin, self).setUp()
[task 2019-04-17T11:09:33.608Z] 11:09:33 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py", line 45, in setUp
Comment 19•6 years ago
|
||
Is this actionable, Jan?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 22•6 years ago
|
||
This has 67 failures in the last 7 days, on linux32,64 and osx all debug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-04-17&endday=2019-04-24&tree=trunk&bug=1450355
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=242229930&repo=autoland
It's now on the disable recommended bugs as it had 150+ failures in the last 30 days. Jan, is there something you could do here? Thanks.
Comment 23•6 years ago
|
||
Maybe Tom can investigate this.
Comment 24•6 years ago
|
||
Sure, I also hit this when pushing a patch to try [1].
Not really sure if it's related at this moment, but I also saw:
[task 2019-04-24T07:39:29.436Z] 07:39:29 INFO - [Parent 6262, IPDL Background] WARNING: NextVersionChangeTransactionSerialNumber doesn't match!: 'aLoggingInfo.nextVersionChangeTransactionSerialNumber() == loggingInfo->mLoggingInfo .nextVersionChangeTransactionSerialNumber()', file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 12135
[task 2019-04-24T07:41:36.456Z] 07:41:36 INFO - [Parent 7635, IPDL Background] WARNING: NextVersionChangeTransactionSerialNumber doesn't match!: 'aLoggingInfo.nextVersionChangeTransactionSerialNumber() == loggingInfo->mLoggingInfo .nextVersionChangeTransactionSerialNumber()', file /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp, line 12135
Comment hidden (Intermittent Failures Robot) |
Comment 26•6 years ago
|
||
I saw something strange:
So, I added a patch for logging the version of the metadata
[task 2019-04-25T08:21:21.339Z] 08:21:21 INFO - [TT] InitiateRequest op requestedVersion:1
[task 2019-04-25T08:21:21.339Z] 08:21:21 INFO - [TT] 0x7f0522783f70 Factory::AllocPBackgroundIDBFactoryRequestParent version:1
[task 2019-04-25T08:21:21.339Z] 08:21:21 INFO - [TT] FullIndexMetadata ctor :1
[task 2019-04-25T08:21:21.340Z] 08:21:21 INFO - [TT] OpenDatabaseOp ctor 0x7f05221e3c00 metadata version:1 param version:1
[task 2019-04-25T08:21:21.340Z] 08:21:21 INFO - 1556180481330 Marionette DEBUG Closed connection 1
[task 2019-04-25T08:21:21.340Z] 08:21:21 INFO - 1556180481334 Marionette DEBUG Accepted connection 2 from 127.0.0.1:60328
[task 2019-04-25T08:21:21.357Z] 08:21:21 INFO - 1556180481346 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-04-25T08:21:21.359Z] 08:21:21 INFO - [TT] 0x7f05221e3c00 OpenDatabaseOp::AssertMetadataConsistency this v:0, other v:1 1
In this case, the version for the metadata held by OpenDatabaseOp is changed between the Operation is constructing and AssertMetadataConsistency. I wonder if the metadata is swapped or modified.
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=242519512&repo=try&lineNumber=38652
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 32•6 years ago
|
||
https://taskcluster-artifacts.net/ZBTwhOMeTx2kb8ASnrydrw/0/public/logs/live_backing.log
It seems it's because something was removed between subtests. The sequence is:
Subtest A start
OpenDatabase for some moz-extension in version 0
VersionChange for upgrading from 0 to 1 and writing the version to 1 for the table database
Subtest A end
Subtest B Start
OpenDatabase for some moz-extension in version 1 and expecting the version in the table database should be 1. (It's 0)
Hit the assertion
Generally successful case:
Subtest A start
OpenDatabase for some moz-extension in version 0
VersionChange for upgrading from 0 to 1 and writing the version to 1 for the table database
OpenDatabase for some moz-extension in version 1 and expecting the version in the table database should be 1. (It's 0)
Subtest A end
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 35•6 years ago
|
||
There are 274 failures in the last 7 days.
:ttung , can you please take a look?
Recent log snippet:
[task 2019-05-02T05:39:20.299Z] 05:39:20 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py TestSwitchProfileWithWorkspace.test_new_named_profile
[task 2019-05-02T05:39:20.303Z] 05:39:20 INFO - 1556775560300 Marionette DEBUG Closed connection 1
[task 2019-05-02T05:39:20.321Z] 05:39:20 INFO - 1556775560309 Marionette DEBUG Accepted connection 2 from 127.0.0.1:47040
[task 2019-05-02T05:39:20.322Z] 05:39:20 INFO - Assertion failure: thisDB->mCommonMetadata.version() == otherDB->mCommonMetadata.version(), at /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp:20922
[task 2019-05-02T05:39:20.323Z] 05:39:20 INFO - #01: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2dae088]
[task 2019-05-02T05:39:20.323Z] 05:39:20 INFO - #02: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2d9f32b]
[task 2019-05-02T05:39:20.324Z] 05:39:20 INFO - #03: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x2d9b3a0]
[task 2019-05-02T05:39:20.325Z] 05:39:20 INFO - #04: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6f9572]
[task 2019-05-02T05:39:20.325Z] 05:39:20 INFO - #05: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6fbe10]
[task 2019-05-02T05:39:20.326Z] 05:39:20 INFO - #06: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc71e2c]
[task 2019-05-02T05:39:20.330Z] 05:39:20 INFO - #07: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc29c55]
[task 2019-05-02T05:39:20.331Z] 05:39:20 INFO - #08: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0xc29bb2]
[task 2019-05-02T05:39:20.332Z] 05:39:20 INFO - #09: ???[/builds/worker/workspace/build/application/firefox/libxul.so +0x6f6d8d]
[task 2019-05-02T05:39:20.332Z] 05:39:20 INFO - #10: ???[/builds/worker/workspace/build/application/firefox/libnspr4.so +0x292b9]
[task 2019-05-02T05:39:20.333Z] 05:39:20 INFO - #11: ???[/lib/i386-linux-gnu/libpthread.so.0 +0x6295]
[task 2019-05-02T05:39:20.337Z] 05:39:20 INFO - ExceptionHandler::GenerateDump cloned child ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-05-02T05:39:20.338Z] 05:39:20 INFO - 5257
[task 2019-05-02T05:39:20.338Z] 05:39:20 INFO - ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-05-02T05:39:20.370Z] 05:39:20 INFO - [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-05-02T05:39:20.371Z] 05:39:20 INFO - [Child 5235, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-05-02T05:39:20.373Z] 05:39:20 INFO - Exiting due to channel error.
Comment 36•6 years ago
|
||
I've been looking into this. I believe some of them are generated while I was investigating by logging. (I couldn't reproduce it on my local machine now)
Comment hidden (Intermittent Failures Robot) |
Comment 39•6 years ago
|
||
this is clearly a failure in:
testing/marionette/harness/marionette_harness/tests/unit/test_profile_management.py
found in this manifest:
https://searchfox.org/mozilla-central/source/testing/marionette/harness/marionette_harness/tests/unit/unit-tests.ini#88
can we disable this on osx/linux && debug?
Comment 40•6 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 42•6 years ago
|
||
Assignee | ||
Updated•6 years ago
|
Updated•6 years ago
|
Comment 43•6 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment 56•1 year ago
|
||
Is this still being reproduced?
The last report by Intermittent Failures Robot is about 4 years ago.
Comment 57•11 months ago
|
||
The test is still disabled:
https://searchfox.org/mozilla-central/rev/202c48686136360a23b73a49b611a19e64f3e1b8/testing/marionette/harness/marionette_harness/tests/unit/unit-tests.toml#113-117
Someone should revert the changes as landed here 5 years ago and check if the test is still failing.
Assignee | ||
Comment 58•11 months ago
|
||
Assignee | ||
Updated•11 months ago
|
Comment 59•11 months ago
|
||
Updated•11 months ago
|
Comment 60•11 months ago
|
||
bugherder |
Description
•