1644283 - Perma [tier2] python/mozbuild/mozpack/test/test_files.py::TestMercurialRevisionFinder::test_default_revision TEST-UNEXPECTED-FAIL

Status: RESOLVED FIXED

(Firefox Build System :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: gbrown [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=305522844&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/CNxIurvRRX6JoZSs6nj8Fw/runs/0/artifacts/public/logs/live_backing.log

---

Noticed while investigating bug 1516847, but apparently unrelated to that bug.

Comment 1

[Geoff Brown [:gbrown]]

[task 2020-06-08T20:44:41.214Z]  1:59.24 python/mozbuild/mozpack/test/test_files.py::TestMercurialRevisionFinder::test_default_revision TEST-UNEXPECTED-FAIL
[task 2020-06-08T20:44:41.214Z]  1:59.24 python/mozbuild/mozpack/test/test_files.py::TestMercurialRevisionFinder::test_old_revision TEST-UNEXPECTED-FAIL
[task 2020-06-08T20:44:41.214Z]  1:59.24 python/mozbuild/mozpack/test/test_files.py::TestMercurialRevisionFinder::test_recognize_repo_paths TEST-UNEXPECTED-FAIL

Comment 2

[Geoff Brown [:gbrown]]

[task 2020-06-08T20:44:41.214Z]  1:59.24 =================================== FAILURES ===================================
[task 2020-06-08T20:44:41.214Z]  1:59.24 ______________ TestMercurialRevisionFinder.test_default_revision _______________
[task 2020-06-08T20:44:41.214Z]  1:59.24 
[task 2020-06-08T20:44:41.214Z]  1:59.24 self = <mozpack.test.test_files.TestMercurialRevisionFinder testMethod=test_default_revision>
[task 2020-06-08T20:44:41.214Z]  1:59.24 
[task 2020-06-08T20:44:41.214Z]  1:59.24     def setUp(self):
[task 2020-06-08T20:44:41.214Z]  1:59.24         super(TestMercurialRevisionFinder, self).setUp()
[task 2020-06-08T20:44:41.215Z]  1:59.24 >       hglib.init(self.tmpdir)
[task 2020-06-08T20:44:41.215Z]  1:59.24 
[task 2020-06-08T20:44:41.215Z]  1:59.24 python/mozbuild/mozpack/test/test_files.py:1185:
[task 2020-06-08T20:44:41.215Z]  1:59.24 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-06-08T20:44:41.215Z]  1:59.24 
[task 2020-06-08T20:44:41.215Z]  1:59.24 dest = '/var/folders/64/xn2tpyws5bx2bnc0c1hk26z4000017/T/tmp5iUbjv', ssh = None
[task 2020-06-08T20:44:41.215Z]  1:59.24 remotecmd = None, insecure = False, encoding = None, configs = None
[task 2020-06-08T20:44:41.215Z]  1:59.24 
[task 2020-06-08T20:44:41.215Z]  1:59.24     def init(dest=None, ssh=None, remotecmd=None, insecure=False,
[task 2020-06-08T20:44:41.215Z]  1:59.24              encoding=None, configs=None):
[task 2020-06-08T20:44:41.215Z]  1:59.24         args = util.cmdbuilder('init', dest, e=ssh, remotecmd=remotecmd,
[task 2020-06-08T20:44:41.215Z]  1:59.24                                insecure=insecure)
[task 2020-06-08T20:44:41.215Z]  1:59.24 
[task 2020-06-08T20:44:41.215Z]  1:59.24         args.insert(0, HGPATH)
[task 2020-06-08T20:44:41.215Z]  1:59.24         proc = util.popen(args)
[task 2020-06-08T20:44:41.216Z]  1:59.24         out, err = proc.communicate()
[task 2020-06-08T20:44:41.220Z]  1:59.25         if proc.returncode:
[task 2020-06-08T20:44:41.220Z]  1:59.25 >           raise error.CommandError(args, proc.returncode, out, err)
[task 2020-06-08T20:44:41.220Z]  1:59.25 E           CommandError: (1, '', 'Traceback (most recent call last):\n  File "/usr/local/bin/hg", line 30, in <module>\n    from hgdemandimport import tracing\n  File "/Users/cltbld/tasks/task_1591645778/checkouts/gecko/build/mach_bootstrap.py", line 475, in __call__\n    module = self._original_import(name, globals, locals, fromlist, level)\nImportError: No module named hgdemandimport')
[task 2020-06-08T20:44:41.220Z]  1:59.25 
[task 2020-06-08T20:44:41.220Z]  1:59.25 third_party/python/python-hglib/hglib/__init__.py:22: CommandError
[task 2020-06-08T20:44:41.220Z]  1:59.25 ________________ TestMercurialRevisionFinder.test_old_revision _________________
[task 2020-06-08T20:44:41.220Z]  1:59.25 
[task 2020-06-08T20:44:41.220Z]  1:59.25 self = <mozpack.test.test_files.TestMercurialRevisionFinder testMethod=test_old_revision>
[task 2020-06-08T20:44:41.220Z]  1:59.25 
[task 2020-06-08T20:44:41.221Z]  1:59.25     def setUp(self):
[task 2020-06-08T20:44:41.221Z]  1:59.25         super(TestMercurialRevisionFinder, self).setUp()
[task 2020-06-08T20:44:41.221Z]  1:59.25 >       hglib.init(self.tmpdir)
[task 2020-06-08T20:44:41.221Z]  1:59.25 
[task 2020-06-08T20:44:41.221Z]  1:59.25 python/mozbuild/mozpack/test/test_files.py:1185:
[task 2020-06-08T20:44:41.221Z]  1:59.25 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-06-08T20:44:41.221Z]  1:59.25 
[task 2020-06-08T20:44:41.221Z]  1:59.25 dest = '/var/folders/64/xn2tpyws5bx2bnc0c1hk26z4000017/T/tmpUsDO0P', ssh = None
[task 2020-06-08T20:44:41.221Z]  1:59.25 remotecmd = None, insecure = False, encoding = None, configs = None
[task 2020-06-08T20:44:41.221Z]  1:59.25 
[task 2020-06-08T20:44:41.221Z]  1:59.25     def init(dest=None, ssh=None, remotecmd=None, insecure=False,
[task 2020-06-08T20:44:41.221Z]  1:59.25              encoding=None, configs=None):
[task 2020-06-08T20:44:41.222Z]  1:59.25         args = util.cmdbuilder('init', dest, e=ssh, remotecmd=remotecmd,
[task 2020-06-08T20:44:41.222Z]  1:59.25                                insecure=insecure)
[task 2020-06-08T20:44:41.222Z]  1:59.25 
[task 2020-06-08T20:44:41.222Z]  1:59.25         args.insert(0, HGPATH)
[task 2020-06-08T20:44:41.222Z]  1:59.25         proc = util.popen(args)
[task 2020-06-08T20:44:41.222Z]  1:59.25         out, err = proc.communicate()
[task 2020-06-08T20:44:41.222Z]  1:59.25         if proc.returncode:
[task 2020-06-08T20:44:41.222Z]  1:59.25 >           raise error.CommandError(args, proc.returncode, out, err)
[task 2020-06-08T20:44:41.222Z]  1:59.25 E           CommandError: (1, '', 'Traceback (most recent call last):\n  File "/usr/local/bin/hg", line 30, in <module>\n    from hgdemandimport import tracing\n  File "/Users/cltbld/tasks/task_1591645778/checkouts/gecko/build/mach_bootstrap.py", line 475, in __call__\n    module = self._original_import(name, globals, locals, fromlist, level)\nImportError: No module named hgdemandimport')
[task 2020-06-08T20:44:41.222Z]  1:59.25 
[task 2020-06-08T20:44:41.222Z]  1:59.25 third_party/python/python-hglib/hglib/__init__.py:22: CommandError
[task 2020-06-08T20:44:41.222Z]  1:59.25 ____________ TestMercurialRevisionFinder.test_recognize_repo_paths _____________
[task 2020-06-08T20:44:41.222Z]  1:59.25 
[task 2020-06-08T20:44:41.223Z]  1:59.25 self = <mozpack.test.test_files.TestMercurialRevisionFinder testMethod=test_recognize_repo_paths>
[task 2020-06-08T20:44:41.223Z]  1:59.25 
[task 2020-06-08T20:44:41.223Z]  1:59.25     def setUp(self):
[task 2020-06-08T20:44:41.223Z]  1:59.25         super(TestMercurialRevisionFinder, self).setUp()
[task 2020-06-08T20:44:41.223Z]  1:59.25 >       hglib.init(self.tmpdir)
[task 2020-06-08T20:44:41.223Z]  1:59.25 
[task 2020-06-08T20:44:41.223Z]  1:59.25 python/mozbuild/mozpack/test/test_files.py:1185:
[task 2020-06-08T20:44:41.223Z]  1:59.25 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2020-06-08T20:44:41.223Z]  1:59.25 
[task 2020-06-08T20:44:41.223Z]  1:59.25 dest = '/var/folders/64/xn2tpyws5bx2bnc0c1hk26z4000017/T/tmpwOM2V2', ssh = None
[task 2020-06-08T20:44:41.223Z]  1:59.25 remotecmd = None, insecure = False, encoding = None, configs = None
[task 2020-06-08T20:44:41.223Z]  1:59.25 
[task 2020-06-08T20:44:41.223Z]  1:59.25     def init(dest=None, ssh=None, remotecmd=None, insecure=False,
[task 2020-06-08T20:44:41.224Z]  1:59.25              encoding=None, configs=None):
[task 2020-06-08T20:44:41.224Z]  1:59.25         args = util.cmdbuilder('init', dest, e=ssh, remotecmd=remotecmd,
[task 2020-06-08T20:44:41.224Z]  1:59.25                                insecure=insecure)
[task 2020-06-08T20:44:41.224Z]  1:59.25 
[task 2020-06-08T20:44:41.224Z]  1:59.25         args.insert(0, HGPATH)
[task 2020-06-08T20:44:41.224Z]  1:59.25         proc = util.popen(args)
[task 2020-06-08T20:44:41.224Z]  1:59.25         out, err = proc.communicate()
[task 2020-06-08T20:44:41.224Z]  1:59.25         if proc.returncode:
[task 2020-06-08T20:44:41.224Z]  1:59.25 >           raise error.CommandError(args, proc.returncode, out, err)
[task 2020-06-08T20:44:41.224Z]  1:59.25 E           CommandError: (1, '', 'Traceback (most recent call last):\n  File "/usr/local/bin/hg", line 30, in <module>\n    from hgdemandimport import tracing\n  File "/Users/cltbld/tasks/task_1591645778/checkouts/gecko/build/mach_bootstrap.py", line 475, in __call__\n    module = self._original_import(name, globals, locals, fromlist, level)\nImportError: No module named hgdemandimport')
[task 2020-06-08T20:44:41.224Z]  1:59.25 
[task 2020-06-08T20:44:41.225Z]  1:59.25 third_party/python/python-hglib/hglib/__init__.py:22: CommandError

Comment 3

[Intermittent Failures Robot]

20 failures in 890 pushes (0.022 failures/push) were associated with this bug yesterday.

Repository breakdown:

• try: 1
• mozilla-beta: 10
• mozilla-central: 6
• autoland: 3

Platform breakdown:

• macosx1014-64: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1644283&startday=2020-06-08&endday=2020-06-08&tree=all

Comment 4

[Intermittent Failures Robot]

28 failures in 988 pushes (0.028 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 27
• mozilla-beta: 1

Platform breakdown:

• macosx1014-64: 28

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1644283&startday=2020-06-09&endday=2020-06-09&tree=all

Comment 5

[Geoff Brown [:gbrown]]

On m-c, started at
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=source-test-python-mozbuild&revision=63dc5e9b1b02b0aebd6badfe5eaef7bb9aa8f430

On autoland, started at
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=source-test-python-mozbuild&revision=99ca33aa9f725700fadf28bcb098a0b869dfa8bf
...but fails on earlier pushes if run there now.
The previous successful run was
https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedTaskRun=aNuGv6QwRsSemoi73NgGfw.0&searchStr=source-test-python-mozbuild&revision=0b63e4f9ea947f8b393086fe19a7d677a88cfca4
but retries there now fail: It looks like this was caused by an infra change, some time around June 8.

Comment 6

[Ricky Stewart]

Bug 1644320 also started popping up on June 8 and also retries of old, succeeding builds are failing today. I find it very difficult to believe they weren't caused by the same infra change.

Comment 7

[:dhouse]

It looks like the failure is:

ImportError: No module named hgdemandimport

Am I reading the log correctly?

Comment 8

[Ricky Stewart]

Yes. Note that that's not an import in mozilla-central code, but it's just part of the contents of /usr/local/bin/hg. So the hg installation on the Mac machines is currently messed up, it's importing a package that is no longer installed on the machines.

Comment 9

[:dhouse]

(In reply to Ricky Stewart from comment #8)

Yes. Note that that's not an import in mozilla-central code, but it's just part of the contents of /usr/local/bin/hg. So the hg installation on the Mac machines is currently messed up, it's importing a package that is no longer installed on the machines.

Thankyou! That helps tremendously. I though this was in the virtualenv of a task. I'll check the hg install, and test with a reinstall.

Comment 11

[Intermittent Failures Robot]

60 failures in 5211 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

This is the #22 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 1
• mozilla-beta: 11
• mozilla-central: 10
• autoland: 38

Platform breakdown:

• macosx1014-64: 60

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1644283&startday=2020-06-08&endday=2020-06-14&tree=all

Comment 12

[:dhouse]

(In reply to Ricky Stewart from comment #8)

Yes. Note that that's not an import in mozilla-central code, but it's just part of the contents of /usr/local/bin/hg. So the hg installation on the Mac machines is currently messed up, it's importing a package that is no longer installed on the machines.

:rstewart it appears this test is doing something different than other tasks as afaict this is the only task encountering this problem. Do you know if this test could be changed to fix it or who might know more about this test?

Comment 13

[Ricky Stewart]

It's not doing "something different" than other tasks, it's doing the same thing as other tasks, namely, importing hglib and doing stuff with it in order to test code in python/mozbuild/mozpack/files.py. The issue is as described above, namely, /usr/local/bin/hg is broken. We could delete the test but I'd really not like to do that just because the automation machines are broken.

Comment 14

[Ricky Stewart]

(That's my understanding of the issue, anyway. If we're really of the opinion that the automation machines are working fine, and the fault is really in m-c code, I would need a lot more information from you to elucidate why that is. As you mentioned, all the other tasks are working fine, including tasks on different OS's that test this same code, so that really does suggest a configuration problem to me.)

Comment 15

[:dhouse]

(In reply to Ricky Stewart from comment #14)

(That's my understanding of the issue, anyway. If we're really of the opinion that the automation machines are working fine, and the fault is really in m-c code, I would need a lot more information from you to elucidate why that is. As you mentioned, all the other tasks are working fine, including tasks on different OS's that test this same code, so that really does suggest a configuration problem to me.)

I think the problem is with the automation machine setup. The macos package for mercurial that we're using results in a dependence on the environment paths to include the mercurial python modules. Perhaps this is unique to our setup, or most people do not encounter it because of homebrew or python environments.

I asked about the task because it seems to be the only one with this problem. But I base that on not receiving reports of problems and task failure counts being the same as normal.

I will work on fixing the hg setup so that the paths (and finding of libdir) are correct.

Comment 16

[:dhouse]

It is fixed now on the macos automation machines. I worked around the path issue with a symlink of /Library as /usr/Library for hg to find without us changing the installer or hg script.

I ran one test against the production pool after making the symlink and confirmed it passes: https://firefox-ci-tc.services.mozilla.com/tasks/ZraUbHD4Q_2KuCSz1oB0KQ
I'll get the fix merged into our puppet configuration so we don't lose the change.

Comment 17

[Intermittent Failures Robot]

38 failures in 4035 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #46 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 28
• mozilla-beta: 3
• mozilla-central: 4
• mozilla-esr78: 3

Platform breakdown:

• macosx1014-64: 38

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1644283&startday=2020-06-15&endday=2020-06-21&tree=all

Comment 18

[:dhouse]

I applied the fix on the workers on the 17th, and it looks like the failure has not repeated.

Comment 19

[Ricky Stewart]

Yeah, I don't see it happening any more either. Thanks!!