# Mozbase unit test mozlog/tests/test_structured.py fails on windows slaves when run from test package.

RESOLVED FIXED in mozilla32

RESOLVED FIXED
5 years ago
5 years ago

## Tracking

Trunk
mozilla32
x86_64
Linux
Points:
---
Dependency tree / graph
Bug Flags:
 in-testsuite +

## Attachments

### (1 attachment, 6 obsolete attachments)

 1.19 KB, patch dminor : review+ Details | Diff | Splinter Review
Reporter

### Description

5 years ago
Relevant portion of log:
13:31:42     INFO -  ERROR: test_setup_logging (test_structured.TestCommandline)
13:31:42     INFO -  ----------------------------------------------------------------------
13:31:42     INFO -  Traceback (most recent call last):
13:31:42     INFO -    File "C:\slave\test\build\tests\mozbase\mozlog\tests\test_structured.py", line 194, in test_setup_logging
13:31:42     INFO -      args = parser.parse_args(["--log-raw=/tmp/foo"])
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 1688, in parse_args
13:31:42     INFO -      args, argv = self.parse_known_args(args, namespace)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 1720, in parse_known_args
13:31:42     INFO -      namespace, args = self._parse_known_args(args, namespace)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 1926, in _parse_known_args
13:31:42     INFO -      start_index = consume_optional(start_index)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 1866, in consume_optional
13:31:42     INFO -      take_action(action, args, option_string)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 1778, in take_action
13:31:42     INFO -      argument_values = self._get_values(action, argument_strings)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 2204, in _get_values
13:31:42     INFO -      value = self._get_value(action, arg_string)
13:31:42     INFO -    File "c:\mozilla-build\python27\Lib\argparse.py", line 2233, in _get_value
13:31:42     INFO -      result = type_func(arg_string)
13:31:42     INFO -    File "C:\slave\test\build\venv\lib\site-packages\mozlog\structured\commandline.py", line 26, in log_file
13:31:42     INFO -      return open(name, "w")
13:31:42     INFO -  IOError: [Errno 2] No such file or directory: '/tmp/foo'

Looks like '/tmp' doesn't exist on our windows test slaves.
Assignee

### Comment 1

5 years ago
Attachment #8419713 - Flags: review?(dminor)
Reporter

### Comment 2

5 years ago
Thanks, this looks good!

I'm going to give this a run on our try server [1] before finishing the review just to make sure nothing unexpected shows up.

[1] https://tbpl.mozilla.org/?tree=Try&rev=8d665a95052b
Assignee: nobody → j.parkouss
Status: NEW → ASSIGNED
Reporter

### Comment 3

5 years ago
Comment on attachment 8419713 [details] [diff] [review]
fix log file creation on windows and delete it at the end of the test

Review of attachment 8419713 [details] [diff] [review]:
-----------------------------------------------------------------

Unfortunately, this doesn't work as expected on Windows. The filename of the NamedTemporaryFile can't be used to reopen the file on Windows while the file is still open [1], which leads to error at [2].

I think what we need to do is to set the delete parameter to false, close the file right away, and then delete the file manually at the end of the test, which is kind of hacky. If you have a cleaner way, let me know. Thanks for looking at this!

[1] https://docs.python.org/2/library/tempfile.html#tempfile.NamedTemporaryFile
[2] https://tbpl.mozilla.org/php/getParsedLog.php?id=39356983&tree=Try&full=1#error4
Attachment #8419713 - Flags: review?(dminor) → review-
Assignee

### Comment 4

5 years ago
I'm sorry for the mistake(s). I didn't test on windows and I didn't read the python doc which clearly indicate the behaviour ;).

I will send another patch where I followed your recommendations as I don't see a better solution. I currently can't test on windows but I think this new patch will work.

Thanks for the feedback!
Assignee

### Comment 5

5 years ago
Attachment #8419713 - Attachment is obsolete: true
Attachment #8420187 - Flags: review?(dminor)
Reporter

### Comment 6

5 years ago
Thanks, don't worry about it! I don't have a windows machine either, so I'll have to kick off another try server run.
Reporter

### Comment 7

5 years ago
Try job here: https://tbpl.mozilla.org/?tree=Try&rev=f46654df2c70
Assignee

### Comment 8

5 years ago
Well !

I saw the error log, and found [1] as a possible explanation and solution for this issue. I'm sorry I have to bother you again to launch a build on the try server, but this is my first bug and I don't have yet a mozilla hg account level 1 - so I'm not able to launch it myself.

I'll post a new patch soon, and I'll hope this one will work:) Thanks for the support.
Assignee

### Comment 9

5 years ago
Attachment #8420187 - Attachment is obsolete: true
Attachment #8420187 - Flags: review?(dminor)
Attachment #8420510 - Flags: review?(dminor)
Reporter

### Comment 10

5 years ago
(In reply to j.parkouss from comment #8)
> Well !
>
> I saw the error log, and found [1] as a possible explanation and solution
> for this issue. I'm sorry I have to bother you again to launch a build on
> the try server, but this is my first bug and I don't have yet a mozilla hg
> account level 1 - so I'm not able to launch it myself.
>
> I'll post a new patch soon, and I'll hope this one will work:) Thanks for
> the support.
Don't worry about it, I'm happy you're interested in contributing! Latest try run is here:
https://tbpl.mozilla.org/?tree=Try&rev=a40f68024d4e
Assignee

### Comment 11

5 years ago
The best solution I can see now is to use NamedTemporaryFile this way:

temp_fname = tempfile.NamedTemporaryFile(delete=False).name
try:
# do something, maybe opening the file
# open(temp_fname, 'w')
finally:

This way the file is automatically created then closed properly, and we may reopen it - but in case of a test failure, the file existed anyway so the finally will always success.

I tested it on a windows xp os today and it's working. i'll send you a patch as soon as I have the time.
Reporter

### Comment 12

5 years ago
(In reply to j.parkouss from comment #11)
> The best solution I can see now is to use NamedTemporaryFile this way:
>
> temp_fname = tempfile.NamedTemporaryFile(delete=False).name
> try:
>     # do something, maybe opening the file
>     # open(temp_fname, 'w')
> finally:
>
> This way the file is automatically created then closed properly, and we may
> reopen it - but in case of a test failure, the file existed anyway so the
> finally will always success.
>
> I tested it on a windows xp os today and it's working. i'll send you a patch
> as soon as I have the time.

Thanks for your persistence! Looking forward to the patch.
Assignee

### Comment 13

5 years ago
Posted patch 1003412.patch (obsolete) — Splinter Review
Attachment #8420510 - Attachment is obsolete: true
Attachment #8420510 - Flags: review?(dminor)
Attachment #8421104 - Flags: review?(dminor)
Reporter

### Comment 14

5 years ago
I think your missing part of your patch - what is there just adds the import for tempfile :)
Assignee

### Comment 15

5 years ago
Hmm I don't think so - I clicked on the following link [1] and scrolled down with the mouse and there is more than the import. But I applied instructions from here [2] this time in order to create the patch and I don't know well mercurial, maybe I have done something wrong ?

[1] https://bugzilla.mozilla.org/attachment.cgi?id=8421104&action=edit
[2] https://developer.mozilla.org/en-US/docs/Mercurial_FAQ#How_can_I_generate_a_patch_for_somebody_else_to_check-in_for_me.3F
Reporter

### Comment 16

5 years ago
Oh, sorry, not sure how I missed that! New try run here: https://tbpl.mozilla.org/?tree=Try&rev=4d9208982141
Assignee

### Comment 17

5 years ago
It's hard to debug when I can't reproduce it! Anyway, I found that on the last try build the preceeding test log some lines like this one:

remove() failed for "('c:\\users\\cltbld\\appdata\\local\\temp\\tmpvcib92\\foo\\bar.txt',)". Reason: The process cannot access the file because it is being used by another process (13). Retrying...

I looked at this test ([1]), and there is a call to mozfile.remove at the end of the test. I looked at the implementation, and there is a retry mecanism in case of a Windows OS [2].

I think this is the solution. Replace os.unlink with mozfile.remove. I hope mozfile is accessible through this test - I will test when I have the time and send another patch.

I read in some post (I can't remember which one right now) that it may be so because of various reasons, for example an antivirus analysing the file while we're trying to delete it.

[1] http://dxr.mozilla.org/mozilla-central/source/testing/mozbase/mozversion/tests/test_b2g.py#30
[2] http://dxr.mozilla.org/mozilla-central/source/testing/mozbase/mozfile/mozfile/mozfile.py#133
Assignee

### Comment 18

5 years ago
Posted patch 1003412.patch (obsolete) — Splinter Review
This one should work on windows. I used mozfile.remove to handle previous errors when deleting a file opened by another process.

This is OK if the inclusion of the mozfile package is accepted here - and I suppose it is.
Attachment #8421104 - Attachment is obsolete: true
Attachment #8421104 - Flags: review?(dminor)
Attachment #8422380 - Flags: review?(dminor)
Reporter

### Comment 19

5 years ago
Still no luck: https://tbpl.mozilla.org/?tree=Try&rev=464a860aaa04

At this point, I think it might end up being better to try something simpler. It looks like using a filename of '-' will cause the log to go to stdout instead of to a file, which seems to be fine (at least on linux.)

If you want to update your patch to do this we can get it landed and find you a more interesting bug to work on.
Reporter

### Updated

5 years ago
Attachment #8422380 - Flags: review?(dminor)
Assignee

### Comment 20

5 years ago
Thank you for the solution - I hope this will work !
Attachment #8422380 - Attachment is obsolete: true
Attachment #8423664 - Flags: review?(dminor)
Reporter

### Comment 21

5 years ago
Thanks for your persistence! The patch looks fine - you just need to update your commit comment for the logs. Use something like:

"Bug 1003412 - Fix Mozbase unit test mozlog/tests/test_structured.py on windows; r=dminor"

You need the bug number, what the patch does and the reviewer. Almost there!

If you're interested in looking at another bug, Bug 1003405 is another straightforward one. After that, maybe we can look at Bug 1003408.
Assignee

### Comment 22

5 years ago
Thanks for all the workflow process infos :)
Attachment #8423664 - Attachment is obsolete: true
Attachment #8423664 - Flags: review?(dminor)
Attachment #8423829 - Flags: review?(dminor)
Reporter

### Comment 23

5 years ago
Comment on attachment 8423829 [details] [diff] [review]
Bug 1003412 - Fix Mozbase unit test mozlog/tests/test_structured.py on windows; r=dminor

Looks good, thank you!
Attachment #8423829 - Flags: review?(dminor) → review+
Reporter

### Updated

5 years ago
Keywords: checkin-needed

### Comment 24

5 years ago
https://hg.mozilla.org/integration/fx-team/rev/5bdeb198f7ce
Keywords: checkin-needed
Whiteboard: [good first bug][mentor=dminor][lang=python] → [good first bug][mentor=dminor][lang=python][fixed-in-fx-team]

### Comment 25

5 years ago
https://hg.mozilla.org/mozilla-central/rev/5bdeb198f7ce
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Whiteboard: [good first bug][mentor=dminor][lang=python][fixed-in-fx-team] → [good first bug][mentor=dminor][lang=python]
Target Milestone: --- → mozilla32
You need to log in before you can comment on or make changes to this bug.