Closed Bug 1280326 Opened 8 years ago Closed 8 years ago

TestWebIDLCodegenManager.test_python_change_regenerate_everything failing in TaskCluster Windows™ Firefox desktop builds

Categories

(Firefox Build System :: General, defect)

Product:
Firefox Build System
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox50 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla50
Tracking Flags:
Tracking Status
firefox50 --- fixed

People

(Reporter: pmoore, Assigned: gps)

References

Details

Attachments

(2 files, 1 obsolete file)

Bug 1280326 - Stop monkeypatching os.path.exists;
58 bytes, text/x-review-board-request
ted
: review+
Details
bug 1280326 - make MockedOpen case-insensitive on Windows.
58 bytes, text/x-review-board-request
gps
: review+
Details 
Pulling this individual failure out of bug 1274676 into its own bug.


See e.g. https://public-artifacts.taskcluster.net/XPWwTaFlQRStvQ7wS-wuNw/4/public/logs/all_commands.log


16:23:46  WARNING - TEST-UNEXPECTED-FAIL |
y:/Task_1466002871/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py
| TestWebIDLCodegenManager.test_python_change_regenerate_everything, line 261:
NO MESSAGE
16:23:46     INFO - ERROR: If a Python file changes, we should attempt to
rebuild everything.
16:23:46     INFO - Traceback (most recent call last):
16:23:46     INFO -   File
"y:/Task_1466002871/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py",
line 261, in test_python_change_regenerate_everything
16:23:46     INFO -     result = m1.generate_build_files()
16:23:46     INFO -   File
"y:\Task_1466002871\build\src\dom\bindings\mozwebidlcodegen\__init__.py", line
259, in generate_build_files
16:23:46     INFO -     global_changed, global_hashes =
self._global_dependencies_changed()
16:23:46     INFO -   File
"y:\Task_1466002871\build\src\dom\bindings\mozwebidlcodegen\__init__.py", line
499, in _global_dependencies_changed
16:23:46     INFO -     with open(f, 'rb') as fh:
16:23:46     INFO -   File "y:\Task_1466002871\build\src\config\mozunit.py",
line 143, in __call__
16:23:46     INFO -     file = self.open(name, mode)
16:23:46     INFO - IOError: [Errno 2] No such file or directory:
u'y:\\task_1466002871\\build\\src\\dom\\bindings\\mozwebidlcodegen\\test\\fakemodule.py'
Note, this is the very last test failure blocking us from going live now, so hopefully no more bugs after this one before rollout. \o/
Component: Integration → Build Config
Product: Taskcluster → Core
Hey Greg,

Does this test run successfully for you locally on Windows?

dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py

Thanks,
Pete
Flags: needinfo?(gps)
Trying a suggestion from mshal:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9e2003f33ead

diff --git a/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py b/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py
--- a/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py
+++ b/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py
@@ -247,17 +247,17 @@ class TestWebIDLCodegenManager(unittest.
             mod.__file__ = fake_path
 
             args = self._get_manager_args()
             m1 = WebIDLCodegenManager(**args)
             with MockedOpen({fake_path: '# Original content'}):
                 old_exists = os.path.exists
                 try:
                     def exists(p):
-                        if p == fake_path:
+                        if os.path.normcase(p) == os.path.normcase(fake_path):
                             return True
                         return old_exists(p)
 
                     os.path.exists = exists
 
                     result = m1.generate_build_files()
                     l = len(result.inputs)
Worker type was broken at the time, so trying again against latest mozilla-central changeset:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=0e64234605c5
while I don't know the exact problem here, it seems that we are trying to create a new file called fakemodule.py, and this fails because the base directory we are using doesn't exist.

The filename:
IOError: [Errno 2] No such file or directory: u'z:\\task_1466758295\\build\\src\\dom\\bindings\\mozwebidlcodegen\\test\\fakemodule.py'

we get the base from the variable OUR_DIR:
https://dxr.mozilla.org/mozilla-central/source/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py#30

which is this code:
OUR_DIR = mozpath.abspath(mozpath.dirname(__file__))

my best guess at __file__ is:
z:/Task_1466758295/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py

which then our_dir should be:
z:/Task_1466758295/build/src/dom/bindings/mozwebidlcodegen/test

so then why does open(f, 'wt') fail where f is:
z:\\task_1466758295\\build\\src\\dom\\bindings\\mozwebidlcodegen\\test\\fakemodule.py


I can think of 2 reasons:
1) python is case sensitive and windows is not, notice that task_1466758295 is lower vs upper case in all other references?
2) forward slash vs backslash

My money is on #1.  How do we fix this?  I am not sure why we use mozpath vs os.path for abspath and dirname when defining OUR_DIR, possibly that is problematic?

As to why this is failing here and not in buildbot- check out our buildbot path:
c:/builds/moz2_slave/try-w32-0000000000000000000000/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py

it is all lowercase, there is no odd stuff going on there.  Maybe we make task lower case at the top level directory in the AMI or wherever that is created?
Oh! Yeah, you hit the nail on the head. If you look at the last frame in the stack in comment 0, it's in `MockedOpen.__call__`:
https://dxr.mozilla.org/mozilla-central/rev/d1102663db10b3d4b9358f3cf4e16b7c56902352/config/mozunit.py#134

We use that class in unit tests to mock filesystem operations. It checks to see if the filename is in its list of known mock files with a simple `absname in self.files`, which is clearly going to fail if there are case differences. We should fix that to work with case differences on Windows and Mac, which both have case-insensitive filesystems by default. (Windows is worse about preserving case, though.)
The simplest solution would probably be to just normalize filenames to lowercase on Windows/Mac everywhere in `MockedOpen`.
I think I have a better fix for this.
Assignee: nobody → gps
Status: NEW → ASSIGNED
Flags: needinfo?(gps)
MockedOpen monkeypatches os.path.exists. Changes to MockedOpen
since this test code was written have made it more robust
making the extra monkeypatching in the test not necessary.

This change may not fix the test failure reported in the bug.
But at least it makes the test code simpler.

Review commit: https://reviewboard.mozilla.org/r/60578/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/60578/
Attachment #8765038 - Flags: review?(ted)
Attachment #8765039 - Flags: review?(ted)
This should make the test failure reported in the bug go away.

Review commit: https://reviewboard.mozilla.org/r/60580/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/60580/
I was super hopeful, but sadly, after patching, the test still fails.
https://public-artifacts.taskcluster.net/Vx3K_ptyT86E8S0LGbOuyQ/0/public/logs/command_000003.log
https://treeherder.mozilla.org/#/jobs?repo=try&revision=388efac568db425335bb95e95b28df41743def8c

11:07:26  WARNING - TEST-UNEXPECTED-FAIL | z:/Task_1467020917/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py | TestWebIDLCodegenManager.test_python_change_regenerate_everything, line 253: [Errno 2] No such file or directory: u'z:\\task_1467020917\\build\\src\\dom\\bindings\\mozwebidlcodegen\\test\\fakemodule.py'
11:07:26     INFO - ERROR: If a Python file changes, we should attempt to rebuild everything.
11:07:26     INFO - Traceback (most recent call last):
11:07:26     INFO -   File "z:/Task_1467020917/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py", line 253, in test_python_change_regenerate_everything
11:07:26     INFO -     result = m1.generate_build_files()
11:07:26     INFO -   File "z:\Task_1467020917\build\src\dom\bindings\mozwebidlcodegen\__init__.py", line 259, in generate_build_files
11:07:26     INFO -     global_changed, global_hashes = self._global_dependencies_changed()
11:07:26     INFO -   File "z:\Task_1467020917\build\src\dom\bindings\mozwebidlcodegen\__init__.py", line 499, in _global_dependencies_changed
11:07:26     INFO -     with open(f, 'rb') as fh:
11:07:26     INFO -   File "z:\Task_1467020917\build\src\config\mozunit.py", line 143, in __call__
11:07:26     INFO -     file = self.open(name, mode)
11:07:26     INFO - IOError: [Errno 2] No such file or directory: u'z:\\task_1467020917\\build\\src\\dom\\bindings\\mozwebidlcodegen\\test\\fakemodule.py'
11:07:26     INFO - TEST-PASS | z:/Task_1467020917/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py | TestWebIDLCodegenManager.test_rebuild_dependencies
11:07:26     INFO - No handlers could be found for logger "mozwebidlcodegen.WebIDLCodegenManager"
11:07:26     INFO - TEST-PASS | z:/Task_1467020917/build/src/dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py | TestWebIDLCodegenManager.test_unknown_state_version
11:07:26     INFO - z:/Task_1467020917/build/src/config/rules.mk:110: recipe for target 'mozwebidlcodegen/test/test_mozwebidlcodegen.py-run' failed
11:07:26     INFO - mozmake[2]: *** [mozwebidlcodegen/test/test_mozwebidlcodegen.py-run] Error 1
11:07:26     INFO - mozmake[2]: Target 'check' not remade because of errors.
ok, interesting.  we still have the same errors and it looks like we are looking for a lower case version of the file vs the real path which has an upper case T for the Task_1467020917.

oh the fun of dealing with tools that are case sensitive and an operating system that isn't.
Attachment #8765038 - Flags: review?(ted) → review-
Attachment #8765038 - Flags: review- → review+
as this patch doesn't seem to be fixing the issue, possibly we need to do a bit more.

:ted, do you have other ideas?
Flags: needinfo?(ted)
gps' patch doesn't actually do what I suggested in comment 7.
Flags: needinfo?(ted)
I am not familiar with MockedOpen, :ted, can you put up a patch for this?
Flags: needinfo?(ted)
Comment on attachment 8765039 [details]
Bug 1280326 - Normalize fake module path;

https://reviewboard.mozilla.org/r/60580/#review57968

::: dom/bindings/mozwebidlcodegen/test/test_mozwebidlcodegen.py:242
(Diff revision 1)
>          # directory.
>          #
>          # Hacking imp to accept a MockedFile doesn't appear possible. So for
>          # the first iteration we read from a temp file. The second iteration
>          # doesn't need to import, so we are fine with a mocked file.
> -        fake_path = mozpath.join(OUR_DIR, 'fakemodule.py')
> +        fake_path = os.path.normpath(mozpath.join(OUR_DIR, 'fakemodule.py'))

`normpath` doesn't normalize case, there's `normcase` for that but it also changes forward slashes into backslashes.
Attachment #8765039 - Flags: review?(ted) → review-
I submitted a try job with my patch. grenade: you want to try my patch in TC?
Flags: needinfo?(ted) → needinfo?(rthijssen)
Testing now: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b66ed8d842a7c72a21d61b23082eb947fb9647cd

I had to make a slight change to the patch because I got a merge conflict on _wrapped_exists due to changes by dustin here: https://hg.mozilla.org/integration/mozilla-inbound/rev/c242defba0dd

My changes here: https://hg.mozilla.org/try/diff/b66ed8d842a7/config/mozunit.py
Flags: needinfo?(rthijssen)
My patch failed with:

16:04:06  WARNING - TEST-UNEXPECTED-FAIL | z:/Task_1467210286/build/src/config/tests/unit-mozunit.py | TestMozUnit.test_mocked_open, line 23: False is not true
16:04:06     INFO - FAIL: test_mocked_open (__main__.TestMozUnit)
16:04:06     INFO - Traceback (most recent call last):
16:04:06     INFO -   File "z:/Task_1467210286/build/src/config/tests/unit-mozunit.py", line 23, in test_mocked_open
16:04:06     INFO -     self.assertTrue(os.path.exists('file1'))
16:04:06     INFO - AssertionError: False is not true
16:04:06     INFO - z:/Task_1467210286/build/src/config/rules.mk:110: recipe for target 'tests/unit-mozunit.py-run' failed
16:04:06     INFO - mozmake[1]: *** [tests/unit-mozunit.py-run] Error 1

I don't know if this is because my patch is altered from Ted's or if it's something else. Build log is at: https://public-artifacts.taskcluster.net/NrpcMYC_Q5OaFh6U_5HYdw/0/public/logs/command_000003.log
that looks like a new error!  although I think this error is related to the patch as it is in mocked_open.
My patch had green builds in buildbot on Try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=5bb0ad6eba93

We probably just need to update the new methods that dustin added in bug 1275409 to use `normcase`. I'll rebase my patch.
Comment on attachment 8766039 [details]
bug 1280326 - make MockedOpen case-insensitive on Windows.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/61100/diff/1-2/
grenade: Rebased! Sorry, I clearly should have written that patch against a more recent revision. Can you try this one? It's on top of central from today.
Flags: needinfo?(rthijssen)
Comment on attachment 8766039 [details]
bug 1280326 - make MockedOpen case-insensitive on Windows.

https://reviewboard.mozilla.org/r/61100/#review58284
Attachment #8766039 - Flags: review?(gps) → review+
Attachment #8765039 - Attachment is obsolete: true
Pushed by gszorc@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/b79c51ca296e
Stop monkeypatching os.path.exists; r=ted
Pushed by gszorc@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/22cfff15c199
make MockedOpen case-insensitive on Windows. r=gps
with the latest push, I still see this in the logs:
19:49:56     INFO - TEST-PASS | z:/Task_1467225885/build/src/config/tests/unit-expandlibs.py | TestSymbolOrder.test_getFoldedSections
19:49:56     INFO - TEST-PASS | z:/Task_1467225885/build/src/config/tests/unit-expandlibs.py | TestSymbolOrder.test_getOrderedSections
19:49:56     INFO - TEST-PASS | z:/Task_1467225885/build/src/config/tests/unit-expandlibs.py | TestSymbolOrder.test_getOrderedSectionsWithICF
19:49:56  WARNING - TEST-UNEXPECTED-FAIL | z:/Task_1467225885/build/src/config/tests/unit-mozunit.py | TestMozUnit.test_mocked_open, line 23: False is not true
19:49:56     INFO - FAIL: test_mocked_open (__main__.TestMozUnit)
19:49:56     INFO - Traceback (most recent call last):
19:49:56     INFO -   File "z:/Task_1467225885/build/src/config/tests/unit-mozunit.py", line 23, in test_mocked_open
19:49:56     INFO -     self.assertTrue(os.path.exists('file1'))
19:49:56     INFO - AssertionError: False is not true
19:49:56     INFO - z:/Task_1467225885/build/src/config/rules.mk:110: recipe for target 'tests/unit-mozunit.py-run' failed
19:49:56     INFO - mozmake[1]: *** [tests/unit-mozunit.py-run] Error 1
19:49:56     INFO - TEST-PASS | z:/Task_1467225885/build/src/config/tests/unit-nsinstall.py | TestNsinstall.test_nsinstall_D
19:49:56     INFO - TEST-PASS | z:/Task_1467225885/build/src/config/tests/unit-nsinstall.py | TestNsinstall.test_nsinstall_basic


^ from win7 debug: https://public-artifacts.taskcluster.net/KBqSbldETQi8YnIoydruYA/0/public/logs/live_backing.log


is it possible that our fix to fiddle with paths is now causing our unittest for the mocked_open to need to be updated for casing as well?

in fact, it appears we are never running the test we are trying to fix as we fail too early.
https://hg.mozilla.org/mozilla-central/rev/b79c51ca296e
https://hg.mozilla.org/mozilla-central/rev/22cfff15c199
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
status-firefox50: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla50
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
We are still failing:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=15c8b674778128c6c8df5377f7a0822c9a18f302

ted, could you maybe do a similar fix the the mocked_open unittests?
grenade gave me access to a builder and I spotted the problem. I just missed a spot with my patch. Additional patch incoming shortly, I verified that it fixed the test failure from comment 31 on a TC build instance.
mozreview doesn't want me to push a new patch to a request that's already been submitted, so jmaher r+ed my pastebin'ed patch over IRC.
The follow up fix worked: https://public-artifacts.taskcluster.net/c-JID7ICQ5WEZqVyXJ6DTQ/0/public/logs/command_000003.log
Now there are new related errors (Lists differ):

14:53:01  WARNING - TEST-UNEXPECTED-FAIL | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestPreprocessManifest.test_preprocess_manifest, line 75: Lists differ: [(('z:\\task_1467380390\\build... != [(('z:\\Task_1467380390\\build...
14:53:01     INFO - FAIL: test_preprocess_manifest (__main__.TestPreprocessManifest)
14:53:01     INFO - Traceback (most recent call last):
14:53:01     INFO -   File "z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py", line 75, in test_preprocess_manifest
14:53:01     INFO -     self.assertEqual(self.sink.log, self.EXPECTED_LOG)
14:53:01     INFO - AssertionError: Lists differ: [(('z:\\task_1467380390\\build... != [(('z:\\Task_1467380390\\build...
14:53:01     INFO - First differing element 0:
14:53:01     INFO - (('z:\\task_1467380390\\build\\src\\obj-firefox\\python\\manifest', 2), 'add', '', 'bar/*')
14:53:01     INFO - (('z:\\Task_1467380390\\build\\src\\obj-firefox\\python\\manifest', 2), 'add', '', 'bar/*')
14:53:01     INFO - Diff is 1092 characters long. Set self.maxDiff to None to see it.
14:53:01  WARNING - TEST-UNEXPECTED-FAIL | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestPreprocessManifest.test_preprocess_manifest_defines, line 92: Lists differ: [(('z:\\task_1467380390\\build... != [(('z:\\Task_1467380390\\build...
14:53:01     INFO - FAIL: test_preprocess_manifest_defines (__main__.TestPreprocessManifest)
14:53:01     INFO - Traceback (most recent call last):
14:53:01     INFO -   File "z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py", line 92, in test_preprocess_manifest_defines
14:53:01     INFO -     [((self.MANIFEST_PATH, 12), 'add', 'baz', 'baz.exe')])
14:53:01     INFO - AssertionError: Lists differ: [(('z:\\task_1467380390\\build... != [(('z:\\Task_1467380390\\build...
14:53:01     INFO - First differing element 0:
14:53:01     INFO - (('z:\\task_1467380390\\build\\src\\obj-firefox\\python\\manifest', 2), 'add', '', 'bar/*')
14:53:01     INFO - (('z:\\Task_1467380390\\build\\src\\obj-firefox\\python\\manifest', 2), 'add', '', 'bar/*')
14:53:01     INFO - Diff is 1308 characters long. Set self.maxDiff to None to see it.
14:53:01     INFO - TEST-PASS | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestPreprocessManifest.test_preprocess_manifest_missing_define
14:53:01     INFO - TEST-PASS | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestSimpleManifestSink.test_simple_manifest_parser
14:53:01     INFO - TEST-PASS | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestSimplePackager.test_simple_packager
14:53:01     INFO - TEST-PASS | z:/Task_1467380390/build/src/python/mozbuild/mozpack/test/test_packager.py | TestSimplePackager.test_simple_packager_manifest_consistency
14:53:01     INFO - z:/Task_1467380390/build/src/config/rules.mk:110: recipe for target 'mozbuild/mozpack/test/test_packager.py-run' failed
14:53:01     INFO - mozmake[1]: *** [mozbuild/mozpack/test/test_packager.py-run] Error 1

I am going to work around this now by changing the build workspace to not include any upper case letters because I don't know how long it will take to find all the methods that fail because of the path casing.
https://hg.mozilla.org/try/rev/aa1a84d2886f4537afefebc1e72305e953391b6c
That's a solid plan. File a new bug on doing that? This one is pretty cluttered. (You could also file a bug on that test failure if you want, what a pain.)
Note, it isn't so critical any more to fix this in the build system; I've updated the generic worker in release https://github.com/taskcluster/generic-worker/releases/tag/v3.0.0alpha1 to use task_<timestamp> rather than Task_<timestamp> and we can go live with that instead...

I slipped upgrading the generic worker in the win2012 worker type into bug 1283858.
error from comment 37 moved to bug 1283917. marking this as fixed since the patches by ted and gps resolved the original error
Status: REOPENED → RESOLVED
Closed: 8 years ago → 8 years ago
Resolution: --- → FIXED
Product: Core → Firefox Build System
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: