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

Assignee

Description

•

7 years ago

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

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 1

•

7 years ago

Attached file Bug 1287258 - retry deletions on windows; — Details

Review commit: https://reviewboard.mozilla.org/r/64752/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/64752/

Attachment #8771661 - Flags: review?(mh+mozilla)

Mike Hommey [:glandium]

Comment 2

•

7 years ago

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)

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 3

•

7 years ago

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.

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 4

•

7 years ago

Sorry I guess I mis-guessed what sys.platform represents! :(

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 5

•

7 years ago

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

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 6

•

7 years ago

trying (harder) again: https://treeherder.mozilla.org/#/jobs?repo=try&revision=f152433df5a6
:)

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Updated

•

7 years ago

Blocks: 1285510

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 7

•

7 years ago

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

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 8

•

7 years ago

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)

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 9

•

7 years ago

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)

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 10

•

7 years ago

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)

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 11

•

7 years ago

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)

Pete Moore [:pmoore][:pete]

Updated

•

7 years ago

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

(not currently active) Ted Mielczarek

Comment 12

•

7 years ago

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+

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Updated

•

7 years ago

Depends on: 1287496

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Comment 13

•

7 years ago

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/

Rob Thijssen [:grenade (EET/UTC+0300)]

Assignee

Updated

•

7 years ago

Flags: needinfo?(ted)

Flags: needinfo?(mh+mozilla)

Keywords: checkin-needed

Pulsebot

Comment 14

•

7 years ago

Pushed by pmoore@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f93d6b4f7936
retry deletions on windows; r=ted

Keywords: checkin-needed

Carsten Book [:Tomcat]

Comment 15

•

7 years ago

bugherder

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

Status: ASSIGNED → RESOLVED

Closed: 7 years ago

status-firefox50: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla50

BMO Automation

Updated

•

6 years ago

Product: Core → Firefox Build System

Bugzilla

Quick Search

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

Categories

(Firefox Build System :: General, defect)

Tracking

(firefox50 fixed)

People

(Reporter: grenade, Assigned: grenade)

References

Details

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Updated

Comment 7

Comment 8

Comment 9

Comment 10

Comment 11

Updated

Comment 12

Updated

Comment 13

Updated

Comment 14

Comment 15

Updated