Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Description • 8 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 • 8 years ago

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

	Mike Hommey [:glandium]
	Comment 2 • 8 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.

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 3 • 8 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 • 8 years ago

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

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 5 • 8 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 • 8 years ago

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

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 7 • 8 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 • 8 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 • 8 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/

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 10 • 8 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/

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 11 • 8 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.

	(not currently active) Ted Mielczarek
	Comment 12 • 8 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.

	Rob Thijssen [:grenade (EET/UTC+0300)] Assignee
	Comment 13 • 8 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/

	Pulsebot
	Comment 14 • 8 years ago

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

	Carsten Book [:Tomcat]
	Comment 15 • 8 years ago
bugherder

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