1231745 - "WindowsError: [Error 2] The system cannot find the file specified" sometimes at the end of bisection

Status: RESOLVED FIXED

(Testing :: mozregression, defect)

Description

[Loic]

Error at the end of bisection:


Traceback (most recent call last):
  File "C:\Python27\Scripts\mozregression-script.py", line 9, in <module>
    load_entry_point('mozregression==2.0.1', 'console_scripts', 'mozregression')
()
  File "C:\Python27\lib\site-packages\mozregression\main.py", line 294, in main
    app.clear()
  File "C:\Python27\lib\site-packages\mozregression\main.py", line 69, in clear
    mozfile.remove(self._download_dir)
  File "C:\Python27\lib\site-packages\mozfile\mozfile.py", line 229, in remove
    _update_permissions(os.path.join(root, entry))
  File "C:\Python27\lib\site-packages\mozfile\mozfile.py", line 202, in _update_
permissions
    stats = os.stat(path)
WindowsError: [Error 2] Le fichier spécifié est introuvable: 'c:\\users\\user\
\appdata\\local\\temp\\tmpoojmxv\\tmpgkjnpq.tmp'

Comment 1

[Loic]

I think it appears with a profile specified:


C:\Users\user>mozregression --bits=32 --find-fix --repo=fx-team --bad=363d8679
31b54a7285eab599297386bdb9c63dd9 --good=432bea2c0c685740470dd5e1e25dd90ecba395c1
 --profile=C:/Users/user/AppData/Roaming/Mozilla/Firefox/Profiles/joa7xru5.nig
htly18 --profile-persistence=reuse
**********
You should use a config file. Please use the --write-config command line flag to
 help you create one.
**********

 0:01.18 LOG: MainThread main INFO Getting fx-team builds between 432bea2c0c6857
40470dd5e1e25dd90ecba395c1 and 363d867931b54a7285eab599297386bdb9c63dd9
 0:05.00 LOG: MainThread Bisector INFO Pushlog:
https://hg.mozilla.org/integration/fx-team/pushloghtml?fromchange=363d867931b54a
7285eab599297386bdb9c63dd9&tochange=432bea2c0c685740470dd5e1e25dd90ecba395c1

 0:05.01 LOG: MainThread download INFO Downloading build from: https://queue.tas
kcluster.net/v1/task/qiNC0az5S5aMh54-UaQjHQ/runs/0/artifacts/public%2Fbuild%2Ffi
refox-45.0a1.en-US.win32.zip
===== Downloaded 100% =====
 1:55.19 LOG: MainThread Test Runner INFO Running fx-team build built on 2015-11
-10 20:03:24.834000, revision 73f07190
 1:57.01 LOG: MainThread Test Runner INFO Launching c:\users\user\appdata\loca
l\temp\tmpmlusqd\firefox\firefox.exe
 1:57.09 LOG: MainThread mozversion INFO application_buildid: 20151110094435
 1:57.09 LOG: MainThread mozversion INFO application_changeset: 73f07190af6de7bc
7f8da17541814e05b5571759
 1:57.09 LOG: MainThread mozversion INFO application_name: Firefox
 1:57.09 LOG: MainThread mozversion INFO application_repository: https://hg.mozi
lla.org/integration/fx-team
 1:57.09 LOG: MainThread mozversion INFO application_version: 45.0a1
Was this inbound build good, bad, or broken? (type 'good', 'bad', 'skip', 'retry
' or 'exit' and press Enter): bad
 2:12.07 LOG: MainThread Bisector INFO Narrowed inbound regression window from [
363d8679, 432bea2c] (4 revisions) to [73f07190, 432bea2c] (2 revisions) (~1 step
s left)
 2:12.07 LOG: MainThread main INFO Oh noes, no (more) inbound revisions :(
 2:12.07 LOG: MainThread Bisector INFO First good revision: 432bea2c0c685740470d
d5e1e25dd90ecba395c1
 2:12.07 LOG: MainThread Bisector INFO Last bad revision: 73f07190af6de7bc7f8da1
7541814e05b5571759
 2:12.07 LOG: MainThread Bisector INFO Pushlog:
https://hg.mozilla.org/integration/fx-team/pushloghtml?fromchange=73f07190af6de7
bc7f8da17541814e05b5571759&tochange=432bea2c0c685740470dd5e1e25dd90ecba395c1

Traceback (most recent call last):
  File "C:\Python27\Scripts\mozregression-script.py", line 9, in <module>
    load_entry_point('mozregression==2.0.1', 'console_scripts', 'mozregression')
()
  File "C:\Python27\lib\site-packages\mozregression\main.py", line 294, in main
    app.clear()
  File "C:\Python27\lib\site-packages\mozregression\main.py", line 69, in clear
    mozfile.remove(self._download_dir)
  File "C:\Python27\lib\site-packages\mozfile\mozfile.py", line 229, in remove
    _update_permissions(os.path.join(root, entry))
  File "C:\Python27\lib\site-packages\mozfile\mozfile.py", line 202, in _update_
permissions
    stats = os.stat(path)
WindowsError: [Error 2] Le fichier spÚcifiÚ est introuvable: 'c:\\users\\user\
\appdata\\local\\temp\\tmpf7wfth\\tmp_nr7y8.tmp'

Comment 2

[Julien Pagès (:parkouss)]

Hey, thanks Loic for reporting that bug!

I think this is a race condition, because we are asking to stop the background downloads in there:

https://github.com/mozilla/mozregression/blob/master/mozregression/main.py#L65

but then we remove the folder - and during this time, the download threads probably ends - removing the file. That means that we list the file name, then just before we try to access it it gets removed by the thread.

I think that if you use a --persist directory, that won't happen - because then the directory do not need to be removed. I believe this is why no one reported this before, because that is a recommended option when you use --write-config.

So, to fix this, we should explicitly wait for the background thread to finish, or use some kind of locking mechanism to prevent that race condition.

Comment 3

[Julien Pagès (:parkouss)]

Oh ahal, sorry my question is here:

Or maybe we want mozfile.remove to be thread safe ?

Comment 4

[Andrew Halberstadt [:ahal]]

I'm not 100% sure what you're proposing. You mean make mozfile not remove files that are still being used by other threads? That sounds really complicated, how would it know?

I'd just make that call to cancel() block from returning until the downloads were actually canceled.

Comment 5

[Julien Pagès (:parkouss)]

Yeah, I guess I wanted to handle those kind of exceptions in mozfile directly, but indeed that should be probably complicated. :)

Agreed, blocking the downloading threads seems to me like the best option also.

Comment 6

[Julien Pagès (:parkouss)]

Attachment: fix race condition when removing dl dir

Comment 7

[William Lachance (:wlach)]

Comment on attachment 8697445 [details] [review]
fix race condition when removing dl dir

Left a question in the review for you. Feel free to r? again after it's either answered or addressed. :)

Comment 8

[William Lachance (:wlach)]

Comment on attachment 8697445 [details] [review]
fix race condition when removing dl dir

After further discussion, happy to r+ this. Leaving it up to you to decide the details.

Comment 9

[Julien Pagès (:parkouss)]

ok thanks Will, I'm changing it to be more explicit, as discussed in github comments. I will add a comment to explain the wait() call - and a comment in the commit to explain why that works in the GUI.

Comment 10

[Julien Pagès (:parkouss)]

Landed in https://github.com/mozilla/mozregression/commit/e37f0dc3241c2e0bedaf2e614f40606a919c1392. I will release a patch release with that fix, waiting some more days to see if something new comes up before I do that.