Mercurial > hg
view tests/test-ssh-bundle1.t @ 44950:f9734b2d59cc
py3: make stdout line-buffered if connected to a TTY
Status messages that are to be shown on the terminal should be written to the
file descriptor before anything further is done, to keep the user updated.
One common way to achieve this is to make stdout line-buffered if it is
connected to a TTY. This is done on Python 2 (except on Windows, where libc,
which the CPython 2 streams depend on, does not properly support this).
Python 3 rolls it own I/O streams. On Python 3, buffered binary streams can't be
set line-buffered. The previous code (added in 227ba1afcb65) incorrectly
assumed that on Python 3, pycompat.stdout (sys.stdout.buffer) is already
line-buffered. However the interpreter initializes it with a block-buffered
stream or an unbuffered stream (when the -u option or the PYTHONUNBUFFERED
environment variable is set), never with a line-buffered stream.
One example where the current behavior is unacceptable is when running
`hg pull https://www.mercurial-scm.org/repo/hg` on Python 3, where the line
"pulling from https://www.mercurial-scm.org/repo/hg" does not appear on the
terminal before the hg process blocks while waiting for the server.
Various approaches to fix this problem are possible, including:
1. Weaken the contract of procutil.stdout to not give any guarantees about
buffering behavior. In this case, users of procutil.stdout need to be
changed to do enough flushes. In particular,
1. either ui must insert enough flushes for ui.write() and friends, or
2. ui.write() and friends get split into flushing and fully buffered
methods, or
3. users of ui.write() and friends must flush explicitly.
2. Make stdout unbuffered.
3. Make stdout line-buffered. Since Python 3 does not natively support that for
binary streams, we must implement it ourselves.
(2.) is problematic because using unbuffered I/O changes the performance
characteristics significantly compared to line-buffered (which is used on
Python 2) and this would be a regression.
(1.2.) and (1.3) are a substantial amount of work. It’s unclear whether the
added complexity would be justified, given that raw performance doesn’t matter
that much when writing to a terminal much faster than the user could read it.
(1.1.) pushes complexity into the ui class instead of separating the concern of
how stdout is buffered. Other users of procutil.stdout would still need to take
care of the flushes.
This patch implements (3.). The general performance considerations are very
similar to (1.1.). The extra method invocation and method forwarding add a
little more overhead if the class is used. In exchange, it doesn’t add overhead
if not used.
For the benchmarks, I compared the previous implementation (incorrect on Python
3), (1.1.), (3.) and (2.). The command was chosen so that the streams were
configured as if they were writing to a TTY, but actually write to a pager,
which is also the default:
HGRCPATH=/dev/null python3 ./hg --cwd ~/vcs/mozilla-central --time --pager yes --config pager.pager='cat > /dev/null' status --all
previous:
time: real 7.880 secs (user 7.290+0.050 sys 0.580+0.170)
time: real 7.830 secs (user 7.220+0.070 sys 0.590+0.140)
time: real 7.800 secs (user 7.210+0.050 sys 0.570+0.170)
(1.1.) using Yuya Nishihara’s patch:
time: real 9.860 secs (user 8.670+0.350 sys 1.160+0.830)
time: real 9.540 secs (user 8.430+0.370 sys 1.100+0.770)
time: real 9.830 secs (user 8.630+0.370 sys 1.180+0.840)
(3.) using this patch:
time: real 9.580 secs (user 8.480+0.350 sys 1.090+0.770)
time: real 9.670 secs (user 8.480+0.330 sys 1.170+0.860)
time: real 9.640 secs (user 8.500+0.350 sys 1.130+0.810)
(2.) using a previous patch by me:
time: real 10.480 secs (user 8.850+0.720 sys 1.590+1.500)
time: real 10.490 secs (user 8.750+0.750 sys 1.710+1.470)
time: real 10.240 secs (user 8.600+0.700 sys 1.590+1.510)
As expected, there’s no difference on Python 2, as exactly the same code paths
are used:
previous:
time: real 6.950 secs (user 5.870+0.330 sys 1.070+0.770)
time: real 7.040 secs (user 6.040+0.360 sys 0.980+0.750)
time: real 7.070 secs (user 5.950+0.360 sys 1.100+0.760)
this patch:
time: real 7.010 secs (user 5.900+0.390 sys 1.070+0.730)
time: real 7.000 secs (user 5.850+0.350 sys 1.120+0.760)
time: real 7.000 secs (user 5.790+0.380 sys 1.170+0.710)
author | Manuel Jacob <me@manueljacob.de> |
---|---|
date | Wed, 10 Jun 2020 13:02:39 +0200 |
parents | edc8504bc26b |
children | d68618954ade |
line wrap: on
line source
This test is a duplicate of 'test-http.t' feel free to factor out parts that are not bundle1/bundle2 specific. #testcases sshv1 sshv2 #if sshv2 $ cat >> $HGRCPATH << EOF > [experimental] > sshpeer.advertise-v2 = true > sshserver.support-v2 = true > EOF #endif $ cat << EOF >> $HGRCPATH > [devel] > # This test is dedicated to interaction through old bundle > legacy.exchange = bundle1 > EOF This test tries to exercise the ssh functionality with a dummy script creating 'remote' repo $ hg init remote $ cd remote $ echo this > foo $ echo this > fooO $ hg ci -A -m "init" foo fooO insert a closed branch (issue4428) $ hg up null 0 files updated, 0 files merged, 2 files removed, 0 files unresolved $ hg branch closed marked working directory as branch closed (branches are permanent and global, did you want a bookmark?) $ hg ci -mc0 $ hg ci --close-branch -mc1 $ hg up -q default configure for serving $ cat <<EOF > .hg/hgrc > [server] > uncompressed = True > > [hooks] > changegroup = sh -c "printenv.py --line changegroup-in-remote 0 ../dummylog" > EOF $ cd $TESTTMP repo not found error $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/nonexistent local remote: abort: repository nonexistent not found! abort: no suitable response from remote hg! [255] non-existent absolute path #if no-msys $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy//`pwd`/nonexistent local remote: abort: repository /$TESTTMP/nonexistent not found! abort: no suitable response from remote hg! [255] #endif clone remote via stream #if no-reposimplestore $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" --stream ssh://user@dummy/remote local-stream streaming all changes 4 files to transfer, 602 bytes of data transferred 602 bytes in * seconds (*) (glob) searching for changes no changes found updating to branch default 2 files updated, 0 files merged, 0 files removed, 0 files unresolved $ cd local-stream $ hg verify checking changesets checking manifests crosschecking files in changesets and manifests checking files checked 3 changesets with 2 changes to 2 files $ hg branches default 0:1160648e36ce $ cd $TESTTMP clone bookmarks via stream $ hg -R local-stream book mybook $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" --stream ssh://user@dummy/local-stream stream2 streaming all changes 4 files to transfer, 602 bytes of data transferred 602 bytes in * seconds (*) (glob) searching for changes no changes found updating to branch default 2 files updated, 0 files merged, 0 files removed, 0 files unresolved $ cd stream2 $ hg book mybook 0:1160648e36ce $ cd $TESTTMP $ rm -rf local-stream stream2 #endif clone remote via pull $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/remote local requesting all changes adding changesets adding manifests adding file changes added 3 changesets with 2 changes to 2 files new changesets 1160648e36ce:ad076bfb429d updating to branch default 2 files updated, 0 files merged, 0 files removed, 0 files unresolved verify $ cd local $ hg verify checking changesets checking manifests crosschecking files in changesets and manifests checking files checked 3 changesets with 2 changes to 2 files $ cat >> .hg/hgrc <<EOF > [hooks] > changegroup = sh -c "printenv.py --line changegroup-in-local 0 ../dummylog" > EOF empty default pull $ hg paths default = ssh://user@dummy/remote $ hg pull -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" pulling from ssh://user@dummy/remote searching for changes no changes found pull from wrong ssh URL $ hg pull -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/doesnotexist pulling from ssh://user@dummy/doesnotexist remote: abort: repository doesnotexist not found! abort: no suitable response from remote hg! [255] local change $ echo bleah > foo $ hg ci -m "add" updating rc $ echo "default-push = ssh://user@dummy/remote" >> .hg/hgrc $ echo "[ui]" >> .hg/hgrc $ echo "ssh = \"$PYTHON\" \"$TESTDIR/dummyssh\"" >> .hg/hgrc find outgoing $ hg out ssh://user@dummy/remote comparing with ssh://user@dummy/remote searching for changes changeset: 3:a28a9d1a809c tag: tip parent: 0:1160648e36ce user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: add find incoming on the remote side $ hg incoming -R ../remote -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/local comparing with ssh://user@dummy/local searching for changes changeset: 3:a28a9d1a809c tag: tip parent: 0:1160648e36ce user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: add find incoming on the remote side (using absolute path) $ hg incoming -R ../remote -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" "ssh://user@dummy/`pwd`" comparing with ssh://user@dummy/$TESTTMP/local searching for changes changeset: 3:a28a9d1a809c tag: tip parent: 0:1160648e36ce user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: add push $ hg push pushing to ssh://user@dummy/remote searching for changes remote: adding changesets remote: adding manifests remote: adding file changes remote: added 1 changesets with 1 changes to 1 files $ cd $TESTTMP/remote check remote tip $ hg tip changeset: 3:a28a9d1a809c tag: tip parent: 0:1160648e36ce user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: add $ hg verify checking changesets checking manifests crosschecking files in changesets and manifests checking files checked 4 changesets with 3 changes to 2 files $ hg cat -r tip foo bleah $ echo z > z $ hg ci -A -m z z created new head test pushkeys and bookmarks $ cd $TESTTMP/local $ hg debugpushkey --config ui.ssh="\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/remote namespaces bookmarks namespaces phases $ hg book foo -r 0 $ hg out -B comparing with ssh://user@dummy/remote searching for changed bookmarks foo 1160648e36ce $ hg push -B foo pushing to ssh://user@dummy/remote searching for changes no changes found exporting bookmark foo [1] $ hg debugpushkey --config ui.ssh="\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/remote bookmarks foo 1160648e36cec0054048a7edc4110c6f84fde594 $ hg book -f foo $ hg push --traceback pushing to ssh://user@dummy/remote searching for changes no changes found updating bookmark foo [1] $ hg book -d foo $ hg in -B comparing with ssh://user@dummy/remote searching for changed bookmarks foo a28a9d1a809c $ hg book -f -r 0 foo $ hg pull -B foo pulling from ssh://user@dummy/remote no changes found updating bookmark foo $ hg book -d foo $ hg push -B foo pushing to ssh://user@dummy/remote searching for changes no changes found deleting remote bookmark foo [1] a bad, evil hook that prints to stdout $ cat <<EOF > $TESTTMP/badhook > import sys > sys.stdout.write("KABOOM\n") > EOF $ echo '[hooks]' >> ../remote/.hg/hgrc $ echo "changegroup.stdout = \"$PYTHON\" $TESTTMP/badhook" >> ../remote/.hg/hgrc $ echo r > r $ hg ci -A -m z r push should succeed even though it has an unexpected response $ hg push pushing to ssh://user@dummy/remote searching for changes remote has heads on branch 'default' that are not known locally: 6c0482d977a3 remote: adding changesets remote: adding manifests remote: adding file changes remote: added 1 changesets with 1 changes to 1 files remote: KABOOM $ hg -R ../remote heads changeset: 5:1383141674ec tag: tip parent: 3:a28a9d1a809c user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: z changeset: 4:6c0482d977a3 parent: 0:1160648e36ce user: test date: Thu Jan 01 00:00:00 1970 +0000 summary: z clone bookmarks $ hg -R ../remote bookmark test $ hg -R ../remote bookmarks * test 4:6c0482d977a3 $ hg clone -e "\"$PYTHON\" \"$TESTDIR/dummyssh\"" ssh://user@dummy/remote local-bookmarks requesting all changes adding changesets adding manifests adding file changes added 6 changesets with 5 changes to 4 files (+1 heads) new changesets 1160648e36ce:1383141674ec updating to branch default 3 files updated, 0 files merged, 0 files removed, 0 files unresolved $ hg -R local-bookmarks bookmarks test 4:6c0482d977a3 passwords in ssh urls are not supported (we use a glob here because different Python versions give different results here) $ hg push ssh://user:erroneouspwd@dummy/remote pushing to ssh://user:*@dummy/remote (glob) abort: password in URL not supported! [255] $ cd $TESTTMP hide outer repo $ hg init Test remote paths with spaces (issue2983): $ hg init --ssh "\"$PYTHON\" \"$TESTDIR/dummyssh\"" "ssh://user@dummy/a repo" $ touch "$TESTTMP/a repo/test" $ hg -R 'a repo' commit -A -m "test" adding test $ hg -R 'a repo' tag tag $ hg id --ssh "\"$PYTHON\" \"$TESTDIR/dummyssh\"" "ssh://user@dummy/a repo" 73649e48688a $ hg id --ssh "\"$PYTHON\" \"$TESTDIR/dummyssh\"" "ssh://user@dummy/a repo#noNoNO" abort: unknown revision 'noNoNO'! [255] Test (non-)escaping of remote paths with spaces when cloning (issue3145): $ hg clone --ssh "\"$PYTHON\" \"$TESTDIR/dummyssh\"" "ssh://user@dummy/a repo" destination directory: a repo abort: destination 'a repo' is not empty [255] Test hg-ssh using a helper script that will restore PYTHONPATH (which might have been cleared by a hg.exe wrapper) and invoke hg-ssh with the right parameters: $ cat > ssh.sh << EOF > userhost="\$1" > SSH_ORIGINAL_COMMAND="\$2" > export SSH_ORIGINAL_COMMAND > PYTHONPATH="$PYTHONPATH" > export PYTHONPATH > "$PYTHON" "$TESTDIR/../contrib/hg-ssh" "$TESTTMP/a repo" > EOF $ hg id --ssh "sh ssh.sh" "ssh://user@dummy/a repo" 73649e48688a $ hg id --ssh "sh ssh.sh" "ssh://user@dummy/a'repo" remote: Illegal repository "$TESTTMP/a'repo" abort: no suitable response from remote hg! [255] $ hg id --ssh "sh ssh.sh" --remotecmd hacking "ssh://user@dummy/a'repo" remote: Illegal command "hacking -R 'a'\''repo' serve --stdio" abort: no suitable response from remote hg! [255] $ SSH_ORIGINAL_COMMAND="'hg' serve -R 'a'repo' --stdio" "$PYTHON" "$TESTDIR/../contrib/hg-ssh" Illegal command "'hg' serve -R 'a'repo' --stdio": No closing quotation [255] Test hg-ssh in read-only mode: $ cat > ssh.sh << EOF > userhost="\$1" > SSH_ORIGINAL_COMMAND="\$2" > export SSH_ORIGINAL_COMMAND > PYTHONPATH="$PYTHONPATH" > export PYTHONPATH > "$PYTHON" "$TESTDIR/../contrib/hg-ssh" --read-only "$TESTTMP/remote" > EOF $ hg clone --ssh "sh ssh.sh" "ssh://user@dummy/$TESTTMP/remote" read-only-local requesting all changes adding changesets adding manifests adding file changes added 6 changesets with 5 changes to 4 files (+1 heads) new changesets 1160648e36ce:1383141674ec updating to branch default 3 files updated, 0 files merged, 0 files removed, 0 files unresolved $ cd read-only-local $ echo "baz" > bar $ hg ci -A -m "unpushable commit" bar $ hg push --ssh "sh ../ssh.sh" pushing to ssh://user@dummy/*/remote (glob) searching for changes remote: Permission denied remote: abort: pretxnopen.hg-ssh hook failed remote: Permission denied remote: pushkey-abort: prepushkey.hg-ssh hook failed updating 6c0482d977a3 to public failed! [1] $ cd $TESTTMP stderr from remote commands should be printed before stdout from local code (issue4336) $ hg clone remote stderr-ordering updating to branch default 3 files updated, 0 files merged, 0 files removed, 0 files unresolved $ cd stderr-ordering $ cat >> localwrite.py << EOF > from mercurial import exchange, extensions > > def wrappedpush(orig, repo, *args, **kwargs): > res = orig(repo, *args, **kwargs) > repo.ui.write(b'local stdout\n') > return res > > def extsetup(ui): > extensions.wrapfunction(exchange, b'push', wrappedpush) > EOF $ cat >> .hg/hgrc << EOF > [paths] > default-push = ssh://user@dummy/remote > [ui] > ssh = "$PYTHON" "$TESTDIR/dummyssh" > [extensions] > localwrite = localwrite.py > EOF $ echo localwrite > foo $ hg commit -m 'testing localwrite' $ hg push pushing to ssh://user@dummy/remote searching for changes remote: adding changesets remote: adding manifests remote: adding file changes remote: added 1 changesets with 1 changes to 1 files remote: KABOOM local stdout debug output $ hg pull --debug ssh://user@dummy/remote pulling from ssh://user@dummy/remote running .* ".*/dummyssh" ['"]user@dummy['"] ('|")hg -R remote serve --stdio('|") (re) sending upgrade request: * proto=exp-ssh-v2-0003 (glob) (sshv2 !) sending hello command sending between command remote: 463 (sshv1 !) protocol upgraded to exp-ssh-v2-0003 (sshv2 !) remote: capabilities: batch branchmap $USUAL_BUNDLE2_CAPS$ changegroupsubset getbundle known lookup protocaps pushkey streamreqs=generaldelta,revlogv1,sparserevlog unbundle=HG10GZ,HG10BZ,HG10UN unbundlehash remote: 1 (sshv1 !) sending protocaps command preparing listkeys for "bookmarks" sending listkeys command received listkey for "bookmarks": 45 bytes query 1; heads sending batch command searching for changes all remote heads known locally no changes found preparing listkeys for "phases" sending listkeys command received listkey for "phases": 15 bytes checking for updated bookmarks $ cd $TESTTMP $ cat dummylog Got arguments 1:user@dummy 2:hg -R nonexistent serve --stdio Got arguments 1:user@dummy 2:hg -R /$TESTTMP/nonexistent serve --stdio (no-msys !) Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R local-stream serve --stdio (no-reposimplestore !) Got arguments 1:user@dummy 2:hg -R remote serve --stdio (no-reposimplestore !) Got arguments 1:user@dummy 2:hg -R remote serve --stdio (no-reposimplestore !) Got arguments 1:user@dummy 2:hg -R doesnotexist serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R local serve --stdio Got arguments 1:user@dummy 2:hg -R $TESTTMP/local serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio changegroup-in-remote hook: HG_HOOKNAME=changegroup HG_HOOKTYPE=changegroup HG_NODE=a28a9d1a809cab7d4e2fde4bee738a9ede948b60 HG_NODE_LAST=a28a9d1a809cab7d4e2fde4bee738a9ede948b60 HG_SOURCE=serve HG_TXNID=TXN:$ID$ HG_TXNNAME=serve remote:ssh:$LOCALIP HG_URL=remote:ssh:$LOCALIP Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio changegroup-in-remote hook: HG_HOOKNAME=changegroup HG_HOOKTYPE=changegroup HG_NODE=1383141674ec756a6056f6a9097618482fe0f4a6 HG_NODE_LAST=1383141674ec756a6056f6a9097618482fe0f4a6 HG_SOURCE=serve HG_TXNID=TXN:$ID$ HG_TXNNAME=serve remote:ssh:$LOCALIP HG_URL=remote:ssh:$LOCALIP Got arguments 1:user@dummy 2:hg -R remote serve --stdio Got arguments 1:user@dummy 2:hg init 'a repo' Got arguments 1:user@dummy 2:hg -R 'a repo' serve --stdio Got arguments 1:user@dummy 2:hg -R 'a repo' serve --stdio Got arguments 1:user@dummy 2:hg -R 'a repo' serve --stdio Got arguments 1:user@dummy 2:hg -R 'a repo' serve --stdio Got arguments 1:user@dummy 2:hg -R remote serve --stdio changegroup-in-remote hook: HG_HOOKNAME=changegroup HG_HOOKTYPE=changegroup HG_NODE=65c38f4125f9602c8db4af56530cc221d93b8ef8 HG_NODE_LAST=65c38f4125f9602c8db4af56530cc221d93b8ef8 HG_SOURCE=serve HG_TXNID=TXN:$ID$ HG_TXNNAME=serve remote:ssh:$LOCALIP HG_URL=remote:ssh:$LOCALIP Got arguments 1:user@dummy 2:hg -R remote serve --stdio remote hook failure is attributed to remote $ cat > $TESTTMP/failhook << EOF > def hook(ui, repo, **kwargs): > ui.write(b'hook failure!\n') > ui.flush() > return 1 > EOF $ echo "pretxnchangegroup.fail = python:$TESTTMP/failhook:hook" >> remote/.hg/hgrc $ hg -q --config ui.ssh="\"$PYTHON\" $TESTDIR/dummyssh" clone ssh://user@dummy/remote hookout $ cd hookout $ touch hookfailure $ hg -q commit -A -m 'remote hook failure' $ hg --config ui.ssh="\"$PYTHON\" $TESTDIR/dummyssh" push pushing to ssh://user@dummy/remote searching for changes remote: adding changesets remote: adding manifests remote: adding file changes remote: hook failure! remote: transaction abort! remote: rollback completed remote: abort: pretxnchangegroup.fail hook failed [1] abort during pull is properly reported as such $ echo morefoo >> ../remote/foo $ hg -R ../remote commit --message "more foo to be pulled" $ cat >> ../remote/.hg/hgrc << EOF > [extensions] > crash = ${TESTDIR}/crashgetbundler.py > EOF $ hg --config ui.ssh="\"$PYTHON\" $TESTDIR/dummyssh" pull pulling from ssh://user@dummy/remote searching for changes adding changesets remote: abort: this is an exercise transaction abort! rollback completed abort: stream ended unexpectedly (got 0 bytes, expected 4) [255]