statprof: separate functions and "line", assume 4 digit line numbers Previously, the profile output looked like this (I've removed many lines that are mostly inconsequential): ``` | 100.0% 0.02s hg: <module> line 43: dispatch.run() | 100.0% 0.02s dispatch.py: run line 115: status = dispatch(req) | 100.0% 0.02s dispatch.py: _runcatchfunc line 432: return _dispatch(req) \ 50.0% 0.01s dispatch.py: _dispatch line 1228: return runcommand( | 50.0% 0.01s dispatch.py: runcommand line 883: ret = _runcommand(ui, optio... | 50.0% 0.01s dispatch.py: _runcommand line 1240: return cmdfunc() | 50.0% 0.01s localrepo.py: __getitem__ line 1670: quick_access = self._quick_... | 50.0% 0.01s localrepo.py: _quick_access_changeidline 1650: return self._quick_access_c... | 50.0% 0.01s localrepo.py: __get__ line 179: return getattr(unfi, self.n... | 50.0% 0.01s util.py: __get__ line 1747: result = self.func(obj) | 50.0% 0.01s localrepo.py: _quick_access_changeid_wcline 1611: cl = self.unfiltered().chan... | 50.0% 0.01s localrepo.py: __get__ line 110: return super(_basefilecache... | 50.0% 0.01s util.py: __getattribute__line 245: self.__spec__.loader.exec_m... | 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 783: | 50.0% 0.01s <frozen importlib._bootstrap>: _call_with_frames_removedline 219: | 50.0% 0.01s changelog.py: <module> line 376: class changelog(revlog.revl... | 50.0% 0.01s util.py: __getattribute__line 245: self.__spec__.loader.exec_m... | 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_moduleline 779: | 50.0% 0.01s <frozen importlib._bootstrap_external>: get_codeline 868: | 50.0% 0.01s <frozen importlib._bootstrap_external>: path_statsline 1012: | 50.0% 0.01s <frozen importlib._bootstrap_external>: _path_statline 87: ``` This has a few problems, though I'm only addressing some of them. 1. If the stuff before "line ###" is long, there's no separation between the function name and the "line" string. 2. If the stuff before "line ###" is really long, there's excessive separation between the "line" string and the line number. 3. We frequently have 4-digit line numbers, the code on the right wasn't dynamically indented and ended up quite messy looking. To solve these problems, I've added a ", " prefix before "line" iff it would otherwise not have any separation such as spaces. I've added a 'max' so that we never use a negative width (which is the cause of problem #2 above), and I've added a default assumption of 4 digit line numbers (but again using a 'max' so this shouldn't cause problems if we go beyond that. With these changes, it now looks like this: ``` | 100.0% 0.02s hg: <module> line 43: dispatch.run() | 100.0% 0.02s dispatch.py: run line 115: status = dispatch(req) | 100.0% 0.02s dispatch.py: _runcatchfunc line 432: return _dispatch(req) \ 50.0% 0.01s dispatch.py: _dispatch line 1228: return runcommand( | 50.0% 0.01s dispatch.py: runcommand line 883: ret = _runcommand(ui, optio... | 50.0% 0.01s dispatch.py: _runcommand line 1240: return cmdfunc() | 50.0% 0.01s localrepo.py: __getitem__ line 1670: quick_access = self._quick_... | 50.0% 0.01s localrepo.py: _quick_access_changeid, line 1650: return self._quick_access_c... | 50.0% 0.01s localrepo.py: __get__ line 179: return getattr(unfi, self.n... | 50.0% 0.01s util.py: __get__ line 1747: result = self.func(obj) | 50.0% 0.01s localrepo.py: _quick_access_changeid_wc, line 1611: cl = self.unfiltered().chan... | 50.0% 0.01s localrepo.py: __get__ line 110: return super(_basefilecache... | 50.0% 0.01s util.py: __getattribute__, line 245: self.__spec__.loader.exec_m... | 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_module, line 783: | 50.0% 0.01s <frozen importlib._bootstrap>: _call_with_frames_removed, line 219: | 50.0% 0.01s changelog.py: <module> line 376: class changelog(revlog.revl... | 50.0% 0.01s util.py: __getattribute__, line 245: self.__spec__.loader.exec_m... | 50.0% 0.01s <frozen importlib._bootstrap_external>: exec_module, line 779: | 50.0% 0.01s <frozen importlib._bootstrap_external>: get_code, line 868: | 50.0% 0.01s <frozen importlib._bootstrap_external>: path_stats, line 1012: | 50.0% 0.01s <frozen importlib._bootstrap_external>: _path_stat, line 87: ``` Differential Revision: https://phab.mercurial-scm.org/D9511

     1

https://bz.mercurial-scm.org/2137

     2

     3

Setup:

     4

     5

create a little extension that has 3 side-effects:

     6

1) ensure changelog data is not inlined

     7

2) make revlog to use lazyparser

     8

3) test that repo.lookup() works

     9

1 and 2 are preconditions for the bug; 3 is the bug.

    10

    11

  $ cat > commitwrapper.py <<EOF

    12

  > from mercurial import extensions, node, revlog

    13

  > 

    14

  > def reposetup(ui, repo):

    15

  >     class wraprepo(repo.__class__):

    16

  >         def commit(self, *args, **kwargs):

    17

  >             result = super(wraprepo, self).commit(*args, **kwargs)

    18

  >             tip1 = node.short(repo.changelog.tip())

    19

  >             tip2 = node.short(repo.lookup(tip1))

    20

  >             assert tip1 == tip2

    21

  >             ui.write(b'new tip: %s\n' % tip1)

    22

  >             return result

    23

  >     repo.__class__ = wraprepo

    24

  > 

    25

  > def extsetup(ui):

    26

  >     revlog._maxinline = 8             # split out 00changelog.d early

    27

  >     revlog._prereadsize = 8           # use revlog.lazyparser

    28

  > EOF

    29

    30

  $ cat >> $HGRCPATH <<EOF

    31

  > [extensions]

    32

  > commitwrapper = `pwd`/commitwrapper.py

    33

  > EOF

    34

    35

  $ hg init repo1

    36

  $ cd repo1

    37

  $ echo a > a

    38

  $ hg commit -A -m'add a with a long commit message to make the changelog a bit bigger'

    39

  adding a

    40

  new tip: 553596fad57b

    41

    42

Test that new changesets are visible to repo.lookup():

    43

    44

  $ echo a >> a

    45

  $ hg commit -m'one more commit to demonstrate the bug'

    46

  new tip: 799ae3599e0e

    47

    48

  $ hg tip

    49

  changeset:   1:799ae3599e0e

    50

  tag:         tip

    51

  user:        test

    52

  date:        Thu Jan 01 00:00:00 1970 +0000

    53

  summary:     one more commit to demonstrate the bug

    54

    55

    56

  $ cd ..