1582860 - Intermittent GECKO(3368) | Assertion failure: false (MOZ_ASSERT_UNREACHABLE: Trying to get a result node for an invalid visit), at z:/build/build/src/toolkit/components/places/nsNavHistory.cpp:3190

Status: RESOLVED FIXED

(Toolkit :: Places, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2019-09-20T16:28:28.409Z] 16:28:28 INFO - TEST-START | browser/base/content/test/general/browser_contentAltClick.js
[task 2019-09-20T16:28:28.419Z] 16:28:28 INFO - GECKO(3368) | ++DOCSHELL 000001EF02D84800 == 4 [pid = 10576] [id = {eaab1c5b-5f26-42a0-8619-e47afd083b60}]
[task 2019-09-20T16:28:28.419Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 13 (000001EF03734D40) [pid = 10576] [serial = 162] [outer = 0000000000000000]
[task 2019-09-20T16:28:28.419Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 14 (000001EF0210B000) [pid = 10576] [serial = 163] [outer = 000001EF03734D40]
[task 2019-09-20T16:28:28.449Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 15 (000001EF02FBAC00) [pid = 10576] [serial = 164] [outer = 000001EF03734D40]
[task 2019-09-20T16:28:28.877Z] 16:28:28 INFO - GECKO(3368) | [Parent 10772, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x1aa767acd90 (http://mzl.la/1FuID0j).: file z:/build/build/src/storage/mozStoragePrivateHelpers.cpp, line 108
[task 2019-09-20T16:28:28.917Z] 16:28:28 INFO - GECKO(3368) | ++DOCSHELL 000002081065A800 == 3 [pid = 5224] [id = {f1e306bf-342b-4d29-a04e-8d3dc147f393}]
[task 2019-09-20T16:28:28.917Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 11 (0000020810612B60) [pid = 5224] [serial = 171] [outer = 0000000000000000]
[task 2019-09-20T16:28:28.917Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 12 (0000020816374000) [pid = 5224] [serial = 172] [outer = 0000020810612B60]
[task 2019-09-20T16:28:28.943Z] 16:28:28 INFO - GECKO(3368) | ++DOMWINDOW == 13 (00000208167A9000) [pid = 5224] [serial = 173] [outer = 0000020810612B60]
[task 2019-09-20T16:28:29.146Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 14 (000001EF021AF400) [pid = 10576] [serial = 145] [outer = 0000000000000000] [url = about:privatebrowsing]
[task 2019-09-20T16:28:29.146Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 13 (000001EF02FB7000) [pid = 10576] [serial = 152] [outer = 0000000000000000] [url = http://127.0.0.1:8888/browser/browser/base/content/test/general/test_bug839103.html]
[task 2019-09-20T16:28:29.146Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 12 (000001EF021B2800) [pid = 10576] [serial = 148] [outer = 0000000000000000] [url = http://mochi.test:8888/browser/]
[task 2019-09-20T16:28:29.146Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 11 (000001EF0184C800) [pid = 10576] [serial = 154] [outer = 0000000000000000] [url = about:blank]
[task 2019-09-20T16:28:29.146Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 000001EF02D84800 == 3 [pid = 10576] [id = {eaab1c5b-5f26-42a0-8619-e47afd083b60}] [url = data:text/html,<p><a id="commonlink" href="http://mochi.test/moz/">Common link</a></p><p><math id="mathxlink" xmlns="http://www.w3.org/1998/Math/MathML" xlink:type="simple" xlink:href="http://mochi.test/moz/"><mtext>MathML XLink</mtext></math></p><p><svg id="svgxlink" xmlns="http://www.w3.org/2000/svg" width="100px" height="50px" version="1.1"><a xlink:type="simple" xlink:href="http://mochi.test/moz/"><text transform="translate(10, 25)">SVG XLink</text></a></svg></p><br><span id="host"></span><script>document.getElementById("host").attachShadow({mode: "closed"}).appendChild(document.getElementById("commonlink").cloneNode(true));</script>]
[task 2019-09-20T16:28:29.148Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 000001EF0182B800 == 2 [pid = 10576] [id = {623a9b25-bc51-4502-8897-40f9d7d8cdde}] [url = http://mochi.test:8888/browser/browser/base/content/test/general/browser_bug970746.xhtml]
[task 2019-09-20T16:28:29.153Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 000001EF02D7F000 == 1 [pid = 10576] [id = {71b5aebf-b6b4-420f-ba11-cce66fbdc272}] [url = data:text/html,%3Cbody%20style%3D%27margin%3A%200%27%3E%20%20%3Cimg%20id%3D%27img%27%20tabindex%3D%271%27%20src%3D%27http%3A//example.org/browser/browser/base/content/test/general/moz.png%27%3E%20%20%3Cdiv%20id%3D%27main%27%20contenteditable%3D%27true%27%3ETest%20%3Cb%3EBold%3C/b%3E%20After%20Text%3C/div%3E%3C/body%3E]
[task 2019-09-20T16:28:29.286Z] 16:28:29 INFO - GECKO(3368) | [Parent 10772, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x1aa767acd90 (http://mzl.la/1FuID0j).: file z:/build/build/src/storage/mozStoragePrivateHelpers.cpp, line 108
[task 2019-09-20T16:28:29.324Z] 16:28:29 INFO - GECKO(3368) | ++DOCSHELL 000001EF0182C800 == 2 [pid = 10576] [id = {8b89b8e9-b89b-42b2-a3aa-e5c7f002136f}]
[task 2019-09-20T16:28:29.324Z] 16:28:29 INFO - GECKO(3368) | ++DOMWINDOW == 12 (000001EF03735100) [pid = 10576] [serial = 165] [outer = 0000000000000000]
[task 2019-09-20T16:28:29.324Z] 16:28:29 INFO - GECKO(3368) | ++DOMWINDOW == 13 (000001EF01848000) [pid = 10576] [serial = 166] [outer = 000001EF03735100]
[task 2019-09-20T16:28:29.367Z] 16:28:29 INFO - GECKO(3368) | ++DOMWINDOW == 14 (000001EF021B8400) [pid = 10576] [serial = 167] [outer = 000001EF03735100]
[task 2019-09-20T16:28:29.580Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 12 (00000208106BA800) [pid = 5224] [serial = 161] [outer = 0000000000000000] [url = about:blank]
[task 2019-09-20T16:28:29.580Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 11 (00000208167A9400) [pid = 5224] [serial = 159] [outer = 0000000000000000] [url = about:privatebrowsing]
[task 2019-09-20T16:28:29.580Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 10 (00000208106AB400) [pid = 5224] [serial = 165] [outer = 0000000000000000] [url = about:blank]
[task 2019-09-20T16:28:29.580Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 9 (0000020816373C00) [pid = 5224] [serial = 163] [outer = 0000000000000000] [url = about:blank]
[task 2019-09-20T16:28:29.580Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 000002081065A800 == 2 [pid = 5224] [id = {f1e306bf-342b-4d29-a04e-8d3dc147f393}] [url = data:text/html,<p><a id="commonlink" href="http://mochi.test/moz/">Common link</a></p><p><math id="mathxlink" xmlns="http://www.w3.org/1998/Math/MathML" xlink:type="simple" xlink:href="http://mochi.test/moz/"><mtext>MathML XLink</mtext></math></p><p><svg id="svgxlink" xmlns="http://www.w3.org/2000/svg" width="100px" height="50px" version="1.1"><a xlink:type="simple" xlink:href="http://mochi.test/moz/"><text transform="translate(10, 25)">SVG XLink</text></a></svg></p><br><span id="host"></span><script>document.getElementById("host").attachShadow({mode: "closed"}).appendChild(document.getElementById("commonlink").cloneNode(true));</script>]
[task 2019-09-20T16:28:29.581Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 0000020810646800 == 1 [pid = 5224] [id = {300a63d8-3b6b-44d7-9bab-d5de29c1a5d1}] [url = about:blank]
[task 2019-09-20T16:28:29.668Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 8 (0000020810612200) [pid = 5224] [serial = 164] [outer = 0000000000000000] [url = about:newtab]
[task 2019-09-20T16:28:29.668Z] 16:28:29 INFO - GECKO(3368) | --DOCSHELL 0000020810652000 == 0 [pid = 5224] [id = {2a120928-ce76-4e19-811c-64fb53db2051}] [url = about:newtab]
[task 2019-09-20T16:28:29.668Z] 16:28:29 INFO - GECKO(3368) | --DOMWINDOW == 7 (000002081C7886A0) [pid = 5224] [serial = 167] [outer = 0000000000000000] [url = about:blank]
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO - GECKO(3368) | Assertion failure: false (MOZ_ASSERT_UNREACHABLE: Trying to get a result node for an invalid visit), at z:/build/build/src/toolkit/components/places/nsNavHistory.cpp:3190
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO - GECKO(3368) | #01: nsNavHistoryResult::OnVisit(nsIURI *,__int64,__int64,unsigned int,nsTSubstring<char> const &,bool,unsigned int,nsTSubstring<char16_t> const &) [toolkit/components/places/nsNavHistoryResult.cpp:3997]
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO - GECKO(3368) | #02: nsNavHistoryResult::HandlePlacesEvent(mozilla::dom::Sequence<mozilla::OwningNonNull<mozilla::dom::PlacesEvent> > const &) [toolkit/components/places/nsNavHistoryResult.cpp:4086]
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO - GECKO(3368) | #03: mozilla::dom::CallListeners<mozilla::WeakPtr<mozilla::places::INativePlacesEventCallback>,RefPtr<mozilla::places::INativePlacesEventCallback> >(unsigned int,nsTArray<mozilla::dom::Flagged<mozilla::WeakPtr<mozilla::places::INativePlacesEventCallback> > > &,mozilla::dom::Sequence<mozilla::OwningNonNull<mozilla::dom::PlacesEvent> > const &,std::function<RefPtr<mozilla::places::INativePlacesEventCallback> > const &,std::function<void > const &) [dom/base/PlacesObservers.cpp:110]
[task 2019-09-20T16:28:29.849Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #04: mozilla::dom::PlacesObservers::NotifyListeners(mozilla::dom::Sequence<mozilla::OwningNonNull<mozilla::dom::PlacesEvent> > const &) [dom/base/PlacesObservers.cpp:293]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #05: nsresult mozilla::places::`anonymous namespace'::NotifyManyVisitsObservers::Run() [toolkit/components/places/History.cpp:610]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #06: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1225]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #07: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:486]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #08: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:88]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO - GECKO(3368) | #09: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:309]
[task 2019-09-20T16:28:29.850Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #10: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #11: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:139]
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #12: nsAppShell::Run() [widget/windows/nsAppShell.cpp:406]
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #13: nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:277]
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #14: XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:4601]
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.851Z] 16:28:29 INFO - GECKO(3368) | #15: XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:4736]
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #16: XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:4817]
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #17: NS_internal_main(int,char * *,char * *) [browser/app/nsBrowserApp.cpp:300]
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #18: wmain [toolkit/xre/nsWindowsWMain.cpp:131]
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #19: static int __scrt_common_main_seh() [f:/dd/vctools/crt/vcstartup/src/startup/exe_common.inl:288]
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #20: KERNEL32.DLL + 0x13034
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO - GECKO(3368) | #21: ntdll.dll + 0x71461
[task 2019-09-20T16:28:29.852Z] 16:28:29 INFO -
[task 2019-09-20T16:28:30.177Z] 16:28:30 INFO - GECKO(3368) | Exiting due to channel error.
[task 2019-09-20T16:28:30.177Z] 16:28:30 INFO - GECKO(3368) | Exiting due to channel error.
[task 2019-09-20T16:28:30.177Z] 16:28:30 INFO - GECKO(3368) | [GPU 4708, Main Thread] WARNING: Shutting down GPU process early due to a crash!: file z:/build/build/src/gfx/ipc/GPUParent.cpp, line 494
[task 2019-09-20T16:28:30.178Z] 16:28:30 INFO - GECKO(3368) | Exiting due to channel error.
[task 2019-09-20T16:28:30.309Z] 16:28:30 INFO - TEST-INFO | Main app process: exit 1
[task 2019-09-20T16:28:30.309Z] 16:28:30 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2019-09-20T16:28:30.310Z] 16:28:30 INFO - Buffered messages logged at 16:28:28
[task 2019-09-20T16:28:30.310Z] 16:28:30 INFO - Entering test bound test_alt_click
[task 2019-09-20T16:28:30.311Z] 16:28:30 INFO - Console message: [JavaScript Warning: "‘xlink:href’ is deprecated in MathML 3, superseded by ‘href’." {file: "data:text/html,<p><a id="commonlink" href="http://mochi.test/moz/">Common link</a></p><p><math id="mathxlink" xmlns="http://www.w3.org/1998/Math/MathML" xlink:type="simple" xlink:href="http://mochi.test/moz/"><mtext>MathML XLink</mtext></math></p><p><svg id="svgxlink" xmlns="http://www.w3.org/2000/svg" width="100px" height="50px" version="1.1"><a xlink:type="simple" xlink:href="http://mochi.test/moz/"><text transform="translate(10, 25)">SVG XLink</text></a></svg></p><br><span id="host"></span><script>docume" line: 0}]
[task 2019-09-20T16:28:30.311Z] 16:28:30 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html,<p><a id="commonlink" href="http://mochi.test/moz/">Common link</a></p><p><math id="mathxlink" xmlns="http://www.w3.org/1998/Math/MathML" xlink:type="simple" xlink:href="http://mochi.test/moz/"><mtext>MathML XLink</mtext></math></p><p><svg id="svgxlink" xmlns="http://www.w3.org/2000/svg" width="100px" height="50px" version="1.1"><a xlink:type="simple" xlink:href="http://mochi.test/moz/"><text transform="translate(10, 25)">SVG XLink</text></a></svg></p><br><span id="host"></span><script>docume" line: 0}]
[task 2019-09-20T16:28:30.312Z] 16:28:30 INFO - TEST-PASS | browser/base/content/test/general/browser_contentAltClick.js | 1 downloads -

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

Bugbug thinks this bug should belong to this component, but please revert this change in case of error.

Comment 2

[Intermittent Failures Robot]

1 failures in 4350 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2019-09-16&endday=2019-09-22&tree=all

Comment 3

[Intermittent Failures Robot]

2 failures in 4292 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• windows10-64-qr: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2019-09-30&endday=2019-10-06&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures in 3801 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2019-10-07&endday=2019-10-13&tree=all

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 6

[Cosmin Sabou [:CosminS]]

https://treeherder.mozilla.org/logviewer.html#?job_id=315857212&repo=mozilla-central

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2
• autoland: 13

Platform breakdown:

• macosx1014-64: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-09-14&endday=2020-09-20&tree=all

Comment 8

[Intermittent Failures Robot]

17 failures in 4019 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 13
• mozilla-central: 4

Platform breakdown:

• macosx1014-64: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-09-21&endday=2020-09-27&tree=all

Comment 9

[Intermittent Failures Robot]

23 failures in 4195 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 20
• mozilla-central: 3

Platform breakdown:

• macosx1014-64: 23

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-09-28&endday=2020-10-04&tree=all

Comment 10

[Intermittent Failures Robot]

20 failures in 4130 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7
• autoland: 12
• try: 1

Platform breakdown:

• macosx1014-64: 19
• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-10-05&endday=2020-10-11&tree=all

Comment 11

[Intermittent Failures Robot]

23 failures in 3694 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15
• mozilla-central: 8

Platform breakdown:

• macosx1014-64: 23

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-10-12&endday=2020-10-18&tree=all

Comment 12

[Intermittent Failures Robot]

27 failures in 4230 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

This is the #48 most frequent failure this week.

Repository breakdown:

• autoland: 21
• mozilla-central: 5
• try: 1

Platform breakdown:

• macosx1014-64: 26
• linux1804-64: 1

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

Comment 13

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

Marco, can you look at this (~30 failures/week)?

Comment 14

[Intermittent Failures Robot]

31 failures in 4275 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

This is the #41 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 23
• mozilla-central: 6
• try: 2

Platform breakdown:

• macosx1014-64: 27
• linux1804-64: 3
• macosx1014-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-10-26&endday=2020-11-01&tree=all

Comment 15

[Marco Bonardo [:mak]]

What happens here is that we receive a page-visited notification, this notification is supposed to contain a visitId, that is the id of the visit that was inserted in moz_historyvisits a small time before the notification. We query moz_historyvisits for that id, and we should find it, but we don't get any result, so apparently the assertion looks correct, how can we not find something we just inserted?

How could this happen?

1. We may be storing the id in one database connection, and retrieving on another one. This is not the case, we're always on the main Places database connection.

2. We may notify the visit without having inserted it in the table. The notification comes from NotifyManyVisitsObservers, that is only used in History.cpp. If the visit is an EMBED transition, we don't insert in the db, but we notify. Though the AddPlaceForNotify() method skips EMBED visits explicitly, so it should not be our culprit. The other 2 notifications come after DoDatabaseInserts() that internally invokes AddVisit(), that is updating the visitId through a Sqlite trigger. There is an ASSERT(visitId > 0) here, so if we'd pass there with an invalid value, we'd assert sooner. I'd also expect to see warnings in the log related to history, if something there failed, since (luckily) it still uses NS_ENSURE_SUCCESS.
   In the end after some deep code inspection I couldn't find a problem here.

3. There may be a thread race. Most of the inserts happen in the async thread, the notification happens on the main-thread, but when we notify all the async work should have been done (it is the async thread dispatching to the main thread once done). The sLastInsertedVisitId integer is atomic, so it should not contain trash data. It is read immediately after the insert and there's an ASSERT that doesn't fail there. The trigger should be run by Sqlite before considering the UPDATE complete. I'd expect that In the worst case the visitId may be a different one, but still a valid one.

4. Something may have removed the visit just after we inserted it, but before we notified it. In dom/serviceworkers/test I couldn't find any explicit call to the history API, but there is a clearData ALL call in test_third_party_iframes.html... Hey, this is actually one of the failing tests!
   Another one is browser_contentAltClick.js, that is also adding and removing visits.

The fact this happens on Linux/Mac but not on Windows makes me think to the different characteristics of the thread schedulers, so either a race condition, or the visit removal on the async thread is just being served before the notification and the I/O on the main-thread by the history result.

Summing up, I couldn't find obvious misuses of the notification, or of the code that retrieves and stores the visitId, as well as I couldn't find evidence of other failures, in the shape of warnings, in History.cpp or nsNavHistory.cpp, that could have polluted the expected results.
On the other side, it's totally possible that between the time we insert the visit and the time we notify it, something can execute an async query removing the visit, or emptying history.
The condition that this assert is protecting is one of the possibly expected outcomes, it's not an impossible condition, thus this assertion should not be here.

Comment 16

[Marco Bonardo [:mak]]

Attachment: Bug 1582860 - Convert bogus fatal assertions about missing Places ids into warnings. r=Standard8

These assertions were intended to protect us from trying to build a result
node from a non existing database id. In practice it is totally possible that
between the time an entry is added and the time it is notified, something else
executes a removal of the same entry.
The assertions are thus converted into warnings, so that we can still notice
them when running manual tests, but they won't cause test failures, since it's
a condition that can happen during test runs, but not a bug.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f7bf357cf2bd
Convert bogus fatal assertions about missing Places ids into warnings. r=Standard8

Comment 18

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/f7bf357cf2bd

Comment 19

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 8
• mozilla-central: 4
• try: 2

Platform breakdown:

• macosx1014-64: 8
• linux1804-64: 3
• macosx1014-64-qr: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1582860&startday=2020-11-02&endday=2020-11-08&tree=all