1716523 - [Trees closed] cloning latest streambundle fails: KeyError: 'h'

Status: RESOLVED FIXED

(Developer Services :: Mercurial: hg.mozilla.org, defect, P1)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Cloning the latest hg stream bundle fails on new workers:

https://treeherder.mozilla.org/logviewer?job_id=342807348&repo=autoland

[taskcluster 2021-06-15 09:24:20.228Z] === Task Starting ===
[setup 2021-06-15T09:24:20.609Z] run-task started in /
[cache 2021-06-15T09:24:20.610Z] cache /builds/worker/checkouts exists; requirements: gid=1000 uid=1000 version=1
[setup 2021-06-15T09:24:20.611Z] running as worker:worker
[vcs 2021-06-15T09:24:20.611Z] fetching hgmointernal config from http://taskcluster/secrets/v1/secret/project/taskcluster/gecko/hgmointernal
[vcs 2021-06-15T09:24:20.741Z] hgmointernal rate miss; using public hg.mozilla.org service
[vcs 2021-06-15T09:24:20.741Z] executing ['hg', 'robustcheckout', '--sharebase', '/builds/worker/checkouts/hg-store', '--purge', '--upstream', 'https://hg.mozilla.org/mozilla-unified', '--sparseprofile', 'build/sparse-profiles/taskgraph', '--revision', 'ad764709ec0f976a4061e61e7c9e15e5f19e5c40', 'https://hg.mozilla.org/integration/autoland', '/builds/worker/checkouts/gecko']
[vcs 2021-06-15T09:24:20.794Z] (using Mercurial 4.8.1)
[vcs 2021-06-15T09:24:20.794Z] ensuring https://hg.mozilla.org/integration/autoland@ad764709ec0f976a4061e61e7c9e15e5f19e5c40 is available at /builds/worker/checkouts/gecko
[vcs 2021-06-15T09:24:21.634Z] (cloning from upstream repo https://hg.mozilla.org/mozilla-unified)
[vcs 2021-06-15T09:24:22.421Z] (sharing from new pooled repository 8ba995b74e18334ab3707f27e9eb8f4e37ba3d29)
[vcs 2021-06-15T09:24:23.755Z] applying clone bundle from https://s3-external-1.amazonaws.com/moz-hg-bundles-us-east-1/mozilla-unified/12e357e1bf9511b86dbd302c8c3fa0caf69e3768.stream-v2.hg
[vcs 2021-06-15T09:24:23.945Z] 623946 files to transfer, 3.77 GB of data
[vcs 2021-06-15T09:24:25.946Z] 
[vcs 2021-06-15T09:24:26.946Z] clone [>                                          ]  105368216/4048212963 1m15s

...

[vcs 2021-06-15T09:25:11.019Z] clone [=====================>                       ] 2018091434/4048212963 47s
[vcs 2021-06-15T09:25:55.038Z] clone [=====================>                       ] 2051216460/4048212963 46s
[vcs 2021-06-15T09:25:55.038Z] PERFHERDER_DATA: {"framework": {"name": "vcs"}, "suites": [{"extraOptions": ["c5d.xlarge"], "hgVersion": "4.8.1", "lowerIsBetter": true, "name": "clone_errored", "serverUrl": "hg.mozilla.org", "shouldAlert": false, "subtests": [], "value": 93.40205502510071}, {"extraOptions": ["c5d.xlarge"], "hgVersion": "4.8.1", "lowerIsBetter": true, "name": "overall", "serverUrl": "hg.mozilla.org", "shouldAlert": false, "subtests": [], "value": 94.24248600006104}, {"extraOptions": ["c5d.xlarge"], "hgVersion": "4.8.1", "lowerIsBetter": true, "name": "overall_clone", "serverUrl": "hg.mozilla.org", "shouldAlert": false, "subtests": [], "value": 94.24248600006104}, {"extraOptions": ["c5d.xlarge"], "hgVersion": "4.8.1", "lowerIsBetter": true, "name": "overall_clone_fullcheckout", "serverUrl": "hg.mozilla.org", "shouldAlert": false, "subtests": [], "value": 94.24248600006104}]}
[vcs 2021-06-15T09:25:55.040Z] ** unknown exception encountered, please report by visiting
[vcs 2021-06-15T09:25:55.040Z] ** https://mercurial-scm.org/wiki/BugTracker
[vcs 2021-06-15T09:25:55.040Z] ** Python 2.7.17 (default, Feb 27 2021, 15:10:58) [GCC 7.5.0]
[vcs 2021-06-15T09:25:55.040Z] ** Mercurial Distributed SCM (version 4.8.1)
[vcs 2021-06-15T09:25:55.040Z] ** Extensions loaded: share, sparse, robustcheckout, histedit, rebase, purge
[vcs 2021-06-15T09:25:55.040Z] Traceback (most recent call last):
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/bin/hg", line 43, in <module>
[vcs 2021-06-15T09:25:55.040Z]     dispatch.run()
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 96, in run
[vcs 2021-06-15T09:25:55.040Z]     status = dispatch(req)
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 220, in dispatch
[vcs 2021-06-15T09:25:55.040Z]     ret = _runcatch(req) or 0
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 363, in _runcatch
[vcs 2021-06-15T09:25:55.040Z]     return _callcatch(ui, _runcatchfunc)
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 371, in _callcatch
[vcs 2021-06-15T09:25:55.040Z]     return scmutil.callcatch(ui, func)
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/scmutil.py", line 166, in callcatch
[vcs 2021-06-15T09:25:55.040Z]     return func()
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 354, in _runcatchfunc
[vcs 2021-06-15T09:25:55.040Z]     return _dispatch(req)
[vcs 2021-06-15T09:25:55.040Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 994, in _dispatch
[vcs 2021-06-15T09:25:55.040Z]     cmdpats, cmdoptions)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 737, in runcommand
[vcs 2021-06-15T09:25:55.041Z]     ret = _runcommand(ui, options, cmd, d)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 1003, in _runcommand
[vcs 2021-06-15T09:25:55.041Z]     return cmdfunc()
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/dispatch.py", line 991, in <lambda>
[vcs 2021-06-15T09:25:55.041Z]     d = lambda: util.checksignature(func)(ui, *args, **strcmdopt)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/util.py", line 1644, in check
[vcs 2021-06-15T09:25:55.041Z]     return func(*args, **kwargs)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/local/mercurial/robustcheckout.py", line 215, in robustcheckout
[vcs 2021-06-15T09:25:55.041Z]     noupdate=noupdate,
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/local/mercurial/robustcheckout.py", line 616, in _docheckout
[vcs 2021-06-15T09:25:55.041Z]     stream=True,
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/hg.py", line 640, in clone
[vcs 2021-06-15T09:25:55.041Z]     stream=stream)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/hg.py", line 445, in clonewithshare
[vcs 2021-06-15T09:25:55.041Z]     revs=rev, update=False, stream=stream)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/hg.py", line 756, in clone
[vcs 2021-06-15T09:25:55.041Z]     depth=depth)
[vcs 2021-06-15T09:25:55.041Z]   File "/usr/lib/python2.7/dist-packages/mercurial/exchange.py", line 1524, in pull
[vcs 2021-06-15T09:25:55.042Z]     _maybeapplyclonebundle(pullop)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/exchange.py", line 2452, in _maybeapplyclonebundle
[vcs 2021-06-15T09:25:55.042Z]     if trypullbundlefromurl(repo.ui, repo, url):
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/exchange.py", line 2648, in trypullbundlefromurl
[vcs 2021-06-15T09:25:55.042Z]     bundle2.applybundle(repo, cg, tr, 'clonebundles', url)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/bundle2.py", line 353, in applybundle
[vcs 2021-06-15T09:25:55.042Z]     return processbundle(repo, unbundler, lambda: tr, source=source)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/bundle2.py", line 460, in processbundle
[vcs 2021-06-15T09:25:55.042Z]     processparts(repo, op, unbundler)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/bundle2.py", line 467, in processparts
[vcs 2021-06-15T09:25:55.042Z]     _processpart(op, part)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/bundle2.py", line 534, in _processpart
[vcs 2021-06-15T09:25:55.042Z]     handler(op, part)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/bundle2.py", line 2289, in handlestreamv2bundle
[vcs 2021-06-15T09:25:55.042Z]     requirements)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/streamclone.py", line 654, in applybundlev2
[vcs 2021-06-15T09:25:55.042Z]     consumev2(repo, fp, filecount, filesize)
[vcs 2021-06-15T09:25:55.042Z]   File "/usr/lib/python2.7/dist-packages/mercurial/streamclone.py", line 618, in consumev2
[vcs 2021-06-15T09:25:55.042Z]     vfs = vfsmap[src]
[vcs 2021-06-15T09:25:55.042Z] KeyError: 'h'

Comment 1

[Mike Hommey [:glandium]]

This is somewhat reproducible outside of automation with hg clone --stream https://hg.mozilla.org/mozilla-unified (it freezes rather than fail), but not with mozilla-central. I guess the stream bundle for unified is busted.

Comment 2

[Mike Hommey [:glandium]]

(In reply to Mike Hommey [:glandium] from comment #1)

(it freezes rather than fail)

Actually, after a while it does fail with the same KeyError message.

Comment 3

[Pierre-Yves David]

If you generate a new streaming clone (keeping the old one around), do you still see the error ?

Comment 4

[Connor Sheehan [:sheehan]]

Rolled back to yesterday's bundle built from changeset e77eb14241b9e712ddda1e8c1cc21ef455377e3c. After which running hg clone --stream https://hg.mozilla.org/mozilla-unified completes successfully. I think we should be OK to re-open trees.

I'm looking into whether this was just one bad bundle or some other bug.

Comment 5

[Connor Sheehan [:sheehan]]

Yesterday's bundle generation failed due to a permissions error copying around the manifest file (my fault). Today's bundle based on 72de1a61b74961add0c99217078eed8d16e4e7a7 looks to be working without issue.

Comment 6

[Intermittent Failures Robot]

140 failures in 2888 pushes (0.048 failures/push) were associated with this bug in the last 7 days.

This is the #3 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 1
• mozilla-central: 139

Platform and build breakdown:

• osx-shippable: 23
  • opt: 23
• gecko-decision: 7
  • opt: 7
• linux32-shippable: 22
  • opt: 22
• windows2012-64-shippable: 22
  • opt: 22
• windows2012-aarch64-shippable: 22
  • opt: 22
• windows2012-32-shippable: 22
  • opt: 22
• linux64-shippable: 22
  • opt: 22

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1716523&startday=2021-06-14&endday=2021-06-20&tree=all