% time hg --profile push --debug --verbose -t riastradh-test20251021 ssh://hg.test.netbsd.org/pkgsrc@draft pushing to ssh://hg.test.netbsd.org/pkgsrc%40draft running /home/riastradh/scripts/cvs-rsh/nbssh.sh hg.test.netbsd.org 'hg -R pkgsrc@draft serve --stdio' sending hello command sending between command remote: 635 remote: capabilities: _evoext_getbundle_obscommon _evoext_obshashrange_v1 _exttopics_heads batch branchmap bundle2=HG20%0Abookmarks%0Achangegroup%3D01%2C02%2C03%0Acheckheads%3Drelated%0Adigests%3Dmd5%2Csha1%2Csha512%0Aerror%3Dabort%2Cunsupportedcontent%2Cpushraced%2Cpushkey%0Ahgtagsfnodes%0Alistkeys%0Aobsmarkers%3DV0%2CV1%0Aphases%3Dheads%0Apushkey%0Aremote-changegroup%3Dhttp%2Chttps%0Astream%3Dv2 changegroupsubset ext-topics-publish=none ext-topics-tns-heads getbundle known lookup protocaps pushkey streamreqs=generaldelta,revlog-compression-zstd,revlogv1,sparserevlog topics topics-namespaces unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash remote: 1 sending protocaps command query 1; heads sending batch command searching for changes taking initial sample query 2; still undecided: 1911, sample size is: 200 sending known command 2 total queries in 1.9714s preparing listkeys for "phases" sending listkeys command received listkey for "phases": 42 bytes preparing listkeys for "namespaces" sending listkeys command received listkey for "namespaces": 40 bytes query 0; sample size is 100, largest range 428090 sending evoext_obshashrange_v1 command query 1; add more sample (target 200, current 9) query 1; sample size is 200, largest range 434426 sending evoext_obshashrange_v1 command obsdiscovery, 0/456184 mismatch - 2 obshashrange queries in 24.6548 seconds checking for updated bookmarks preparing listkeys for "bookmarks" sending listkeys command received listkey for "bookmarks": 0 bytes preparing listkeys for "namespaces" sending listkeys command received listkey for "namespaces": 40 bytes preparing listkeys for "phases" sending listkeys command received listkey for "phases": 42 bytes sending branchmap command preparing listkeys for "bookmarks" sending listkeys command received listkey for "bookmarks": 0 bytes 1 changesets found list of changesets: a0063143f0ff8e87affdff7567d9f69f831d2f95 sending unbundle command bundle2-output-bundle: "HG20", 4 parts total bundle2-output-part: "replycaps" 227 bytes payload bundle2-output-part: "check:phases" 48 bytes payload bundle2-output-part: "changegroup" (params: 1 mandatory) streamed payload bundle2-output-part: "obsmarkers" streamed payload remote: adding changesets remote: adding manifests remote: adding file changes remote: checking encoding/normalization/case-sensitivity... remote: 0.267579 sec to check encoding/normalization/case-sensitivity remote: no encoding/normalization/case-sensitivity trouble found remote: added 1 changesets with 1 changes to 1 files (+1 heads) remote: 1 new obsolescence markers remote: obsoleted 1 changesets bundle2-input-bundle: no-transaction bundle2-input-part: "reply:changegroup" (advisory) (params: 0 advisory) supported bundle2-input-part: "reply:obsmarkers" (params: 0 advisory) supported bundle2-input-bundle: 2 parts total preparing listkeys for "phases" sending listkeys command received listkey for "phases": 85 bytes remote: | 100.0% 93.67s hg: line 61: dispatch.run() remote: | 100.0% 93.67s dispatch.py: run line 143: status = dispatch(req) remote: | 100.0% 93.67s dispatch.py: dispatch line 232: status = _rundispatch(req) remote: | 100.0% 93.67s dispatch.py: _rundispatch line 276: ret = _runcatch(req) or 0 remote: | 100.0% 93.67s dispatch.py: _runcatch line 457: return _callcatch(ui, _runc... remote: | 100.0% 93.67s dispatch.py: _callcatch line 467: return scmutil.callcatch(ui... remote: | 100.0% 93.67s scmutil.py: callcatch line 177: return func() remote: | 100.0% 93.67s dispatch.py: _runcatchfunc line 447: return _dispatch(req) remote: | 99.7% 93.43s dispatch.py: _dispatch line 1272: return runcommand( remote: | 99.7% 93.41s dispatch.py: runcommand line 905: ret = _runcommand(ui, optio... remote: | 99.7% 93.41s dispatch.py: _runcommand line 1284: return cmdfunc() remote: | 99.7% 93.41s dispatch.py: line 1270: d = lambda: util.checksigna... remote: | 99.7% 93.41s util.py: check line 1957: return func(*args, **kwargs) remote: | 99.7% 93.41s commands.py: serve line 6706: s.serve_forever() remote: | 99.7% 93.41s wireprotoserver.py: serve_forever line 532: self.serveuntil(threading.E... remote: | 99.7% 93.41s wireprotoserver.py: serveuntil line 551: _runsshserver( remote: \ 60.1% 56.32s wireprotoserver.py: _runsshserver line 488: rsp = wireprotov1server.dis... remote: | 55.4% 51.88s wireprotov1server.py: dispatch line 92: return func(repo, proto, *a... remote: | 54.2% 50.73s wireprotov1server.py: unbundle line 722: r = exchange.unbundle( remote: | 51.1% 47.85s exchange.py: unbundle line 2823: lockandtr[2].close() remote: | 51.1% 47.85s transaction.py: _active line 41: return func(self, *args, **... remote: | 51.0% 47.81s transaction.py: close line 756: self._postclosecallback[cat... remote: | 51.0% 47.81s localrepo.py: updater line 2891: repo.updatecaches(tr) remote: | 51.0% 47.81s localrepo.py: wrapper line 246: return orig(repo.unfiltered... remote: | 51.0% 47.80s obscache.py: updatecaches line 519: super(obscacherepo, self).u... remote: | 51.0% 47.80s localrepo.py: wrapper line 246: return orig(repo.unfiltered... remote: | 50.0% 46.83s firstmergecache.py: updatecaches, line 64: super(firstmergecacherepo, ... remote: | 50.0% 46.83s localrepo.py: wrapper line 246: return orig(repo.unfiltered... remote: | 48.9% 45.82s depthcache.py: updatecaches line 91: super(depthcacherepo, self)... remote: | 48.9% 45.82s localrepo.py: wrapper line 246: return orig(repo.unfiltered... remote: | 48.1% 45.04s stablesort.py: updatecaches line 971: super(stablesortrepo, self)... remote: | 48.1% 45.04s localrepo.py: wrapper line 246: return orig(repo.unfiltered... remote: | 48.0% 44.99s stablerangecache.py: updatecaches, line 535: self.stablerange.update(self) remote: | 48.0% 44.99s genericcaches.py: update line 122: self._updatefrom(repo, data) remote: | 48.0% 44.97s stablerangecache.py: _updatefrom, line 112: for sub in self.subranges(r... remote: | 48.0% 44.97s stablerange.py: subranges line 654: value = self._subranges(rep... remote: | 48.0% 44.97s stablerange.py: _subranges line 739: ret = self._slicesrangeat(r... remote: | 48.0% 44.97s stablerange.py: _slicesrangeat line 745: self._warmcachefor(repo, ra... remote: | 46.9% 43.91s stablerange.py: _warmcachefor line 729: self.subranges(repo, current) remote: | 46.9% 43.91s stablerange.py: subranges line 651: cached = self._getsub(rangeid) remote: \ 23.7% 22.23s stablerangecache.py: _getsub line 222: result = self._con.execute(... remote: \ 23.1% 21.63s stablerangecache.py: _getsub line 224: value = self._con.execute(_... remote: \ 39.6% 37.06s wireprotoserver.py: _runsshserver line 471: request = fin.readline()[:-1] remote: --- remote: Sample count: 4532 remote: Total time: 48.610000 seconds (93.690000 wall) | 100.0% 101.10s hg: line 59: dispatch.run() | 100.0% 101.10s dispatch.py: run line 142: status = dispatch(req) | 100.0% 101.10s dispatch.py: dispatch line 231: status = _rundispatch(req) | 100.0% 101.10s dispatch.py: _rundispatch line 275: ret = _runcatch(req) or 0 | 100.0% 101.10s dispatch.py: _runcatch line 456: return _callcatch(ui, _runc... | 100.0% 101.10s dispatch.py: _callcatch line 466: return scmutil.callcatch(ui... | 100.0% 101.10s scmutil.py: callcatch line 152: return func() | 100.0% 101.10s dispatch.py: _runcatchfunc line 446: return _dispatch(req) | 99.3% 100.42s dispatch.py: _dispatch line 1271: return runcommand( | 99.3% 100.42s __init__.py: runcommand line 577: return orig(lui, repo, *arg... | 99.3% 100.42s dispatch.py: runcommand line 904: ret = _runcommand(ui, optio... | 99.3% 100.42s dispatch.py: _runcommand line 1283: return cmdfunc() | 99.3% 100.42s dispatch.py: line 1269: d = lambda: util.checksigna... | 99.3% 100.42s util.py: check line 1898: return func(*args, **kwargs) | 99.3% 100.42s util.py: check line 1898: return func(*args, **kwargs) | 99.3% 100.35s __init__.py: pushoutgoingwrap line 1683: return orig(ui, repo, *args... | 99.3% 100.35s util.py: check line 1898: return func(*args, **kwargs) | 99.3% 100.35s util.py: check line 1898: return func(*args, **kwargs) | 99.3% 100.35s flow.py: wrappush line 118: return orig(repo, remote, *... | 99.3% 100.35s util.py: check line 1898: return func(*args, **kwargs) \ 91.1% 92.16s commands.py: push line 5873: pushop = exchange.push( | 91.1% 92.16s __init__.py: push line 581: return orig(repo, *args, **... \ 56.1% 56.72s exchange.py: push line 524: _pushbundle2(pushop) | 51.6% 52.17s exchange.py: _pushbundle2, line 1224: reply = e.callcommand( | 51.6% 52.17s server.py: callcommand line 148: return s.callcommand(comman... | 51.6% 52.17s wireprotov1peer.py: callcommand, line 175: self.sendcommands() | 51.6% 52.17s wireprotov1peer.py: sendcommands, line 208: result = fn(**pycompat.strk... | 50.9% 51.42s wireprotov1peer.py: unbundle, line 515: ret = bundle2.getunbundler(... | 50.9% 51.42s bundle2.py: getunbundler, line 811: magicstring = changegroup.r... | 50.9% 51.42s util.py: readexactly line 3197: s = stream.read(n) | 50.9% 51.42s sshpeer.py: read line 97: r = self._call(b'read', size) | 50.9% 51.42s sshpeer.py: _call line 128: mainready, sideready = self... | 50.9% 51.42s sshpeer.py: _wait line 87: act = util.poll(fds) | 50.9% 51.42s posix.py: poll line 761: res = select.select(fds, fd... \ 34.4% 34.74s exchange.py: push line 520: _pushdiscovery(pushop) | 34.4% 34.74s exchange.py: _pushdiscovery, line 572: step(pushop) | 31.0% 31.33s obsdiscovery.py: newdisco line 817: _pushdiscoveryobsmarkers(ol... | 24.4% 24.66s obsdiscovery.py: _pushdiscoveryobsmarkers, line 802: nodes = discovery(pushop, c... | 24.4% 24.66s obsdiscovery.py: _pushobshashrange, line 754: missing = findmissingrange(... | 18.3% 18.51s obsdiscovery.py: findmissingrange, line 78: local.stablerange.warmup(lo... | 18.3% 18.51s localrepo.py: __get__ line 220: return super(unfilteredprop... | 18.3% 18.51s util.py: __get__ line 1766: result = self.func(obj) | 18.3% 18.51s stablerangecache.py: stablerange, line 522: cache.update(self) | 18.3% 18.51s genericcaches.py: update line 122: self._updatefrom(repo, data) | 18.3% 18.51s stablerangecache.py: _updatefrom, line 112: for sub in self.subranges(r... | 18.3% 18.50s stablerange.py: subranges line 654: value = self._subranges(rep... | 17.7% 17.90s stablerange.py: _subranges line 739: ret = self._slicesrangeat(r... | 17.7% 17.90s stablerange.py: _slicesrangeat, line 745: self._warmcachefor(repo, ra... | 16.3% 16.44s stablerange.py: _warmcachefor, line 729: self.subranges(repo, current) | 16.3% 16.44s stablerange.py: subranges line 651: cached = self._getsub(rangeid) \ 8.5% 8.64s stablerangecache.py: _getsub, line 224: value = self._con.execute(_... \ 7.7% 7.79s stablerangecache.py: _getsub, line 222: result = self._con.execute(... \ 5.7% 5.78s commands.py: push line 5828: other = hg.peer(repo, opts,... | 5.7% 5.78s discovery.py: wraphgpeer line 369: peer = orig(uiorrepo, opts,... | 5.7% 5.78s hg.py: peer line 264: peer = cls.make_peer( | 5.0% 5.07s sshpeer.py: make_peer line 694: peer = _make_peer( | 5.0% 5.06s sshpeer.py: _make_peer line 610: protoname, caps = _performh... | 5.0% 5.06s sshpeer.py: _performhandshake, line 323: l = stdout.readline() --- Sample count: 44523 Total time: 37.281000 seconds (101.110000 wall) hg --profile push --debug --verbose -t riastradh-test20251021 42.32s user 5.95s system 42% cpu 1:52.30 total