annotate tests/test-chg.t @ 42044:bb271ec2fbfb

compression: introduce a `storage.revlog.zstd.level` configuration

This option control the zstd compression level used when compressing revlog
chunk. The usage of zstd for revlog compression has not graduated from
experimental yet, but we intend to fix that soon.

The option name for the compression level is more straight forward to pick, so
this changesets comes first.  Having a dedicated option for each compression
engine is useful because they don't support the same range of values.

I ran the same measurement as for the zlib compression level (in the parent
changesets). The variation in repository size is stay mostly in the same (small)
range. The "read/write" performance see smallish variation, but are overall much
better than zlib. Write performance show the same tend of having better write
performance for when reaching high-end compression.

Again, we don't intend to change the default zstd compression level (currently:
3) in this series. However this is worth investigating in the future.

The Performance comparison of zlib vs zstd is quite impressive. The repository
size stay in the same range, but the performance are much better in all
situations.

Comparison summary
==================

We are looking at:
- performance range for zlib
- performance range for zstd
- comparison of default zstd (level-3) to default zlib (level 6)
- comparison of the slowest zstd time to the fastest zlib time

Read performance:
-----------------
          |           zlib          |           zstd          | cmp | f2s
mercurial |   0.170159 -   0.189219 |   0.144127 -   0.149624 | 80% | 88%
pypy      |   2.679217 -   2.768691 |   1.532317 -   1.705044 | 60% | 63%
netbeans  | 122.477027 - 141.620281 |  72.996346 -  89.731560 | 58% | 73%
mozilla   | 147.867662 - 170.572118 |  91.700995 - 105.853099 | 56% | 71%

Write performance:
------------------
          |           zlib          |           zstd          | cmp | f2s
mercurial |  53.250304 - 56.2936129 |  40.877025 -  45.677286 | 75% | 86%
pypy      | 460.721984 - 476.589918 | 270.545409 - 301.002219 | 63% | 65%
netbeans  | 520.560316 - 715.930400 | 370.356311 - 428.329652 | 55% | 82%
mozilla   | 739.803002 - 987.056093 | 505.152906 - 591.930683 | 57% | 80%

Raw data
--------

repo      alg lvl  .hg/store size  00manifest.d read       write

mercurial zlib  1      49,402,813     5,963,475   0.170159  53.250304
mercurial zlib  6      47,197,397     5,875,730   0.182820  56.264320
mercurial zlib  9      47,121,596     5,849,781   0.189219  56.293612

mercurial zstd  1      49,737,084     5,966,355   0.144127  40.877025
mercurial zstd  3      48,961,867     5,895,208   0.146376  42.268142
mercurial zstd  5      48,200,592     5,938,676   0.149624  43.162875
mercurial zstd 10      47,833,520     5,913,353   0.145185  44.012489
mercurial zstd 15      47,314,604     5,728,679   0.147686  45.677286
mercurial zstd 20      47,330,502     5,830,539   0.145789  45.025407
mercurial zstd 22      47,330,076     5,830,539   0.143996  44.690460


pypy      zlib  1     370,830,572    28,462,425   2.679217 460.721984
pypy      zlib  6     340,112,317    27,648,747   2.768691 467.537158
pypy      zlib  9     338,360,736    27,639,003   2.763495 476.589918

pypy      zstd  1     362,377,479    27,916,214   1.532317 270.545409
pypy      zstd  3     354,137,693    27,905,988   1.686718 294.951509
pypy      zstd  5     342,640,043    27,655,774   1.705044 301.002219
pypy      zstd 10     334,224,327    27,164,493   1.567287 285.186239
pypy      zstd 15     329,000,363    26,645,965   1.637729 299.561332
pypy      zstd 20     324,534,039    26,199,547   1.526813 302.149827
pypy      zstd 22     324,530,595    26,198,932   1.525718 307.821218


netbeans  zlib  1   1,281,847,810   165,495,457 122.477027 520.560316
netbeans  zlib  6   1,205,284,353   159,161,207 139.876147 715.930400
netbeans  zlib  9   1,197,135,671   155,034,586 141.620281 678.297064

netbeans  zstd  1   1,259,581,737   160,840,613  72.996346 370.356311
netbeans  zstd  3   1,232,978,122   157,691,551  81.622317 396.733087
netbeans  zstd  5   1,208,034,075   160,246,880  83.080549 364.342626
netbeans  zstd 10   1,188,624,176   156,083,417  79.323935 403.594602
netbeans  zstd 15   1,176,973,589   153,859,477  89.731560 428.329652
netbeans  zstd 20   1,162,958,258   151,147,535  82.842667 392.335349
netbeans  zstd 22   1,162,707,029   151,150,220  82.565695 402.840655


mozilla   zlib  1   2,775,497,186   298,527,987 147.867662 751.263721
mozilla   zlib  6   2,596,856,420   286,597,671 170.572118 987.056093
mozilla   zlib  9   2,587,542,494   287,018,264 163.622338 739.803002

mozilla   zstd  1   2,723,159,348   286,617,532  91.700995 570.042751
mozilla   zstd  3   2,665,055,001   286,152,013  95.240155 561.412805
mozilla   zstd  5   2,607,819,817   288,060,030 101.978048 505.152906
mozilla   zstd 10   2,558,761,085   283,967,648 104.113481 497.771202
mozilla   zstd 15   2,526,216,060   275,581,300 105.853099 591.930683
mozilla   zstd 20   2,485,114,806   266,478,859  95.268795 576.515389
mozilla   zstd 22   2,484,869,080   266,456,505  94.429282 572.785537

#require chg

  $ mkdir log
  $ cp $HGRCPATH $HGRCPATH.unconfigured
  $ cat <<'EOF' >> $HGRCPATH
  > [cmdserver]
  > log = $TESTTMP/log/server.log
  > max-log-files = 1
  > max-log-size = 10 kB
  > EOF
  $ cp $HGRCPATH $HGRCPATH.orig

  $ filterlog () {
  >   sed -e 's!^[0-9/]* [0-9:]* ([0-9]*)>!YYYY/MM/DD HH:MM:SS (PID)>!' \
  >       -e 's!\(setprocname\|received fds\|setenv\): .*!\1: ...!' \
  >       -e 's!\(confighash\|mtimehash\) = [0-9a-f]*!\1 = ...!g' \
  >       -e 's!\(in \)[0-9.]*s\b!\1 ...s!g' \
  >       -e 's!\(pid\)=[0-9]*!\1=...!g' \
  >       -e 's!\(/server-\)[0-9a-f]*!\1...!g'
  > }

init repo

  $ chg init foo
  $ cd foo

ill-formed config

  $ chg status
  $ echo '=brokenconfig' >> $HGRCPATH
  $ chg status
  hg: parse error at * (glob)
  [255]

  $ cp $HGRCPATH.orig $HGRCPATH

long socket path

  $ sockpath=$TESTTMP/this/path/should/be/longer/than/one-hundred-and-seven/characters/where/107/is/the/typical/size/limit/of/unix-domain-socket
  $ mkdir -p $sockpath
  $ bakchgsockname=$CHGSOCKNAME
  $ CHGSOCKNAME=$sockpath/server
  $ export CHGSOCKNAME
  $ chg root
  $TESTTMP/foo
  $ rm -rf $sockpath
  $ CHGSOCKNAME=$bakchgsockname
  $ export CHGSOCKNAME

  $ cd ..

editor
------

  $ cat >> pushbuffer.py <<EOF
  > def reposetup(ui, repo):
  >     repo.ui.pushbuffer(subproc=True)
  > EOF

  $ chg init editor
  $ cd editor

by default, system() should be redirected to the client:

  $ touch foo
  $ CHGDEBUG= HGEDITOR=cat chg ci -Am channeled --edit 2>&1 \
  > | egrep "HG:|run 'cat"
  chg: debug: * run 'cat "*"' at '$TESTTMP/editor' (glob)
  HG: Enter commit message.  Lines beginning with 'HG:' are removed.
  HG: Leave message empty to abort commit.
  HG: --
  HG: user: test
  HG: branch 'default'
  HG: added foo

but no redirection should be made if output is captured:

  $ touch bar
  $ CHGDEBUG= HGEDITOR=cat chg ci -Am bufferred --edit \
  > --config extensions.pushbuffer="$TESTTMP/pushbuffer.py" 2>&1 \
  > | egrep "HG:|run 'cat"
  [1]

check that commit commands succeeded:

  $ hg log -T '{rev}:{desc}\n'
  1:bufferred
  0:channeled

  $ cd ..

pager
-----

  $ cat >> fakepager.py <<EOF
  > import sys
  > for line in sys.stdin:
  >     sys.stdout.write('paged! %r\n' % line)
  > EOF

enable pager extension globally, but spawns the master server with no tty:

  $ chg init pager
  $ cd pager
  $ cat >> $HGRCPATH <<EOF
  > [extensions]
  > pager =
  > [pager]
  > pager = "$PYTHON" $TESTTMP/fakepager.py
  > EOF
  $ chg version > /dev/null
  $ touch foo
  $ chg ci -qAm foo

pager should be enabled if the attached client has a tty:

  $ chg log -l1 -q --config ui.formatted=True
  paged! '0:1f7b0de80e11\n'
  $ chg log -l1 -q --config ui.formatted=False
  0:1f7b0de80e11

chg waits for pager if runcommand raises

  $ cat > $TESTTMP/crash.py <<EOF
  > from mercurial import registrar
  > cmdtable = {}
  > command = registrar.command(cmdtable)
  > @command(b'crash')
  > def pagercrash(ui, repo, *pats, **opts):
  >     ui.write('going to crash\n')
  >     raise Exception('.')
  > EOF

  $ cat > $TESTTMP/fakepager.py <<EOF
  > from __future__ import absolute_import
  > import sys
  > import time
  > for line in iter(sys.stdin.readline, ''):
  >     if 'crash' in line: # only interested in lines containing 'crash'
  >         # if chg exits when pager is sleeping (incorrectly), the output
  >         # will be captured by the next test case
  >         time.sleep(1)
  >         sys.stdout.write('crash-pager: %s' % line)
  > EOF

  $ cat >> .hg/hgrc <<EOF
  > [extensions]
  > crash = $TESTTMP/crash.py
  > EOF

  $ chg crash --pager=on --config ui.formatted=True 2>/dev/null
  crash-pager: going to crash
  [255]

  $ cd ..

server lifecycle
----------------

chg server should be restarted on code change, and old server will shut down
automatically. In this test, we use the following time parameters:

 - "sleep 1" to make mtime different
 - "sleep 2" to notice mtime change (polling interval is 1 sec)

set up repository with an extension:

  $ chg init extreload
  $ cd extreload
  $ touch dummyext.py
  $ cat <<EOF >> .hg/hgrc
  > [extensions]
  > dummyext = dummyext.py
  > EOF

isolate socket directory for stable result:

  $ OLDCHGSOCKNAME=$CHGSOCKNAME
  $ mkdir chgsock
  $ CHGSOCKNAME=`pwd`/chgsock/server

warm up server:

  $ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
  chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)

new server should be started if extension modified:

  $ sleep 1
  $ touch dummyext.py
  $ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
  chg: debug: * instruction: unlink $TESTTMP/extreload/chgsock/server-* (glob)
  chg: debug: * instruction: reconnect (glob)
  chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)

old server will shut down, while new server should still be reachable:

  $ sleep 2
  $ CHGDEBUG= chg log 2>&1 | (egrep 'instruction|start' || true)

socket file should never be unlinked by old server:
(simulates unowned socket by updating mtime, which makes sure server exits
at polling cycle)

  $ ls chgsock/server-*
  chgsock/server-* (glob)
  $ touch chgsock/server-*
  $ sleep 2
  $ ls chgsock/server-*
  chgsock/server-* (glob)

since no server is reachable from socket file, new server should be started:
(this test makes sure that old server shut down automatically)

  $ CHGDEBUG= chg log 2>&1 | egrep 'instruction|start'
  chg: debug: * start cmdserver at $TESTTMP/extreload/chgsock/server.* (glob)

shut down servers and restore environment:

  $ rm -R chgsock
  $ sleep 2
  $ CHGSOCKNAME=$OLDCHGSOCKNAME
  $ cd ..

check that server events are recorded:

  $ ls log
  server.log
  server.log.1

print only the last 10 lines, since we aren't sure how many records are
preserved:

  $ cat log/server.log.1 log/server.log | tail -10 | filterlog
  YYYY/MM/DD HH:MM:SS (PID)> forked worker process (pid=...)
  YYYY/MM/DD HH:MM:SS (PID)> setprocname: ...
  YYYY/MM/DD HH:MM:SS (PID)> received fds: ...
  YYYY/MM/DD HH:MM:SS (PID)> chdir to '$TESTTMP/extreload'
  YYYY/MM/DD HH:MM:SS (PID)> setumask 18
  YYYY/MM/DD HH:MM:SS (PID)> setenv: ...
  YYYY/MM/DD HH:MM:SS (PID)> confighash = ... mtimehash = ...
  YYYY/MM/DD HH:MM:SS (PID)> validate: []
  YYYY/MM/DD HH:MM:SS (PID)> worker process exited (pid=...)
  YYYY/MM/DD HH:MM:SS (PID)> $TESTTMP/extreload/chgsock/server-... is not owned, exiting.

repository cache
----------------

  $ rm log/server.log*
  $ cp $HGRCPATH.unconfigured $HGRCPATH
  $ cat <<'EOF' >> $HGRCPATH
  > [cmdserver]
  > log = $TESTTMP/log/server.log
  > max-repo-cache = 1
  > track-log = command, repocache
  > EOF

isolate socket directory for stable result:

  $ OLDCHGSOCKNAME=$CHGSOCKNAME
  $ mkdir chgsock
  $ CHGSOCKNAME=`pwd`/chgsock/server

create empty repo and cache it:

  $ hg init cached
  $ hg id -R cached
  000000000000 tip
  $ sleep 1

modify repo (and cache will be invalidated):

  $ touch cached/a
  $ hg ci -R cached -Am 'add a'
  adding a
  $ sleep 1

read cached repo:

  $ hg log -R cached
  changeset:   0:ac82d8b1f7c4
  tag:         tip
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     add a
  
  $ sleep 1

discard cached from LRU cache:

  $ hg clone cached cached2
  updating to branch default
  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
  $ hg id -R cached2
  ac82d8b1f7c4 tip
  $ sleep 1

read uncached repo:

  $ hg log -R cached
  changeset:   0:ac82d8b1f7c4
  tag:         tip
  user:        test
  date:        Thu Jan 01 00:00:00 1970 +0000
  summary:     add a
  
  $ sleep 1

shut down servers and restore environment:

  $ rm -R chgsock
  $ sleep 2
  $ CHGSOCKNAME=$OLDCHGSOCKNAME

check server log:

  $ cat log/server.log | filterlog
  YYYY/MM/DD HH:MM:SS (PID)> init cached
  YYYY/MM/DD HH:MM:SS (PID)> id -R cached
  YYYY/MM/DD HH:MM:SS (PID)> loaded repo into cache: $TESTTMP/cached (in  ...s)
  YYYY/MM/DD HH:MM:SS (PID)> repo from cache: $TESTTMP/cached
  YYYY/MM/DD HH:MM:SS (PID)> ci -R cached -Am 'add a'
  YYYY/MM/DD HH:MM:SS (PID)> loaded repo into cache: $TESTTMP/cached (in  ...s)
  YYYY/MM/DD HH:MM:SS (PID)> repo from cache: $TESTTMP/cached
  YYYY/MM/DD HH:MM:SS (PID)> log -R cached
  YYYY/MM/DD HH:MM:SS (PID)> loaded repo into cache: $TESTTMP/cached (in  ...s)
  YYYY/MM/DD HH:MM:SS (PID)> clone cached cached2
  YYYY/MM/DD HH:MM:SS (PID)> id -R cached2
  YYYY/MM/DD HH:MM:SS (PID)> loaded repo into cache: $TESTTMP/cached2 (in  ...s)
  YYYY/MM/DD HH:MM:SS (PID)> log -R cached
  YYYY/MM/DD HH:MM:SS (PID)> loaded repo into cache: $TESTTMP/cached (in  ...s)