Closed Bug 1580036 Opened 5 years ago Closed 4 years ago

Intermittent IOError: [Errno 2] No such file or directory: 'c:\\users\\task_1568058584\\appdata\\local\\temp\\xpc-plugins-prdjhq\\gmp-clearkey\\0.1\\clearkey.dll'

Categories

(Testing :: XPCShell Harness, defect, P3)

Product:
Testing
Component:
XPCShell Harness
Type:
defect

Tracking

(firefox-esr68 fixed, firefox71 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla71
Tracking Flags:
Tracking Status
firefox-esr68 --- fixed
firefox71 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Bug 1580036 - Verify that xpcshell plugins directory created; r=
47 bytes, text/x-phabricator-request
Details | Review

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

[task 2019-09-09T22:13:27.855Z] 22:13:27 INFO - TEST-START | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js
[task 2019-09-09T22:13:29.615Z] 22:13:29 INFO - TEST-PASS | toolkit/mozapps/extensions/test/xpcshell/rs-blocklist/test_pluginBlocklistCtp.js | took 1762ms
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - Following exceptions were raised:
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - Traceback (most recent call last):
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 186, in run
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - self.run_test()
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 654, in run_test
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - self.command = self.buildXpcsCmd()
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 488, in buildXpcsCmd
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - self.pluginsDir = self.setupPluginsDir()
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 372, in setupPluginsDir
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - dir_util.copy_tree(self.pluginsPath, pluginsDir)
[task 2019-09-09T22:13:29.642Z] 22:13:29 INFO - File "c:\mozilla-build\python\Lib\distutils\dir_util.py", line 163, in copy_tree
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - verbose=verbose, dry_run=dry_run))
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - File "c:\mozilla-build\python\Lib\distutils\dir_util.py", line 163, in copy_tree
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - verbose=verbose, dry_run=dry_run))
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - File "c:\mozilla-build\python\Lib\distutils\dir_util.py", line 167, in copy_tree
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - dry_run=dry_run)
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - File "c:\mozilla-build\python\Lib\distutils\file_util.py", line 156, in copy_file
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - _copy_file_contents(src, dst)
[task 2019-09-09T22:13:29.643Z] 22:13:29 INFO - File "c:\mozilla-build\python\Lib\distutils\file_util.py", line 44, in _copy_file_contents
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - fdst = open(dst, 'wb')
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - IOError: [Errno 2] No such file or directory: 'c:\users\task_1568058584\appdata\local\temp\xpc-plugins-prdjhq\gmp-clearkey\0.1\clearkey.dll'
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - Traceback (most recent call last):
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 1689, in <module>
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - main()
[task 2019-09-09T22:13:29.644Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 1684, in main
[task 2019-09-09T22:13:29.647Z] 22:13:29 INFO - if not xpcsh.runTests(options):
[task 2019-09-09T22:13:29.647Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 1451, in runTests
[task 2019-09-09T22:13:29.650Z] 22:13:29 INFO - mobileArgs, **kwargs)
[task 2019-09-09T22:13:29.650Z] 22:13:29 INFO - File "Z:\task_1568058584\build\tests\xpcshell\runxpcshelltests.py", line 1647, in runTestList
[task 2019-09-09T22:13:29.653Z] 22:13:29 INFO - raise exceptions[0]
[task 2019-09-09T22:13:29.653Z] 22:13:29 INFO - IOError: [Errno 2] No such file or directory: 'c:\users\task_1568058584\appdata\local\temp\xpc-plugins-prdjhq\gmp-clearkey\0.1\clearkey.dll'
[task 2019-09-09T22:16:34.732Z] WARNING | IO Completion Port failed to signal process shutdown
[task 2019-09-09T22:16:34.732Z] Parent process 1400 exited with children alive:
[task 2019-09-09T22:16:34.732Z] PIDS: 3504
[task 2019-09-09T22:16:34.732Z] Attempting to kill them, but no guarantee of success
[task 2019-09-09T22:16:34.745Z] 22:16:34 ERROR - Return code: 1
[task 2019-09-09T22:16:34.745Z] 22:16:34 ERROR - No tests run or test summary not found
[task 2019-09-09T22:16:34.745Z] 22:16:34 INFO - TinderboxPrint: xpcshell-xpcshell<br/><em class="testfail">T-FAIL</em>

https://bugzilla.mozilla.org/buglist.cgi?quicksearch=ALL%20clearkey.dll&list_id=14893143 shows 8 other bugs that happen once every 3-5 months or so. This is a bug in the harness if anything, not the test that happens to fall foul of it.

Component: Blocklist Implementation → XPCShell Harness
Product: Toolkit → Testing

Trying to flag this for triage, and there's no regressing bug and loads of dupes, so removing regression keyword.

Keywords: regression
Priority: P5 → --

This appears to be a Windows-specific (Windows 7 and Windows 10) low-frequency intermittent failure which has existed since at least 2016.

My understanding is that we execute:

        pluginsDir = mkdtemp(prefix='xpc-plugins-', dir=self._rootTempDir)
        # shutil.copytree requires dst to not exist. Deleting the tempdir
        # would make a race condition possible in a concurrent environment,
        # so we are using dir_utils.copy_tree which accepts an existing dst
        dir_util.copy_tree(self.pluginsPath, pluginsDir)

and sometimes copy_tree finds that the newly-created destination directory (pluginsDir) does not exist. This is happening in the test thread, so there is a lot of I/O happening concurrently. Windows OS or python bug? It would be nice to avoid this, but I'm not sure how.

:bc - Any ideas?

Flags: needinfo?(bob)
  • Sync the file system to write changes to disk after we create the temp directory?
  • Try our retry loop approach by waiting after the failure and trying again a couple of times?
  • Is this a common pattern used elsewhere? Should we wrap up our work around into a function and call that everywhere this pattern is used?
Flags: needinfo?(bob)

I know Windows xpcshell tests sometimes have trouble removing directories; that's currently handled with wait-and-retry:

https://searchfox.org/mozilla-central/rev/7531325c8660cfa61bf71725f83501028178cbb9/testing/xpcshell/runxpcshelltests.py#494

I don't recall seeing file-system problems in other test harnesses.

I don't recall seeing file-system problems on other platforms -- just Windows and of course the Android issues we know well from mozdevice.

The priority flag is not set for this bug.
:gbrown, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(gbrown)
Assignee: nobody → gbrown
Flags: needinfo?(gbrown)
Priority: -- → P3

Add simple wait-and-retry logic for the plugins directory creation, in hopes
of addressing low frequency intermittent failures. Add logging too, so that
there will be more information if this does not work.

Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0e416ad51fe7
Verify that xpcshell plugins directory created; r=bc

Leave open to better monitor any on-going failures.

Keywords: leave-open
Keywords: leave-open

No new clearkey.dll failures in almost 3 months.

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
status-firefox71: --- → fixed
status-firefox-esr68: --- → affected
Target Milestone: --- → mozilla71
See Also: → 1624073
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: