Closed Bug 1359167 Opened 6 years ago Closed 6 years ago

Intermittent test_429505_remove_shortcuts.js | xpcshell return code: 0

Categories

(Toolkit :: Places, defect)

Product:
Toolkit
Component:
Places
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla55
Tracking Flags:
Tracking Status
firefox53 --- unaffected
firefox54 --- unaffected
firefox55 --- fixed

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed]) 

36 failures in the last 4 days:
https://brasstacks.mozilla.com/orangefactor/index.html?display=Bug&bugid=1359167&startday=2017-04-21&endday=2017-04-28&tree=trunk

linux32/64 opt/pgo xpcshell-7 primarily.

first instance is:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=93679026&lineNumber=2541

and we see in that log:
[task 2017-04-24T10:10:58.737425Z] 10:10:58     INFO -  TEST-START | toolkit/components/places/tests/unit/test_429505_remove_shortcuts.js
[task 2017-04-24T10:11:00.755213Z] 10:11:00  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/places/tests/unit/test_429505_remove_shortcuts.js | xpcshell return code: 0
[task 2017-04-24T10:11:00.755672Z] 10:11:00     INFO -  TEST-INFO took 2017ms
[task 2017-04-24T10:11:00.761557Z] 10:11:00     INFO -  >>>>>>>
[task 2017-04-24T10:11:00.763706Z] 10:11:00     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2017-04-24T10:11:00.765901Z] 10:11:00     INFO -  NS_ERROR_STORAGE_BUSY: Component returned failure code: 0x80630001 (NS_ERROR_STORAGE_BUSY) [nsINavBookmarksService.createFolder]
[task 2017-04-24T10:11:00.768137Z] 10:11:00     INFO -  run_test@/home/worker/workspace/build/tests/xpcshell/tests/toolkit/components/places/tests/unit/test_429505_remove_shortcuts.js:20:7
[task 2017-04-24T10:11:00.770248Z] 10:11:00     INFO -  _execute_test@/home/worker/workspace/build/tests/xpcshell/head.js:536:7
[task 2017-04-24T10:11:00.772183Z] 10:11:00     INFO -  @-e:1:1
[task 2017-04-24T10:11:00.774136Z] 10:11:00     INFO -  <<<<<<<

:mak, I wanted to get this on your radar, seems to be fairly frequent, I will do some retriggers and see if I can get a % failure and try to find what revision started this.
Flags: needinfo?(mak77)
Whiteboard: [stockwell needswork]
here is my initial work for retriggers (data in a couple hours):
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=xpcshell-7%20linux%20opt%20x64&tochange=7457db3be2751899c296052079dc5e6ebecc284d&fromchange=c3f35f8a1f219f47437f63bb87e9308870a151d9

it looks like we fail on line 20 in the test:
https://dxr.mozilla.org/mozilla-central/source/toolkit/components/places/tests/unit/test_429505_remove_shortcuts.js?q=path%3Atest_429505_remove_shortcuts.js&redirect_type=single#20

which is really creating a folder:
    var folderId =
      PlacesUtils.bookmarks.createFolder(PlacesUtils.toolbarFolderId, "", IDX);


looking in bugzilla, possibly bug 1359607 is related?  I see some discussion there- it would be nice if a single fix could solve this problem.

:mak, can you help determine if this is related to bug 1359607 and if so we can do all our work there- otherwise, any additional info you could provide or request to help get this resolve would be helpful!
(In reply to Joel Maher ( :jmaher) from comment #3)

I think this failure started earlier. My theory is bug 1356220:

https://treeherder.mozilla.org/#/jobs?repo=autoland&filter-searchStr=linux%20xpcshell-7&tochange=4719f83be95240031a6e748eecab2934e8fccae2&fromchange=184dc928df689bea8008becd8fe6ea2058c028e6

There were a few "places" failures that seemed to start around that time - :mak is already looking at some of those, I think.
I'll try to increase the sqlite busy_timeout on Try and see if that helps.

It's likely the problem is related to bug 1356220. It's not exactly a direct relation, the problem is still that Places uses the database on 2 threads (And that will unfortunately continue until we are resourced to finish converting all the APIs to async).
Increasing the journal size has brought nice perf improvements, but looks like it increased the likelyhood that a synchronous request hits a lock from an asynchronous request. This could already happen, but we didn't observe it in tests.

(In reply to Joel Maher ( :jmaher) from comment #2)
> :mak, can you help determine if this is related to bug 1359607 and if so we
> can do all our work there- otherwise, any additional info you could provide
> or request to help get this resolve would be helpful!

Yes, all of these new failures with NS_ERROR_STORAGE_BUSY are the same thing.
Depends on: 1359887
Flags: needinfo?(mak77)
Should have been fixed by bug 1359887
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox53: --- → unaffected
status-firefox54: --- → unaffected
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Whiteboard: [stockwell needswork] → [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.