profile of hg status in openjdk repository

hg-profile

~/Java/openjdk-upstream $ time HGWITHRUSTEXT=cpython ~/Downloads/hg-stable/hg --profile status
*** failed to import extension hggit: 'module' object has no attribute 'command'
| 100.0%  1.05s  dispatch.py:    _callcatch        line 43:  dispatch.run()
| 100.0%  1.05s  scmutil.py:     callcatch         line 486:  return scmutil.callcatch(ui...
| 100.0%  1.05s  dispatch.py:    _runcatchfunc     line 152:  return func()
| 100.0%  1.05s  commands.py:    status            line 467:  return _dispatch(req)
 \ 89.5%  0.94s  ui.py:          pager             line 6889:  ui.pager(b'status')
   \ 59.0%  0.62s  ui.py:          _runpager       line 1357:  if self._runpager(pagercmd,...
     | 59.0%  0.62s  subprocess.py:  __init__      line 1415:  env=procutil.tonativeenv(pr...
     | 59.0%  0.62s  subprocess.py:  _execute_childline 394:  errread, errwrite)
     | 59.0%  0.62s  subprocess.py:  _eintr_retry_callline 1023:  data = _eintr_retry_call(os...
   \ 30.5%  0.32s  ui.py:          formatted       line 1329:  or not self.formatted()
     | 30.5%  0.32s  ui.py:          _isatty       line 1584:  return self._isatty(self._f...
     | 30.5%  0.32s  procutil.py:    isatty        line 1265:  return procutil.isatty(fh)
 \  5.7%  0.06s  localrepo.py:   status            line 6866:  opts.get(b'subrepos'),
   |  5.7%  0.06s  context.py:     status          line 3325:  node2, match, ignored, clea...
   |  5.7%  0.06s  context.py:     _buildstatus    line 428:  ctx1, r, match, listignored...
   |  5.7%  0.06s  context.py:     _dirstatestatus line 1961:  s = self._dirstatestatus(ma...
   |  5.7%  0.06s  dirstate.py:    status          line 1871:  match, subrepos, ignored=ig...
   |  5.7%  0.06s  util.py:        __get__         line 1203:  elif self._checkcase:
   |  5.7%  0.06s  dirstate.py:    _checkcase      line 1747:  result = self.func(obj)
   |  5.7%  0.06s  util.py:        fscasesensitive line 194:  return not util.fscasesensi...
---
Sample count: 558
Total time: 1.100000 seconds (1.090000 wall)

real	0m1,344s
user	0m1,385s
sys	0m0,580s

~/Java/openjdk-upstream $ time RUST_LOG=trace ~/Downloads/hg-stable/hg --profile status
*** failed to import extension hggit: 'module' object has no attribute 'command'
2020-08-26 15:03:56,010 TRACE [hg::dirstate::parsers] Duration of `parse_dirstate`: 60.790046ms
2020-08-26 15:03:56,012 TRACE [hg::matchers] Duration of `re_matcher`: 382.741µs
2020-08-26 15:03:56,013 TRACE [hg::dirstate::status] Duration of `walk_explicit`: 426.919µs
2020-08-26 15:03:56,176 TRACE [hg::dirstate::status] Duration of `traverse`: 163.491168ms
2020-08-26 15:03:56,266 TRACE [hg::dirstate::status] Duration of `handle_unknowns`: 89.424584ms
2020-08-26 15:03:56,275 TRACE [hg::dirstate::status] Duration of `build_response`: 9.669935ms
2020-08-26 15:03:56,276 TRACE [hg::dirstate::status] Duration of `status`: 264.079528ms
| 100.0%  1.04s  dispatch.py:    _callcatch        line 43:  dispatch.run()
| 100.0%  1.04s  scmutil.py:     callcatch         line 486:  return scmutil.callcatch(ui...
| 100.0%  1.04s  dispatch.py:    _runcatchfunc     line 152:  return func()
| 100.0%  1.04s  commands.py:    status            line 467:  return _dispatch(req)
 \ 85.6%  0.89s  ui.py:          pager             line 6889:  ui.pager(b'status')
   \ 59.6%  0.62s  ui.py:          _runpager       line 1357:  if self._runpager(pagercmd,...
     | 59.6%  0.62s  subprocess.py:  __init__      line 1415:  env=procutil.tonativeenv(pr...
     | 59.6%  0.62s  subprocess.py:  _execute_childline 394:  errread, errwrite)
     | 59.6%  0.62s  subprocess.py:  _eintr_retry_callline 1023:  data = _eintr_retry_call(os...
   \ 26.0%  0.27s  ui.py:          formatted       line 1329:  or not self.formatted()
     | 26.0%  0.27s  ui.py:          _isatty       line 1584:  return self._isatty(self._f...
     | 26.0%  0.27s  procutil.py:    isatty        line 1265:  return procutil.isatty(fh)
 \  5.8%  0.06s  localrepo.py:   status            line 6866:  opts.get(b'subrepos'),
   |  5.8%  0.06s  context.py:     status          line 3325:  node2, match, ignored, clea...
   |  5.8%  0.06s  context.py:     _buildstatus    line 428:  ctx1, r, match, listignored...
   |  5.8%  0.06s  context.py:     _dirstatestatus line 1961:  s = self._dirstatestatus(ma...
   |  5.8%  0.06s  dirstate.py:    status          line 1871:  match, subrepos, ignored=ig...
   |  5.8%  0.06s  util.py:        __get__         line 1203:  elif self._checkcase:
   |  5.8%  0.06s  dirstate.py:    _checkcase      line 1747:  result = self.func(obj)
   |  5.8%  0.06s  util.py:        fscasesensitive line 194:  return not util.fscasesensi...
---
Sample count: 556
Total time: 1.110000 seconds (1.050000 wall)

real	0m1,308s
user	0m1,382s
sys	0m0,588s```

~/Java/openjdk-upstream $ time RUST_LOG=trace ~/Downloads/hg-stable/hg -q --profile status
*** failed to import extension hggit: 'module' object has no attribute 'command'
2020-08-26 15:11:34,245 TRACE [hg::dirstate::parsers] Duration of `parse_dirstate`: 64.655934ms
2020-08-26 15:11:34,247 TRACE [hg::dirstate::status] Duration of `walk_explicit`: 447.894µs
2020-08-26 15:11:34,344 TRACE [hg::dirstate::status] Duration of `extend_from_dmap`: 96.473076ms
2020-08-26 15:11:34,344 TRACE [hg::dirstate::status] Duration of `build_response`: 473.588µs
2020-08-26 15:11:34,344 TRACE [hg::dirstate::status] Duration of `status`: 97.561499ms
| 100.0%  0.89s  dispatch.py:    _callcatch        line 43:  dispatch.run()
| 100.0%  0.89s  scmutil.py:     callcatch         line 486:  return scmutil.callcatch(ui...
| 100.0%  0.89s  dispatch.py:    _runcatchfunc     line 152:  return func()
| 100.0%  0.89s  commands.py:    status            line 467:  return _dispatch(req)
 \ 82.0%  0.73s  ui.py:          pager             line 6889:  ui.pager(b'status')
   \ 70.8%  0.63s  ui.py:          _runpager       line 1357:  if self._runpager(pagercmd,...
     | 70.8%  0.63s  subprocess.py:  __init__      line 1415:  env=procutil.tonativeenv(pr...
     | 70.8%  0.63s  subprocess.py:  _execute_childline 394:  errread, errwrite)
     | 69.7%  0.62s  subprocess.py:  _eintr_retry_callline 1023:  data = _eintr_retry_call(os...
   \ 11.2%  0.10s  ui.py:          formatted       line 1329:  or not self.formatted()
     | 11.2%  0.10s  ui.py:          _isatty       line 1584:  return self._isatty(self._f...
     | 11.2%  0.10s  procutil.py:    isatty        line 1265:  return procutil.isatty(fh)
 \  7.9%  0.07s  localrepo.py:   status            line 6866:  opts.get(b'subrepos'),
   |  7.9%  0.07s  context.py:     status          line 3325:  node2, match, ignored, clea...
   |  7.9%  0.07s  context.py:     _buildstatus    line 428:  ctx1, r, match, listignored...
   |  7.9%  0.07s  context.py:     _dirstatestatus line 1961:  s = self._dirstatestatus(ma...
   |  7.9%  0.07s  dirstate.py:    status          line 1871:  match, subrepos, ignored=ig...
   |  7.9%  0.07s  util.py:        __get__         line 1203:  elif self._checkcase:
   |  7.9%  0.07s  dirstate.py:    _checkcase      line 1747:  result = self.func(obj)
   |  7.9%  0.07s  util.py:        fscasesensitive line 194:  return not util.fscasesensi...
---
Sample count: 564
Total time: 0.720000 seconds (0.900000 wall)

real	0m1,151s
user	0m1,048s
sys	0m0,524s```

~/Java/openjdk-upstream $ time HGPLAIN=1 ~/Downloads/hg-stable/hg status --profile
| 100.0%  0.10s  dispatch.py:    _callcatch        line 43:  dispatch.run()
| 100.0%  0.10s  scmutil.py:     callcatch         line 486:  return scmutil.callcatch(ui...
| 100.0%  0.10s  dispatch.py:    _runcatchfunc     line 152:  return func()
| 100.0%  0.10s  commands.py:    status            line 467:  return _dispatch(req)
 \ 60.0%  0.06s  localrepo.py:   status            line 6866:  opts.get(b'subrepos'),
   | 60.0%  0.06s  context.py:     status          line 3325:  node2, match, ignored, clea...
   | 60.0%  0.06s  context.py:     _buildstatus    line 428:  ctx1, r, match, listignored...
   | 60.0%  0.06s  context.py:     _dirstatestatus line 1961:  s = self._dirstatestatus(ma...
   | 60.0%  0.06s  dirstate.py:    status          line 1871:  match, subrepos, ignored=ig...
   | 60.0%  0.06s  util.py:        __get__         line 1203:  elif self._checkcase:
   | 60.0%  0.06s  dirstate.py:    _checkcase      line 1747:  result = self.func(obj)
   | 60.0%  0.06s  util.py:        fscasesensitive line 194:  return not util.fscasesensi...
 \ 20.0%  0.02s  scmutil.py:     revpair           line 6818:  ctx1, ctx2 = scmutil.revpai...
   | 20.0%  0.02s  localrepo.py:   __getitem__     line 707:  return repo[b'.'], repo[None]
   | 20.0%  0.02s  localrepo.py:   _quick_access_changeidline 1616:  quick_access = self._quick_...
   | 20.0%  0.02s  localrepo.py:   __get__         line 1596:  mapping.update(self._quick_...
   | 20.0%  0.02s  localrepo.py:   __get__         line 177:  return getattr(unfi, self.n...
   | 20.0%  0.02s  util.py:        __get__         line 176:  return super(unfilteredprop...
   | 20.0%  0.02s  localrepo.py:   _quick_access_changeid_wcline  1747:  result = self.func(obj)
   | 20.0%  0.02s  localrepo.py:   __get__         line 1555:  cl = self.unfiltered().chan...
   | 20.0%  0.02s  scmutil.py:     __get__         line 108:  return super(_basefilecache...
     \ 10.0%  0.01s  scmutil.py:     __init__      line 1621:  entry = filecacheentry(path...
       | 10.0%  0.01s  scmutil.py:     __init__    line 1546:  self._entries.append(fileca...
       | 10.0%  0.01s  scmutil.py:     stat        line 1493:  self.cachestat = filecaches...
       | 10.0%  0.01s  posix.py:       __init__    line 1536:  return util.cachestat(path)
     \ 10.0%  0.01s  localrepo.py:   changelog     line 1622:  entry.obj = self.func(obj)
       | 10.0%  0.01s  localrepo.py:   __get__     line 1464:  self.dirstate.prefetch_pare...
       | 10.0%  0.01s  dirstate.py:    _pl         line 111:  self._pl
       | 10.0%  0.01s  dirstate.py:    parents     line 166:  return self._map.parents()
       | 10.0%  0.01s  dirstate.py:    _opendirstatefileline 1831:  fp = self._opendirstatefile()
       | 10.0%  0.01s  txnutil.py:     trypending  line 1813:  self._root, self._opener, s...
       | 10.0%  0.01s  vfs.py:         __call__    line 36:  return (vfs(filename, **kwa...
       | 10.0%  0.01s  posix.py:       posixfile   line 471:  fp = util.posixfile(f, mode)
 \ 20.0%  0.02s  hg.py:          _peerorrepo       line 227:  createopts=createopts,
   \ 10.0%  0.01s  hg.py:          _peerlookup     line 188:  obj = _peerlookup(path).ins...
     | 10.0%  0.01s  hg.py:          _local        line 152:  return thing(path)
   \ 10.0%  0.01s  localrepo.py:   instance        line 189:  ui, path, create, intents=i...
     | 10.0%  0.01s  localrepo.py:   makelocalrepositoryline 3523:  return makelocalrepository(...
     | 10.0%  0.01s  ui.py:          copy          line 493:  ui = baseui.copy()
     | 10.0%  0.01s  ui.py:          __init__      line 351:  return self.__class__(self)
     | 10.0%  0.01s  ui.py:          fixconfig     line 273:  self.fixconfig()
---
Sample count: 14
Total time: 1.000000 seconds (0.390000 wall)

real	0m0,602s
user	0m0,807s
sys	0m0,386s```

~/Java/openjdk-upstream $ time RUST_LOG=trace HGPLAIN=1 ~/Downloads/hg-stable/hg -q --profile status
2020-08-26 15:26:44,857 TRACE [hg::dirstate::parsers] Duration of `parse_dirstate`: 64.03532ms
2020-08-26 15:26:44,864 TRACE [hg::dirstate::status] Duration of `walk_explicit`: 5.714797ms
2020-08-26 15:26:44,951 TRACE [hg::dirstate::status] Duration of `extend_from_dmap`: 87.120196ms
2020-08-26 15:26:44,952 TRACE [hg::dirstate::status] Duration of `build_response`: 479.758µs
2020-08-26 15:26:44,952 TRACE [hg::dirstate::status] Duration of `status`: 93.455529ms
| 100.0%  0.11s  dispatch.py:    _callcatch        line 43:  dispatch.run()
| 100.0%  0.11s  scmutil.py:     callcatch         line 486:  return scmutil.callcatch(ui...
| 100.0%  0.11s  dispatch.py:    _runcatchfunc     line 152:  return func()
| 100.0%  0.11s  commands.py:    status            line 467:  return _dispatch(req)
 \ 63.6%  0.07s  localrepo.py:   status            line 6866:  opts.get(b'subrepos'),
   | 63.6%  0.07s  context.py:     status          line 3325:  node2, match, ignored, clea...
   | 63.6%  0.07s  context.py:     _buildstatus    line 428:  ctx1, r, match, listignored...
   | 63.6%  0.07s  context.py:     _dirstatestatus line 1961:  s = self._dirstatestatus(ma...
     \ 54.5%  0.06s  dirstate.py:    status        line 1871:  match, subrepos, ignored=ig...
       | 54.5%  0.06s  util.py:        __get__     line 1203:  elif self._checkcase:
       | 54.5%  0.06s  dirstate.py:    _checkcase  line 1747:  result = self.func(obj)
       | 54.5%  0.06s  util.py:        fscasesensitiveline 194:  return not util.fscasesensi...
     \  9.1%  0.01s  context.py:     __contains__  line 1868:  if b'.hgsub' in self:
       |  9.1%  0.01s  dirstate.py:    __getitem__ line 1544:  return self._repo.dirstate[...
       |  9.1%  0.01s  dirstate.py:    get         line 287:  return self._map.get(key, (...
       |  9.1%  0.01s  util.py:        __get__     line 1754:  return self._rustmap.get(*a...
       |  9.1%  0.01s  dirstate.py:    _rustmap    line 1747:  result = self.func(obj)
       |  9.1%  0.01s  dirstate.py:    read        line 1763:  self.read()
 \ 18.2%  0.02s  scmutil.py:     revpair           line 6818:  ctx1, ctx2 = scmutil.revpai...
   | 18.2%  0.02s  localrepo.py:   __getitem__     line 707:  return repo[b'.'], repo[None]
   | 18.2%  0.02s  localrepo.py:   _quick_access_changeidline 1616:  quick_access = self._quick_...
   | 18.2%  0.02s  localrepo.py:   __get__         line 1596:  mapping.update(self._quick_...
   | 18.2%  0.02s  localrepo.py:   __get__         line 177:  return getattr(unfi, self.n...
   | 18.2%  0.02s  util.py:        __get__         line 176:  return super(unfilteredprop...
   | 18.2%  0.02s  localrepo.py:   _quick_access_changeid_wcline  1747:  result = self.func(obj)
   | 18.2%  0.02s  localrepo.py:   __get__         line 1555:  cl = self.unfiltered().chan...
   | 18.2%  0.02s  scmutil.py:     __get__         line 108:  return super(_basefilecache...
     \  9.1%  0.01s  scmutil.py:     __init__      line 1621:  entry = filecacheentry(path...
       |  9.1%  0.01s  scmutil.py:     __init__    line 1546:  self._entries.append(fileca...
       |  9.1%  0.01s  scmutil.py:     stat        line 1493:  self.cachestat = filecaches...
       |  9.1%  0.01s  posix.py:       __init__    line 1536:  return util.cachestat(path)
     \  9.1%  0.01s  localrepo.py:   changelog     line 1622:  entry.obj = self.func(obj)
       |  9.1%  0.01s  store.py:       changelog   line 1465:  return self.store.changelog...
       |  9.1%  0.01s  changelog.py:   __init__    line 424:  return changelog.changelog(...
       |  9.1%  0.01s  revlog.py:      __init__    line 388:  persistentnodemap=opener.op...
       |  9.1%  0.01s  revlog.py:      _loadindex  line 484:  self._loadindex()
       |  9.1%  0.01s  revlog.py:      _indexfp    line 555:  with self._indexfp() as f:
       |  9.1%  0.01s  store.py:       __call__    line 685:  return self.opener(self.ind...
       |  9.1%  0.01s  vfs.py:         __call__    line 643:  return self.vfs(encoded, mo...
       |  9.1%  0.01s  posix.py:       posixfile   line 471:  fp = util.posixfile(f, mode)
 \ 18.2%  0.02s  hg.py:          _peerorrepo       line 227:  createopts=createopts,
   \  9.1%  0.01s  hg.py:          _peerlookup     line 188:  obj = _peerlookup(path).ins...
     |  9.1%  0.01s  hg.py:          _local        line 152:  return thing(path)
   \  9.1%  0.01s  localrepo.py:   instance        line 189:  ui, path, create, intents=i...
     |  9.1%  0.01s  localrepo.py:   makelocalrepositoryline 3523:  return makelocalrepository(...
     |  9.1%  0.01s  localrepo.py:   makestore     line 602:  lambda base: vfsmod.vfs(bas...
     |  9.1%  0.01s  store.py:       __init__      line 808:  path, vfstype, b'dotencode'...
     |  9.1%  0.01s  localrepo.py:   <lambda>      line 659:  vfs = vfstype(path + b'/sto...
     |  9.1%  0.01s  vfs.py:         __init__      line 602:  lambda base: vfsmod.vfs(bas...
     |  9.1%  0.01s  pathutil.py:    __init__      line 360:  self.audit = pathutil.patha...
     |  9.1%  0.01s  posixpath.py:   lexists       line 56:  if os.path.lexists(root) an...
---
Sample count: 16
Total time: 0.600000 seconds (0.220000 wall)

real	0m0,436s
user	0m0,458s
sys	0m0,343s```