% time hg --profile --config ui.paginate=never 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 2.2699s preparing listkeys for "phases" sending listkeys command received listkey for "phases": 128 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 22.8668 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": 128 bytes sending branchmap command preparing listkeys for "bookmarks" sending listkeys command received listkey for "bookmarks": 0 bytes 1 changesets found list of changesets: 728f1b8126be62db573bb9b2603ff34d030d625c sending unbundle command bundle2-output-bundle: "HG20", 4 parts total bundle2-output-part: "replycaps" 227 bytes payload bundle2-output-part: "check:phases" 96 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.294664 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": 171 bytes remote: | 100.0% 87.98s hg: line 51: dispatch.run() remote: | 100.0% 87.98s dispatch.py: run line 144: status = dispatch(req) remote: | 100.0% 87.98s dispatch.py: dispatch line 233: status = _rundispatch(req) remote: | 100.0% 87.98s dispatch.py: _rundispatch line 278: ret = _runcatch(req) or 0 remote: | 100.0% 87.98s dispatch.py: _runcatch line 468: return _callcatch(ui, _runc... remote: | 100.0% 87.98s dispatch.py: _callcatch line 478: return scmutil.callcatch(ui... remote: | 100.0% 87.98s scmutil.py: callcatch line 182: return func() remote: | 100.0% 87.98s dispatch.py: _runcatchfunc line 458: return _dispatch(req) remote: | 100.0% 87.98s dispatch.py: _dispatch line 1106: return _dispatch_post_cwd(req) remote: | 99.7% 87.72s dispatch.py: _dispatch_post_cwd line 1362: return runcommand( remote: | 99.7% 87.72s dispatch.py: runcommand line 975: ret = _runcommand(ui, optio... remote: | 99.7% 87.72s dispatch.py: _runcommand line 1374: return cmdfunc() remote: | 99.7% 87.72s dispatch.py: line 1360: d = lambda: util.checksigna... remote: | 99.7% 87.72s util.py: check line 1979: return func(*args, **kwargs) remote: | 99.7% 87.72s commands.py: serve line 6412: s.serve_forever() remote: | 99.7% 87.72s wireprotoserver.py: serve_forever line 531: self.serveuntil(threading.E... remote: | 99.7% 87.72s wireprotoserver.py: serveuntil line 550: _runsshserver( remote: \ 59.5% 52.35s wireprotoserver.py: _runsshserver line 487: rsp = wireprotov1server.dis... remote: \ 53.3% 46.85s wireprotov1server.py: dispatch line 92: return func(repo, proto, *a... remote: | 51.8% 45.61s wireprotov1server.py: unbundle, line 725: r = exchange.unbundle( remote: | 48.5% 42.70s exchange.py: unbundle line 2823: lockandtr[2].close() remote: | 48.5% 42.70s transaction.py: _active line 53: return func(self, *args, **... remote: | 48.5% 42.68s transaction.py: close line 797: self._postclosecallback[cat... remote: | 48.5% 42.68s localrepo.py: updater line 3015: repo.updatecaches(tr) remote: | 48.5% 42.68s localrepo.py: wrapper line 264: return orig(repo.unfiltered... remote: | 48.5% 42.68s obscache.py: updatecaches line 519: super(obscacherepo, self).u... remote: | 48.5% 42.68s localrepo.py: wrapper line 264: return orig(repo.unfiltered... remote: | 47.4% 41.74s firstmergecache.py: updatecaches, line 64: super(firstmergecacherepo, ... remote: | 47.4% 41.74s localrepo.py: wrapper line 264: return orig(repo.unfiltered... remote: | 46.3% 40.76s depthcache.py: updatecaches line 91: super(depthcacherepo, self)... remote: | 46.3% 40.76s localrepo.py: wrapper line 264: return orig(repo.unfiltered... remote: | 45.5% 40.05s stablesort.py: updatecaches line 971: super(stablesortrepo, self)... remote: | 45.5% 40.05s localrepo.py: wrapper line 264: return orig(repo.unfiltered... remote: | 45.5% 39.99s stablerangecache.py: updatecaches, line 533: self.stablerange.update(self) remote: | 45.5% 39.99s genericcaches.py: update line 122: self._updatefrom(repo, data) remote: | 45.5% 39.99s stablerangecache.py: _updatefrom, line 112: for sub in self.subranges(r... remote: | 45.5% 39.99s stablerange.py: subranges line 654: value = self._subranges(rep... remote: | 45.5% 39.99s stablerange.py: _subranges line 739: ret = self._slicesrangeat(r... remote: | 45.5% 39.99s stablerange.py: _slicesrangeat, line 745: self._warmcachefor(repo, ra... remote: | 44.4% 39.03s stablerange.py: _warmcachefor line 729: self.subranges(repo, current) remote: | 44.4% 39.03s stablerange.py: subranges line 651: cached = self._getsub(rangeid) remote: \ 22.3% 19.58s stablerangecache.py: _getsub, line 222: value = self._con.execute(_... remote: \ 22.0% 19.36s stablerangecache.py: _getsub, line 220: result = self._con.execute(... remote: \ 6.3% 5.50s wireprotov1server.py: dispatch line 90: args = proto.getargs(spec) remote: \ 40.2% 35.34s wireprotoserver.py: _runsshserver line 470: request = fin.readline()[:-1] remote: --- remote: Sample count: 4267 remote: Total time: 44.740000 seconds (88.000000 wall) | 100.0% 94.63s hg: line 51: dispatch.run() | 100.0% 94.63s dispatch.py: run line 144: status = dispatch(req) | 100.0% 94.63s dispatch.py: dispatch line 233: status = _rundispatch(req) | 100.0% 94.63s dispatch.py: _rundispatch line 278: ret = _runcatch(req) or 0 | 100.0% 94.63s dispatch.py: _runcatch line 468: return _callcatch(ui, _runc... | 100.0% 94.63s dispatch.py: _callcatch line 478: return scmutil.callcatch(ui... | 100.0% 94.63s scmutil.py: callcatch line 182: return func() | 100.0% 94.63s dispatch.py: _runcatchfunc line 458: return _dispatch(req) | 100.0% 94.63s dispatch.py: _dispatch line 1106: return _dispatch_post_cwd(req) | 99.7% 94.39s dispatch.py: _dispatch_post_cwd line 1362: return runcommand( | 99.7% 94.39s __init__.py: runcommand line 578: return orig(lui, repo, *arg... | 99.7% 94.39s dispatch.py: runcommand line 975: ret = _runcommand(ui, optio... | 99.7% 94.39s dispatch.py: _runcommand line 1374: return cmdfunc() | 99.7% 94.39s dispatch.py: line 1360: d = lambda: util.checksigna... | 99.7% 94.39s util.py: check line 1979: return func(*args, **kwargs) | 99.7% 94.39s util.py: check line 1979: return func(*args, **kwargs) | 99.7% 94.32s __init__.py: pushoutgoingwrap line 1683: return orig(ui, repo, *args... | 99.7% 94.32s util.py: check line 1979: return func(*args, **kwargs) | 99.7% 94.32s util.py: check line 1979: return func(*args, **kwargs) | 99.7% 94.32s flow.py: wrappush line 118: return orig(repo, remote, *... | 99.7% 94.32s util.py: check line 1979: return func(*args, **kwargs) \ 91.5% 86.55s commands.py: push line 5567: pushop = exchange.push( | 91.5% 86.55s __init__.py: push line 581: return orig(repo, *args, **... \ 54.5% 51.58s exchange.py: push line 525: _pushbundle2(pushop) | 50.0% 47.29s exchange.py: _pushbundle2, line 1225: reply = e.callcommand( | 50.0% 47.29s server.py: callcommand line 148: return s.callcommand(comman... | 50.0% 47.29s wireprotov1peer.py: callcommand, line 176: self.sendcommands() | 50.0% 47.29s wireprotov1peer.py: sendcommands, line 209: result = fn(**pycompat.strk... | 49.2% 46.60s wireprotov1peer.py: unbundle, line 517: ret = bundle2.getunbundler(... | 49.2% 46.60s bundle2.py: getunbundler, line 822: magicstring = changegroup.r... | 49.2% 46.60s util.py: readexactly line 3326: s = stream.read(n) | 49.2% 46.60s sshpeer.py: read line 130: r = self._call(b'read', size) | 49.2% 46.60s sshpeer.py: _call line 163: mainready, sideready = self... | 49.2% 46.60s sshpeer.py: _wait line 115: act = util.poll(fds) | 49.2% 46.60s posix.py: poll line 760: res = select.select(fds, fd... \ 36.3% 34.33s exchange.py: push line 521: _pushdiscovery(pushop) | 36.3% 34.33s exchange.py: _pushdiscovery, line 573: step(pushop) | 32.4% 30.69s obsdiscovery.py: newdisco line 832: _pushdiscoveryobsmarkers(ol... | 24.2% 22.87s obsdiscovery.py: _pushdiscoveryobsmarkers, line 817: nodes = discovery(pushop, c... | 24.2% 22.87s obsdiscovery.py: _pushobshashrange, line 769: missing = findmissingrange(... | 17.0% 16.05s obsdiscovery.py: findmissingrange, line 78: local.stablerange.warmup(lo... | 17.0% 16.05s localrepo.py: __get__ line 243: return super().__get__(unfi) | 17.0% 16.05s util.py: __get__ line 1847: result = self.func(obj) | 17.0% 16.05s stablerangecache.py: stablerange, line 520: cache.update(self) | 17.0% 16.05s genericcaches.py: update line 122: self._updatefrom(repo, data) | 17.0% 16.05s stablerangecache.py: _updatefrom, line 112: for sub in self.subranges(r... | 17.0% 16.05s stablerange.py: subranges line 654: value = self._subranges(rep... | 16.4% 15.56s stablerange.py: _subranges line 739: ret = self._slicesrangeat(r... | 16.4% 15.56s stablerange.py: _slicesrangeat, line 745: self._warmcachefor(repo, ra... | 15.1% 14.33s stablerange.py: _warmcachefor, line 729: self.subranges(repo, current) | 15.1% 14.33s stablerange.py: subranges line 651: cached = self._getsub(rangeid) \ 7.6% 7.19s stablerangecache.py: _getsub, line 220: result = self._con.execute(... \ 7.5% 7.07s stablerangecache.py: _getsub, line 222: value = self._con.execute(_... \ 5.5% 5.23s commands.py: push line 5522: other = hg.peer(repo, opts,... | 5.5% 5.23s discovery.py: wraphgpeer line 374: peer = orig(uiorrepo, opts,... | 5.5% 5.23s hg.py: peer line 264: peer = cls.make_peer( --- Sample count: 41367 Total time: 34.991000 seconds (94.635000 wall) hg --profile --config ui.paginate=never push --debug --verbose -t 37.81s user 5.63s system 42% cpu 1:43.08 total