Closed Bug 1909904 Opened 4 months ago Closed 4 months ago

Intermittent FileNotFoundError: [Errno 2] No such file or directory: 'hg'

Categories

(Infrastructure & Operations :: RelOps: Posix OS, defect, P1)

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Assigned: rcurran)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=467907528&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/HILSl3_EQ6iKrT1QYg1oJQ/runs/0/artifacts/public/logs/live_backing.log


[taskcluster 2024-07-25T14:07:40.489Z] Worker Type (releng-hardware/gecko-t-osx-1015-r8) settings:
[taskcluster 2024-07-25T14:07:40.489Z]   {
[taskcluster 2024-07-25T14:07:40.489Z]     "arch": "x86_64",
[taskcluster 2024-07-25T14:07:40.489Z]     "config": {
[taskcluster 2024-07-25T14:07:40.489Z]       "deploymentId": ""
[taskcluster 2024-07-25T14:07:40.489Z]     },
[taskcluster 2024-07-25T14:07:40.489Z]     "disk_size": "233.47 GiB",
[taskcluster 2024-07-25T14:07:40.489Z]     "generic-worker": {
[taskcluster 2024-07-25T14:07:40.489Z]       "engine": "simple",
[taskcluster 2024-07-25T14:07:40.489Z]       "go-arch": "amd64",
[taskcluster 2024-07-25T14:07:40.489Z]       "go-os": "darwin",
[taskcluster 2024-07-25T14:07:40.489Z]       "go-version": "go1.22.0",
[taskcluster 2024-07-25T14:07:40.489Z]       "release": "https://github.com/taskcluster/taskcluster/releases/tag/v60.3.4",
[taskcluster 2024-07-25T14:07:40.489Z]       "revision": "943a6f2b0d14fa0270280bc6f23acc2945d0fe45",
[taskcluster 2024-07-25T14:07:40.489Z]       "source": "https://github.com/taskcluster/taskcluster/commits/943a6f2b0d14fa0270280bc6f23acc2945d0fe45",
[taskcluster 2024-07-25T14:07:40.489Z]       "version": "60.3.4"
[taskcluster 2024-07-25T14:07:40.489Z]     },
[taskcluster 2024-07-25T14:07:40.489Z]     "ip": "10.49.58.108",
[taskcluster 2024-07-25T14:07:40.489Z]     "machine-setup": {
[taskcluster 2024-07-25T14:07:40.489Z]       "config": "https://github.com/mozilla-platform-ops/ronin_puppet"
[taskcluster 2024-07-25T14:07:40.489Z]     },
[taskcluster 2024-07-25T14:07:40.489Z]     "memory": "16 GB",
[taskcluster 2024-07-25T14:07:40.489Z]     "model_identifier": "Macmini8,1",
[taskcluster 2024-07-25T14:07:40.489Z]     "processor_cores": "6",
[taskcluster 2024-07-25T14:07:40.489Z]     "processor_count": "1",
[taskcluster 2024-07-25T14:07:40.489Z]     "processor_name": "6-Core Intel Core i7",
[taskcluster 2024-07-25T14:07:40.489Z]     "processor_speed": "3.2 GHz",
[taskcluster 2024-07-25T14:07:40.489Z]     "system_version": "macOS 10.15.7 (19H524)",
[taskcluster 2024-07-25T14:07:40.489Z]     "workerGroup": "mdc1",
[taskcluster 2024-07-25T14:07:40.489Z]     "workerId": "macmini-r8-6"
[taskcluster 2024-07-25T14:07:40.489Z]   }
[taskcluster 2024-07-25T14:07:40.489Z] Task ID: HILSl3_EQ6iKrT1QYg1oJQ
[taskcluster 2024-07-25T14:07:40.489Z] === Task Starting ===
[taskcluster 2024-07-25T14:07:41.847Z] Uploading redirect artifact public/logs/live.log to URL https://firefoxci-websocktunnel.services.mozilla.com/mdc1.macmini-r8-6.60099/log/SUFQRbzsQsaqqtU1mTQoYw with mime type "text/plain; charset=utf-8" and expiry 2024-07-25T15:22:41.801Z
[taskcluster 2024-07-25T14:07:41.890Z] [mounts] Moving existing writable directory cache gecko-level-3-checkouts from /opt/worker/cache/MO0QXLefRDukRKeOk0I0Mg to /opt/worker/tasks/task_172191645932799/checkouts
[taskcluster 2024-07-25T14:07:41.890Z] [mounts] Creating directory /opt/worker/tasks/task_172191645932799
[taskcluster 2024-07-25T14:07:41.891Z] [mounts] Successfully mounted writable directory cache '/opt/worker/tasks/task_172191645932799/checkouts'
[taskcluster 2024-07-25T14:07:41.891Z] [mounts] Downloading url http://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JYF5PankR4efJpVlIkwF3g/artifacts/public/run-task to /opt/worker/downloads/VjF1dFWJQ0i1-CeJLBIxIw
[taskcluster 2024-07-25T14:07:42.105Z] [mounts] Downloaded 36057 bytes with SHA256 df928252a170103b7408804522b94b04ecfe3bd04e3a83df87bab3fdb7ed4b36 from url http://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JYF5PankR4efJpVlIkwF3g/artifacts/public/run-task to /opt/worker/downloads/VjF1dFWJQ0i1-CeJLBIxIw
[taskcluster:warn 2024-07-25T14:07:42.105Z] [mounts] Download /opt/worker/downloads/VjF1dFWJQ0i1-CeJLBIxIw of url http://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JYF5PankR4efJpVlIkwF3g/artifacts/public/run-task has SHA256 df928252a170103b7408804522b94b04ecfe3bd04e3a83df87bab3fdb7ed4b36 but task payload does not declare a required value, so content authenticity cannot be verified
[taskcluster 2024-07-25T14:07:42.105Z] [mounts] Creating directory /opt/worker/tasks/task_172191645932799
[taskcluster 2024-07-25T14:07:42.106Z] [mounts] Copying /opt/worker/downloads/VjF1dFWJQ0i1-CeJLBIxIw to /opt/worker/tasks/task_172191645932799/run-task
[taskcluster 2024-07-25T14:07:42.151Z] Executing command 0: chmod '+x' run-task
[taskcluster 2024-07-25T14:07:42.161Z]    Exit Code: 0
[taskcluster 2024-07-25T14:07:42.161Z]    User Time: 403µs
[taskcluster 2024-07-25T14:07:42.161Z]  Kernel Time: 1.261ms
[taskcluster 2024-07-25T14:07:42.161Z]    Wall Time: 9.061ms
[taskcluster 2024-07-25T14:07:42.161Z]       Result: SUCCEEDED
[taskcluster 2024-07-25T14:07:42.162Z] Executing command 1: /usr/local/bin/python3 run-task '--gecko-checkout=./checkouts/gecko' --task-cwd checkouts/gecko -- bash -cx 'LC_ALL=en_US.UTF-8 LANG=en_US.UTF-8 python3 ./mach python-test --subsuite mach --run-slow'
[setup 2024-07-25T14:07:42.532Z] run-task started in /opt/worker/tasks/task_172191645932799
[vcs 2024-07-25T14:07:42.546Z] WARNING: vcs checkout path (./checkouts/gecko) not in cache or volume; performance will likely suffer
[vcs 2024-07-25T14:07:42.546Z] WARNING: HG_STORE_PATH (./checkouts/hg-shared) not in cache or volume; performance will likely suffer
[vcs 2024-07-25T14:07:42.546Z] TASKCLUSTER_WORKER_LOCATION missing required keys; using public hg.mozilla.org service
[vcs 2024-07-25T14:07:42.546Z] executing ['hg', 'robustcheckout', '--sharebase', '/opt/worker/tasks/task_172191645932799/checkouts/hg-shared', '--purge', '--upstream', 'https://hg.mozilla.org/mozilla-unified', '--revision', 'cfa2a54bceaefd93b284e5b44aeaba41a47a5608', 'https://hg.mozilla.org/integration/autoland', '/opt/worker/tasks/task_172191645932799/checkouts/gecko']
Traceback (most recent call last):
  File "/opt/worker/tasks/task_172191645932799/run-task", line 958, in <module>
    sys.exit(main(sys.argv[1:]))
             ^^^^^^^^^^^^^^^^^^
  File "/opt/worker/tasks/task_172191645932799/run-task", line 891, in main
    vcs_checkout_from_args(args, 'gecko')
  File "/opt/worker/tasks/task_172191645932799/run-task", line 675, in vcs_checkout_from_args
    os.environ['%s_HEAD_REV' % options['env-prefix']] = vcs_checkout(
                                                        ^^^^^^^^^^^^^
  File "/opt/worker/tasks/task_172191645932799/run-task", line 476, in vcs_checkout
    res = run_and_prefix_output(b'vcs', args,
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/worker/tasks/task_172191645932799/run-task", line 139, in run_and_prefix_output
    p = subprocess.Popen(args,
        ^^^^^^^^^^^^^^^^^^^^^^
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/subprocess.py", line 1022, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/Library/Frameworks/Python.framework/Versions/3.11/lib/python3.11/subprocess.py", line 1899, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
FileNotFoundError: [Errno 2] No such file or directory: 'hg'
[taskcluster 2024-07-25T14:07:42.558Z]    Exit Code: 1
[taskcluster 2024-07-25T14:07:42.558Z]    User Time: 55.596ms
[taskcluster 2024-07-25T14:07:42.558Z]  Kernel Time: 55.233ms
[taskcluster 2024-07-25T14:07:42.558Z]    Wall Time: 396.028ms
[taskcluster 2024-07-25T14:07:42.558Z]       Result: FAILED
[taskcluster 2024-07-25T14:07:42.558Z] === Task Finished ===
[taskcluster 2024-07-25T14:07:42.558Z] Task Duration: 406.396ms
[taskcluster 2024-07-25T14:07:42.558Z] [mounts] Preserving cache: Moving "/opt/worker/tasks/task_172191645932799/checkouts" to "/opt/worker/cache/MO0QXLefRDukRKeOk0I0Mg"
[taskcluster 2024-07-25T14:07:42.605Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2025-07-25T13:55:25.808Z
[taskcluster:error] exit status 1

We've been rolling out an updated version of mercurial that relies on Python3 vs Python2 on r8:1-40 per RELOPS-1005

[relops@macmini-r8-6.test.releng.mdc1.mozilla.com ~]$ which hg
/Library/Frameworks/Python.framework/Versions/3.11/bin/hg

[relops@macmini-r8-6.test.releng.mdc1.mozilla.com ~]$ hg --version
Mercurial Distributed SCM (version 6.4.5)
(see https://mercurial-scm.org for more information)

Copyright (C) 2005-2023 Olivia Mackall and others
This is free software; see the source for copying conditions. There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
[relops@macmini-r8-6.test.releng.mdc1.mozilla.com ~]$ head -n 1 $(which hg)
#!/Library/Frameworks/Python.framework/Versions/3.11/bin/python3.11

Would you like us to quarantine these hosts or is there a change you can make on your end :jcristau

Flags: needinfo?(jcristau)

I'm not sure what change I could do, so I guess I'll ask:

  1. where does hg live?
  2. what is the new hg shebang?
  3. where does python3 live?
Flags: needinfo?(jcristau) → needinfo?(rcurran)

[relops@macmini-r8-6.test.releng.mdc1.mozilla.com ~]$ which hg
/Library/Frameworks/Python.framework/Versions/3.11/bin/hg

[relops@macmini-r8-6.test.releng.mdc1.mozilla.com ~]$ which python3
/usr/local/bin/python

Flags: needinfo?(rcurran)

r8:1-40 have been quarantined

symlink fix rolling out to affected nodes

AFAICT the failing tasks set PATH to /usr/local/bin:/bin:/sbin:/usr/bin:/usr/sbin (https://searchfox.org/mozilla-central/rev/d353cfa1fbd207e13dc974f30e5f88535a4303ae/taskcluster/gecko_taskgraph/transforms/job/mozharness_test.py#358), which doesn't include the new location for hg.
Ryan's fix at https://github.com/mozilla-platform-ops/ronin_puppet/pull/698 should work fix this for now, but we should probably also look at removing that PATH setting from gecko_taskgraph if possible.

Regressed by: 1626357
Status: NEW → RESOLVED
Closed: 4 months ago
Keywords: regression
Resolution: --- → FIXED
Severity: S4 → --
Component: Task Configuration → RelOps: Posix OS
Priority: P5 → P1
Product: Firefox Build System → Infrastructure & Operations
Assignee: nobody → rcurran
You need to log in before you can comment on or make changes to this bug.