taskcluster win64 (debug) build failure: attempt to delete readonly file fails

RESOLVED FIXED in Firefox 50

Status

defect
RESOLVED FIXED
3 years ago
Last year

People

(Reporter: grenade, Assigned: grenade)

Tracking

unspecified
mozilla50
x86_64
Windows
Dependency tree / graph

Firefox Tracking Flags

(firefox50 fixed)

Details

Attachments

(1 attachment)

On TaskCluster Windows 64 bit builds, the platform is specified as win64 (rather than win32), so there is a failure to delete a readonly file on line 132 of config/nsinstall.py

Taken from the TaskCluster "Windows 8 x64 debug" build log at: https://treeherder.allizom.org/#/jobs?repo=try&revision=e04c8b20bc671da4bd67c45aa61001f567c3e6ba

21:56:13     INFO -  z:/task_1468616587/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1468616587/build/src/config/nsinstall.py -t -m 644 z:/task_1468616587/build/src/obj-firefox/security/nss/lib/freebl/freebl3.pdb z:/task_1468616587/build/src/obj-firefox/dist/lib
21:56:13     INFO -  Traceback (most recent call last):
21:56:13     INFO -    File "z:/task_1468616587/build/src/config/nsinstall.py", line 181, in <module>
21:56:13     INFO -      sys.exit(_nsinstall_internal(argv[1:]))
21:56:13     INFO -    File "z:/task_1468616587/build/src/config/nsinstall.py", line 146, in _nsinstall_internal
21:56:13     INFO -      copy_all_entries(args, target)
21:56:13     INFO -    File "z:/task_1468616587/build/src/config/nsinstall.py", line 106, in copy_all_entries
21:56:13     INFO -      handleTarget(e, dest)
21:56:13     INFO -    File "z:/task_1468616587/build/src/config/nsinstall.py", line 132, in handleTarget
21:56:13     INFO -      os.remove(targetpath)
21:56:13     INFO -  WindowsError: [Error 5] Access is denied: u'z:\\task_1468616587\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb'
21:56:13     INFO -  ../../coreconf/rules.mk:80: recipe for target 'libs' failed
Comment on attachment 8771661 [details]
Bug 1287258 - retry deletions on windows;

https://reviewboard.mozilla.org/r/64752/#review61760

::: config/nsinstall.py:130
(Diff revision 1)
>          if options.m:
>            os.chmod(targetpath, options.m)
>        else:
>          if os.path.exists(targetpath):
>            # On Windows, read-only files can't be deleted
> -          if sys.platform == "win32":
> +          if sys.platform.startswith("win"):

AFAIK, sys.platform is "win32" on 64-bits windows too.
Attachment #8771661 - Flags: review?(mh+mozilla)
https://reviewboard.mozilla.org/r/64752/#review61760

> AFAIK, sys.platform is "win32" on 64-bits windows too.

On buildbot that's most likely the case, but on TaskCluster builds it's specified as win64.
Sorry I guess I mis-guessed what sys.platform represents! :(
i did a little googling and came up with a theory that there is a file handle left open (https://bugs.python.org/issue1425127#msg27453).

Testing with a try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=caefed2fefbb
testing a new patch which:
- if platform is windows:
 - retry deletion n times
  - if attempt < n: log exception and wait (attempt * 0.5) seconds and retry until attempt = n
  - else throw exception
I've tested a push without the exception handling & logging (just retries) and it seems to work (https://treeherder.mozilla.org/#/jobs?repo=try&revision=36c84e5bf1acdcca4030f442c6d86cbee5805f36), eg the deletion eventually succeeds) this latest push should handle cases where the deletion doesn't succeed after n attempts: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c9281af4e3f6e0dd1b580b33145fbe6b7f832849
last link in above comment should have been: https://treeherder.allizom.org/#/jobs?repo=try&revision=c9281af4e3f6e0dd1b580b33145fbe6b7f832849
(push is to staging only, where win tc builds are visible)
Comment on attachment 8771661 [details]
Bug 1287258 - retry deletions on windows;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/64752/diff/1-2/
Attachment #8771661 - Attachment description: Bug 1287258 - include win64 in readonly file deletions; → Bug 1287258 - retry deletions on windows;
Attachment #8771661 - Flags: review?(mh+mozilla)
Comment on attachment 8771661 [details]
Bug 1287258 - retry deletions on windows;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/64752/diff/2-3/
Attachment #8771661 - Flags: review?(mh+mozilla) → review?(ted)
so i tried using mozfile.remove (https://treeherder.allizom.org/#/jobs?repo=try&revision=e5bca2e4c23e7e121235df5a6cd660a7bb56b693) and sometimes didn't get better results:

14:08:49     INFO -  mozmake.EXE[10]: Entering directory 'z:/task_1468846795/build/src/security/nss/lib/freebl'
14:08:49     INFO -  z:/task_1468846795/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1468846795/build/src/config/nsinstall.py -t -m 775 z:/task_1468846795/build/src/obj-firefox/security/nss/lib/freebl/freebl3.dll z:/task_1468846795/build/src/obj-firefox/dist/lib
14:08:49     INFO -  z:/task_1468846795/build/src/obj-firefox/_virtualenv/Scripts/python.exe z:/task_1468846795/build/src/config/nsinstall.py -t -m 644 z:/task_1468846795/build/src/obj-firefox/security/nss/lib/freebl/freebl3.pdb z:/task_1468846795/build/src/obj-firefox/dist/lib
14:08:49     INFO -  remove() failed for "(u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb',)". Reason: Access is denied (13). Retrying...
14:08:49     INFO -  remove() failed for "(u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb',)". Reason: Access is denied (13). Retrying...
14:08:49     INFO -  remove() failed for "(u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb',)". Reason: Access is denied (13). Retrying...
14:08:49     INFO -  remove() failed for "(u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb',)". Reason: Access is denied (13). Retrying...
14:08:49     INFO -  remove() failed for "(u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb',)". Reason: Access is denied (13). Retrying...
14:08:49     INFO -  Traceback (most recent call last):
14:08:49     INFO -    File "z:/task_1468846795/build/src/config/nsinstall.py", line 185, in <module>
14:08:49     INFO -      sys.exit(_nsinstall_internal(argv[1:]))
14:08:49     INFO -    File "z:/task_1468846795/build/src/config/nsinstall.py", line 150, in _nsinstall_internal
14:08:49     INFO -      copy_all_entries(args, target)
14:08:49     INFO -    File "z:/task_1468846795/build/src/config/nsinstall.py", line 107, in copy_all_entries
14:08:49     INFO -      handleTarget(e, dest)
14:08:49     INFO -    File "z:/task_1468846795/build/src/config/nsinstall.py", line 134, in handleTarget
14:08:49     INFO -      mozfile.remove(targetpath)
14:08:49     INFO -    File "z:\task_1468846795\build\src\testing\mozbase\mozfile\mozfile\mozfile.py", line 222, in remove
14:08:49     INFO -      _call_with_windows_retry(os.remove, (path,))
14:08:49     INFO -    File "z:\task_1468846795\build\src\testing\mozbase\mozfile\mozfile\mozfile.py", line 191, in _call_with_windows_retry
14:08:49     INFO -      _call_windows_retry(*args, **kwargs)
14:08:49     INFO -    File "z:\task_1468846795\build\src\testing\mozbase\mozfile\mozfile\mozfile.py", line 149, in _call_windows_retry
14:08:49     INFO -      func(*args)
14:08:49     INFO -  WindowsError: [Error 5] Access is denied: u'z:\\task_1468846795\\build\\src\\obj-firefox\\dist\\lib\\freebl3.pdb'
14:08:49     INFO -  ../../coreconf/rules.mk:80: recipe for target 'libs' failed

there are examples where this succeeded after several retries (https://public-artifacts.taskcluster.net/O6uGc1bFQsqtopaQ6xeSYw/0/public/logs/command_000003.log search for "remove() failed") but we still get examples where all 5 retries fail. i suspect this is due to the sleep timespan being the same 0.5 seconds every time and that we would get better results using either a random length timespan or if we were to increase the timespan on subsequent retries.

if the current patch gets through and ted or glandium agrees with my idea, i'll raise another bug to address the idea about varying the sleep timespan.
Flags: needinfo?(ted)
Flags: needinfo?(mh+mozilla)
Summary: taskcluster win64 (debug) build failure: atempt to delete readonly file fails → taskcluster win64 (debug) build failure: attempt to delete readonly file fails
Comment on attachment 8771661 [details]
Bug 1287258 - retry deletions on windows;

https://reviewboard.mozilla.org/r/64752/#review61944

::: config/nsinstall.py:19
(Diff revision 3)
>  import os
>  import os.path
>  import sys
>  import shutil
>  import stat
> +import mozfile

nit: imports are alphabetically ordered here.

::: config/nsinstall.py:132
(Diff revision 3)
>        else:
>          if os.path.exists(targetpath):
> -          # On Windows, read-only files can't be deleted
>            if sys.platform == "win32":
> +            # On Windows, read-only files can't be deleted
>              os.chmod(targetpath, stat.S_IWUSR)

I believe `mozfile.remove` takes care of this for you. If so, just remove these lines.

::: config/nsinstall.py:136
(Diff revision 3)
> +            # On Windows, read-only files can't be deleted
>              os.chmod(targetpath, stat.S_IWUSR)
> +            # and file handles may take a while to be released
> +            mozfile.remove(targetpath)
> +          else:
> -          os.remove(targetpath)
> +            os.remove(targetpath)

It might be nice if we fixed `mozfile.remove` to just call `os.remove` or `shutil.rmtree` as necessary on non-Windows so you could use it on all platforms here without extra overhead.
Attachment #8771661 - Flags: review?(ted) → review+
Depends on: 1287496
Comment on attachment 8771661 [details]
Bug 1287258 - retry deletions on windows;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/64752/diff/3-4/
Flags: needinfo?(ted)
Flags: needinfo?(mh+mozilla)
Keywords: checkin-needed

Comment 15

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/f93d6b4f7936
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla50

Updated

Last year
Product: Core → Firefox Build System
You need to log in before you can comment on or make changes to this bug.