tests/test-profile.t

streamclone: use backgroundfilecloser (issue4889)

Closing files that have been appended to is slow on Windows/NTFS.
CloseHandle() calls on this platform often take 1-10ms - and that's
on my i7-6700K Skylake processor with a modern and fast SSD. Contrast
with other I/O operations, such as writing data, which take <100us.

This means that creating/appending thousands of files can add
significant overhead. For example, cloning mozilla-central creates
~232,000 revlog files. Assuming 1ms per CloseHandle(), that yields
232s (3:52) of wall time waiting for file closes!

The impact of this overhead can be measured most directly when applying
stream clone bundles. Applying these files is effectively uncompressing
a tar archive (read: it's very fast).

Using a RAM disk (read: no I/O wait), the difference in wall time for a
`hg debugapplystreamclonebundle` for a ~1731 MB mozilla-central bundle
between Windows and Linux from the same machine is drastic:

Linux:    ~12.8s (128MB/s)
Windows: ~352.0s (4.7MB/s)

Windows is ~27.5x slower. Yikes!

After this patch:

Linux:    ~12.8s (128MB/s)
Windows: ~102.1s (16.1MB/s)

Windows is now ~3.4x faster. Unfortunately, it is still ~8x slower than
Linux. Profiling reveals a few hot code paths that could likely be
improved. But those are for other patches.

This patch introduces test-clone-uncompressed.t because existing tests
of `clone --uncompressed` are scattered about and adding a variation for
background thread closing to e.g. test-http.t doesn't feel correct.

test --time

  $ hg --time help -q help 2>&1 | grep time > /dev/null
  $ hg init a
  $ cd a

#if lsprof

test --profile

  $ hg --profile st 2>../out
  $ grep CallCount ../out > /dev/null || cat ../out

  $ hg --profile --config profiling.output=../out st
  $ grep CallCount ../out > /dev/null || cat ../out

  $ hg --profile --config profiling.output=blackbox --config extensions.blackbox= st
  $ grep CallCount .hg/blackbox.log > /dev/null || cat .hg/blackbox.log

  $ hg --profile --config profiling.format=text st 2>../out
  $ grep CallCount ../out > /dev/null || cat ../out

  $ echo "[profiling]" >> $HGRCPATH
  $ echo "format=kcachegrind" >> $HGRCPATH

  $ hg --profile st 2>../out
  $ grep 'events: Ticks' ../out > /dev/null || cat ../out

  $ hg --profile --config profiling.output=../out st
  $ grep 'events: Ticks' ../out > /dev/null || cat ../out

#endif

  $ cd ..