Closed Bug 1620630 Opened 5 years ago Closed 5 years ago

The OS.File worker should record markers indicating which operation it is performing on which file

Categories

(Toolkit Graveyard :: OS.File, enhancement)

enhancement
Not set
normal

Tracking

(firefox76 fixed)

RESOLVED FIXED
mozilla76
Tracking Status
firefox76 --- fixed

People

(Reporter: florian, Assigned: florian)

Details

Attachments

(1 file)

This would be useful to understand what's happening in the OS File worker and detect wasteful activity using the profiler. Here's an example profile with the proposed markers captured on the slow 2018 reference laptop: https://perfht.ml/2PSvXeh

Pushed by fqueze@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/c1b10a848d64 The OS.File worker should record markers indicating which operation it is performing on which file, r=Yoric.

The log of the failed test says:
Unexpected exception TypeError: can't access property "string", args[0] is null at resource://gre/modules/osfile/osfile_async_worker.js:38
worker.dispatch@resource://gre/modules/osfile/osfile_async_worker.js:38:11
handleMessage@resource://gre/modules/workers/PromiseWorker.js:129:21

In the case that failed during the test, method is "exists" and args is [null].

(In reply to Florian Quèze [:florian] from comment #6)

downloader.baseFolder is undefined at https://searchfox.org/mozilla-central/rev/070a000dd49aac4a26147e137efcd91a728d13b8/services/settings/test/unit/test_attachments_downloader.js#195

Is this expected, or pointing to a bug in this test or the code it is testing?

Flags: needinfo?(mathieu)

Is this expected, or pointing to a bug in this test or the code it is testing?

Oh this is clearly an error! The downloader instance has no baseFolder attribute!

Note: This test asserts that parent folders are deleted when the last file is deleted.
https://searchfox.org/mozilla-central/rev/070a000dd49aac4a26147e137efcd91a728d13b8/services/settings/Attachments.jsm#160-161

Flags: needinfo?(mathieu)

I updated the patch with a test fix provided by Mathieu.

Flags: needinfo?(florian)
Pushed by fqueze@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/6aaa835ae0eb The OS.File worker should record markers indicating which operation it is performing on which file, r=Yoric.
Backout by dvarga@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2177e8ac584c Backed out changeset 6aaa835ae0eb for causing xpcshell failures at osfile/tests/xpcshell/test_osfile_closed.js

Backed out changeset 6aaa835ae0eb (Bug 1620630) for causing xpcshell failures at osfile/tests/xpcshell/test_osfile_closed.js

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=autoland&collapsedPushes=659858&selectedJob=292525359&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=6aaa835ae0eb2f4d7b0d89d243f702df2143c690

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=292520407&repo=autoland&lineNumber=2738

Backout link: https://treeherder.mozilla.org/#/jobs?repo=autoland&collapsedPushes=659858&selectedJob=292525359&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=ba409a89fb2bceefbd93f25c32d759cfc1aea9d7

[task 2020-03-10T18:24:08.481Z] 18:24:08     INFO -  TEST-START | services/sync/tests/unit/test_clients_engine.js
[task 2020-03-10T18:24:17.258Z] 18:24:17     INFO -  TEST-PASS | services/sync/tests/unit/test_clients_engine.js | took 8781ms
[task 2020-03-10T18:24:17.261Z] 18:24:17     INFO -  Retrying tests that failed when run in parallel.
[task 2020-03-10T18:24:17.270Z] 18:24:17     INFO -  TEST-START | browser/components/tests/unit/test_distribution.js
[task 2020-03-10T18:24:20.770Z] 18:24:20     INFO -  TEST-PASS | browser/components/tests/unit/test_distribution.js | took 3501ms
[task 2020-03-10T18:24:20.777Z] 18:24:20     INFO -  TEST-START | toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js
[task 2020-03-10T18:24:21.137Z] 18:24:21  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js | xpcshell return code: 0
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  TEST-INFO took 357ms
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  >>>>>>>
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | [18781, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/checkouts/gecko/toolkit/crashreporter/nsExceptionHandler.cpp, line 2930
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test pending (2)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (3)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test MAIN run_test finished (3)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  running event loop
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | [18781, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp, line 363
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  "CONSOLE_MESSAGE: (info) No chrome package registered for chrome://branding/locale/brand.properties"
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js | Starting test_closed
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test test_closed pending (3)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (3)
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | OS Controller Posting message {"fun":"getCurrentDirectory","id":1}
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | [18781, Main Thread] WARNING: Workers don't support the 'mem.mem.' preference!: file /builds/worker/checkouts/gecko/dom/workers/RuntimeService.cpp, line 535
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | [18781, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file /builds/worker/checkouts/gecko/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 658
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | OS Controller Message posted
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | OS Controller Expecting reply
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | OS Controller Posting message {"fun":"SET_DEBUG","args":[true],"id":2}
[task 2020-03-10T18:24:21.137Z] 18:24:21     INFO -  PID 18781 | OS Controller Message posted
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Controller Expecting reply
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Agent Method SET_DEBUG succeeded
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Agent Sending positive reply  id is 2
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Controller Received message from worker {"ok":{"string":"/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/osfile/tests/xpcshell"},"id":1,"timeStamps":{"entered":1583864660967,"loaded":1583864661004}}
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  "Open a file, ensure that we can call stat()"
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Controller Posting message {"fun":"open","args":[{"string":"/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js"},null,null],"id":3}
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Agent Received message {"fun":"open","args":[{"string":"/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/osfile/tests/xpcshell/test_osfile_closed.js"},null,null],"id":3}
[task 2020-03-10T18:24:21.143Z] 18:24:21     INFO -  PID 18781 | OS Agent Calling method open
Flags: needinfo?(florian)
Flags: needinfo?(florian)
Pushed by fqueze@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/db04841c16dc The OS.File worker should record markers indicating which operation it is performing on which file, r=Yoric.
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla76
Product: Toolkit → Toolkit Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: