D2720: debugcommands: introduce actions to perform deterministic reads
This revision was automatically updated to reflect the committed changes.
Closed by commit rHG143219fc2620: debugcommands: introduce actions to perform
deterministic reads (authored by indygreg, committed by ).
REPOSITORY
rHG Mercurial
CHANGES SINCE LAST UPDATE
https://phab.mercurial-scm.org/D2720?vs=6976=7153
REVISION DETAIL
https://phab.mercurial-scm.org/D2720
AFFECTED FILES
mercurial/debugcommands.py
CHANGE DETAILS
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2715,6 +2715,21 @@
Read a line of output from the server. If there are multiple output
pipes, reads only the main pipe.
+
+ereadline
+-
+
+Like ``readline``, but read from the stderr pipe, if available.
+
+read
+
+
+``read()`` N bytes from the server's main output pipe.
+
+eread
+-
+
+``read()`` N bytes from the server's stderr pipe, if available.
"""
opts = pycompat.byteskwargs(opts)
@@ -2855,6 +2870,14 @@
stderr.read()
elif action == 'readline':
stdout.readline()
+elif action == 'ereadline':
+stderr.readline()
+elif action.startswith('read '):
+count = int(action.split(' ', 1)[1])
+stdout.read(count)
+elif action.startswith('eread '):
+count = int(action.split(' ', 1)[1])
+stderr.read(count)
else:
raise error.Abort(_('unknown action: %s') % action)
To: indygreg, #hg-reviewers, durin42
Cc: yuja, mharbison72, mercurial-devel
___
Mercurial-devel mailing list
Mercurial-devel@mercurial-scm.org
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment. Sounds good to me. I think the only thing I have inflight is the patch with explicit flushes in the observer. I haven't tried Yuya's series yet, because I'm not sure where it fits into the other stuff inflight. I don't mind mopping this up after it lands. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: yuja, mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg added a subscriber: yuja. indygreg added a comment. I removed the test changes from this. So we should be able to land it without causing chaos to Windows tests. It may conflict with other patches that @yuja and @mharbison72 have in flight though. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: yuja, mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg updated this revision to Diff 6976.
indygreg edited the summary of this revision.
REPOSITORY
rHG Mercurial
CHANGES SINCE LAST UPDATE
https://phab.mercurial-scm.org/D2720?vs=6714=6976
REVISION DETAIL
https://phab.mercurial-scm.org/D2720
AFFECTED FILES
mercurial/debugcommands.py
CHANGE DETAILS
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2701,6 +2701,21 @@
Read a line of output from the server. If there are multiple output
pipes, reads only the main pipe.
+
+ereadline
+-
+
+Like ``readline``, but read from the stderr pipe, if available.
+
+read
+
+
+``read()`` N bytes from the server's main output pipe.
+
+eread
+-
+
+``read()`` N bytes from the server's stderr pipe, if available.
"""
opts = pycompat.byteskwargs(opts)
@@ -2841,6 +2856,14 @@
stderr.read()
elif action == 'readline':
stdout.readline()
+elif action == 'ereadline':
+stderr.readline()
+elif action.startswith('read '):
+count = int(action.split(' ', 1)[1])
+stdout.read(count)
+elif action.startswith('eread '):
+count = int(action.split(' ', 1)[1])
+stderr.read(count)
else:
raise error.Abort(_('unknown action: %s') % action)
To: indygreg, #hg-reviewers
Cc: mharbison72, mercurial-devel
___
Mercurial-devel mailing list
Mercurial-devel@mercurial-scm.org
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg added a comment. See the `contrib/showstack.py` extension for registering SIGQUIT and SIGINFO signals to dump the active stack. Not sure if that works on Windows though. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment. At this point, I've narrowed it down to stderr. I misunderstood the 'noreadstderr', and wondered why we were bothering to pipe stderr if True. So I set it to os.devnull, and the test sails through. (But it does drop all "e>" lines, so that's not an actual solution.) Is there some way to send a signal to a python process to get it to dump its stacks, like Ctrl+\ in java? Sprinkling random prints and flushes hasn't been fruitful so far. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment. > IDK if this means anything, but when it is stuck and I hit Ctrl+C, instead of terminating the test, the test simply continues with the script, and then hangs on the next 'remote output:' line. Typically, Ctrl+C ends the test runner. A couple of more tidbits on this: 1. When I hit Ctrl+C, it *does* print the shell prompt, but the process keeps printing test output after it, so I missed it. When it jams, I can hit Ctrl+C again to get it going again. 2. I did that all the way through the test, and eventually it got to the last one, which prints: i> write(2) -> 2: i> 0\n i> flush() -> None o> readline() -> 2: o> 0\n o> readline() -> 2: o> 1\n o> read(1) -> 1: 1 result: 1 remote output: e> read(152) -> 152: e> adding changesets\n e> adding manifests\n e> adding file changes\n e> added 1 changesets with 1 changes to 1 files\n e> ui.write 1\n e> ui.write_err 1\n e> ui.write 2\n e> ui.write_err 2\n + '[' -n 1 ']' + hg --config extensions.strip= strip --no-backup -r 'all() - ::' + echo SALT1520635194 2034 0 SALT1520635194 2034 0 Note the exit code is 1 here. So is it possible that the debug command is having trouble reading bytes from an empty stderr in the initial cases? REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment. In https://phab.mercurial-scm.org/D2720#44396, @indygreg wrote: > My only explanation is this is stdout output buffering and things are really hanging on the next read operation. > > Maybe try sprinkling some `ui.fout.flush()` and/or `util.stdout.flush()` and/or `sys.stdout.flush()` calls throughout the debug command? Maybe at the first thing in the loop that evaluates commands to execute? Both `util.stdout.flush()` and `ui.fout.flush()` get a little further in the same command; `sys.stdout.flush()` has no effect, when added at the top of the loop. But then it stalls on remote output: ... o> readline() -> 2: o> 0\n i> write(4) -> 4: i> 426\n i> write(426) -> 426: i> HG10UN\x00\x00\x00\x9eh\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x0 0\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\ x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\ x00>cba485ca3678256e044428f70f58291196f6e9de\n i> test\n i> 0 0\n i> foo\n i> \n i> initial\x00\x00\x00\x00\x00\x00\x00\x8d\xcb\xa4\x85\xca6x%n\x04D(\xf7\x0fX)\x11\x96\xf6\xe9\xde\x00\x00 \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x 00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x 00\x00\x00\x00\x00\x00\x00-foo\x00362fef284ce2ca02aecc8de6d5e8a1c3af0556fe\n i> \x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00b6/\xef(L\xe2\xca\x02\xae\xcc\x8d\xe6\xd5\xe8\xa1\xc3\xa f\x05V\xfe\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00 \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f \x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x020\n i> \x00\x00\x00\x00\x00\x00\x00\x00 i> write(2) -> 2: i> 0\n i> flush() -> None o> readline() -> 2: o> 0\n o> readline() -> 2: o> 1\n o> read(1) -> 1: 0 result: 0 remote output: So I added a self.flush() inside ui._write() because I figured this is a problem on the remote end (and probably not localized like the debug command), but that didn't do anything. (ui._write_err() already flushes, and has a comment about stderr may be buffered on Windows.) IDK if this means anything, but when it is stuck and I hit Ctrl + C, instead of terminating the test, the test simply continues with the script, and then hangs on the next 'remote output:' line. Typically, Ctrl + C ends the test runner. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg added a comment. My only explanation is this is stdout output buffering and things are really hanging on the next read operation. Maybe try sprinkling some `ui.fout.flush()` and/or `util.stdout.flush()` and/or `sys.stdout.flush()` calls throughout the debug command? Maybe at the first thing in the loop that evaluates commands to execute? REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment.
In https://phab.mercurial-scm.org/D2720#44350, @indygreg wrote:
> In https://phab.mercurial-scm.org/D2720#44293, @mharbison72 wrote:
>
> > i> write(4) -> 4:
> > i> 426\n
> > i> write(426) -> 426:
> > i>
HG10UN\x00\x00\x00\x9eh\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x0
> >
0\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> >
x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> > x00>cba485ca3678256e044428f70f58291196f6e9de\n
> > i> test\n
> > i> 0 0\n
> > i> foo\n
> > i> \n
> > i>
initial\x00\x00\x00\x00\x00\x00\x00\x8d\xcb\xa4\x85\xca6x%n\x04D(\xf7\x0fX)\x11\x96\xf6\xe9\xde\x00\x00
> >
\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x
> >
00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x
> >
00\x00\x00\x00\x00\x00\x00-foo\x00362fef284ce2ca02aecc8de6d5e8a1c3af0556fe\n
> > i>
\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00b6/\xef(L\xe2\xca\x02\xae\xcc\x8d\xe6\xd5\xe8\xa1\xc3\xa
> >
f\x05V\xfe\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
> > \x00\x00\x00\x00\x00\x00\x00\x00\
> >
> >
>
>
> This is a wonky place to hang! For context, this is processing a `command
unbundle` line. The lines that follow should be:
>
> i> write(2) -> 2:
> i> 0\n
> i> flush() -> None
> o> readline() -> 2:
> o> 0\n
> o> readline() -> 2:
> o> 1\n
> o> read(1) -> 1: 0
> result: 0
> remote output:
> e> read(115) -> 115:
> e> abort: incompatible Mercurial client; bundle2 required\n
> e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n
>
>
> What happens under the hood during pushes is we send out chunks containing
the bundle followed by an empty chunk. That code is:
>
> for d in iter(lambda: fp.read(4096), ''):
> self._writeframed(d)
> self._writeframed("", flush=True)
>
>
> That empty chunk is apparently not getting sent. Or its logging is not
getting written/printed.
>
> This patch shouldn't have changed any behavior with regard to this part of
the I/O. So I'm scratching my head over how this caused deadlock. Are you sure
you can bisect it to this patch.
Yep. I imported this with `hg phapread --stack`, and can run the
https://phab.mercurial-scm.org/D2719 in 50 seconds or so. The debug run of
this I let hang out for 20 minutes before killing it.
Here's the neighboring failure from https://phab.mercurial-scm.org/D2719,
because I can't explain the AWOL output. (But that shouldn't have stopped
stdout above mid stream.)
--- e:/Projects/hg/tests/test-ssh-proto-unbundle.t
+++ e:/Projects/hg/tests/test-ssh-proto-unbundle.t.err
@@ -93,9 +93,6 @@
o> read(1) -> 1: 0
result: 0
remote output:
- e> read(-1) -> 115:
- e> abort: incompatible Mercurial client; bundle2 required\n
- e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n
testing ssh2
creating ssh peer from handshake results
@@ -143,9 +140,6 @@
o> read(1) -> 1: 0
result: 0
remote output:
- e> read(-1) -> 115:
- e> abort: incompatible Mercurial client; bundle2 required\n
- e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n
$ cd ..
REPOSITORY
rHG Mercurial
REVISION DETAIL
https://phab.mercurial-scm.org/D2720
To: indygreg, #hg-reviewers
Cc: mharbison72, mercurial-devel
___
Mercurial-devel mailing list
Mercurial-devel@mercurial-scm.org
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg added a comment.
In https://phab.mercurial-scm.org/D2720#44293, @mharbison72 wrote:
> i> write(4) -> 4:
> i> 426\n
> i> write(426) -> 426:
> i>
HG10UN\x00\x00\x00\x9eh\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x0
>
0\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
>
x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
> x00>cba485ca3678256e044428f70f58291196f6e9de\n
> i> test\n
> i> 0 0\n
> i> foo\n
> i> \n
> i>
initial\x00\x00\x00\x00\x00\x00\x00\x8d\xcb\xa4\x85\xca6x%n\x04D(\xf7\x0fX)\x11\x96\xf6\xe9\xde\x00\x00
>
\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x
>
00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x
>
00\x00\x00\x00\x00\x00\x00-foo\x00362fef284ce2ca02aecc8de6d5e8a1c3af0556fe\n
> i>
\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00b6/\xef(L\xe2\xca\x02\xae\xcc\x8d\xe6\xd5\xe8\xa1\xc3\xa
>
f\x05V\xfe\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
> \x00\x00\x00\x00\x00\x00\x00\x00\
>
>
This is a wonky place to hang! For context, this is processing a `command
unbundle` line. The lines that follow should be:
i> write(2) -> 2:
i> 0\n
i> flush() -> None
o> readline() -> 2:
o> 0\n
o> readline() -> 2:
o> 1\n
o> read(1) -> 1: 0
result: 0
remote output:
e> read(115) -> 115:
e> abort: incompatible Mercurial client; bundle2 required\n
e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n
What happens under the hood during pushes is we send out chunks containing
the bundle followed by an empty chunk. That code is:
for d in iter(lambda: fp.read(4096), ''):
self._writeframed(d)
self._writeframed("", flush=True)
That empty chunk is apparently not getting sent. Or its logging is not
getting written/printed.
This patch shouldn't have changed any behavior with regard to this part of
the I/O. So I'm scratching my head over how this caused deadlock. Are you sure
you can bisect it to this patch.
REPOSITORY
rHG Mercurial
REVISION DETAIL
https://phab.mercurial-scm.org/D2720
To: indygreg, #hg-reviewers
Cc: mharbison72, mercurial-devel
___
Mercurial-devel mailing list
Mercurial-devel@mercurial-scm.org
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment.
In https://phab.mercurial-scm.org/D2720#44288, @indygreg wrote:
> In https://phab.mercurial-scm.org/D2720#44221, @mharbison72 wrote:
>
> > This patch seems to deadlock on Windows when running
test-ssh-proto-unbundle.t. There are two python processes idling:
> >
> > Past experience says that something needs to be flushed- stdout (and
maybe stderr?) are full buffered on Windows IIRC. The following failure with
this patch might also point to that:
>
>
> Hmmm.
>
> We explicitly create the pipes between the processes as unbuffered
(`bufsize=0`). That being said, I would not at all be surprised if we need to
throw a `flush()` in here somewhere.
>
> Could you please run the test with `run-tests.py -d` and see where it is
deadlocking?
>
> The test failure due to the `o>` block is likely due to buffering or a race
condition when writing to stdout of the `hg debugwireproto` process. I'll look
into that after we fix the deadlock (since fixing might change order of things
and I don't want to debug this in a system that is changing).
It looks like the middle of line 84. Here's the relevant output, from the
start of the stuck command on 43 (the off-by-one in the SALT line is odd, but
the other lines are line that too, so I assume it's a zero based index thing):
+ echo SALT1520615870 42 0
SALT1520615870 42 0
+ debugwireproto
++ cat -
+ commands='command unbundle
# This is "force" in hex.
heads 666f726365
PUSHFILE ../initial.v1.hg
eread 115'
+ echo 'testing ssh1'
testing ssh1
++ hg log -r tip -T '{node}'
+ tip=
+ echo 'command unbundle
# This is "force" in hex.
heads 666f726365
PUSHFILE ../initial.v1.hg
eread 115'
+ hg --verbose debugwireproto --localssh --noreadstderr
creating ssh peer from handshake results
i> write(104) -> 104:
i> hello\n
i> between\n
i> pairs 81\n
i>
-
i> flush() -> None
o> readline() -> 4:
o> 384\n
o> readline() -> 384:
o> capabilities: lookup branchmap pushkey known getbundle unbundlehash
batch changegroupsubset streamreqs=
generaldelta,revlogv1
bundle2=HG20%0Abookmarks%0Achangegroup%3D01%2C02%0Adigests%3Dmd5%2Csha1%2Csha512%0Aerror
%3Dabort%2Cunsupportedcontent%2Cpushraced%2Cpushkey%0Ahgtagsfnodes%0Alistkeys%0Aphases%3Dheads%0Apushkey%0Arem
ote-changegroup%3Dhttp%2Chttps unbundle=HG10GZ,HG10BZ,HG10UN\n
o> readline() -> 2:
o> 1\n
o> readline() -> 1:
o> \n
sending unbundle command
i> write(9) -> 9:
i> unbundle\n
i> write(9) -> 9:
i> heads 10\n
i> write(10) -> 10: 666f726365
i> flush() -> None
o> readline() -> 2:
o> 0\n
i> write(4) -> 4:
i> 426\n
i> write(426) -> 426:
i>
HG10UN\x00\x00\x00\x9eh\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x0
0\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\
x00>cba485ca3678256e044428f70f58291196f6e9de\n
i> test\n
i> 0 0\n
i> foo\n
i> \n
i>
initial\x00\x00\x00\x00\x00\x00\x00\x8d\xcb\xa4\x85\xca6x%n\x04D(\xf7\x0fX)\x11\x96\xf6\xe9\xde\x00\x00
\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x
00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00h\x98b\x13\xbdD\x85\xeaQS55\xe3\xfc\x9ex\x00zq\x1f\x00\x00\x00\x00\x
00\x00\x00\x00\x00\x00\x00-foo\x00362fef284ce2ca02aecc8de6d5e8a1c3af0556fe\n
i>
\x00\x00\x00\x00\x00\x00\x00\x07foo\x00\x00\x00b6/\xef(L\xe2\xca\x02\xae\xcc\x8d\xe6\xd5\xe8\xa1\xc3\xa
f\x05V\xfe\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00
\x00\x00\x00\x00\x00\x00\x00\x00\
REPOSITORY
rHG Mercurial
REVISION DETAIL
https://phab.mercurial-scm.org/D2720
To: indygreg, #hg-reviewers
Cc: mharbison72, mercurial-devel
___
Mercurial-devel mailing list
Mercurial-devel@mercurial-scm.org
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg added a comment. In https://phab.mercurial-scm.org/D2720#44221, @mharbison72 wrote: > This patch seems to deadlock on Windows when running test-ssh-proto-unbundle.t. There are two python processes idling: > > Past experience says that something needs to be flushed- stdout (and maybe stderr?) are full buffered on Windows IIRC. The following failure with this patch might also point to that: Hmmm. We explicitly create the pipes between the processes as unbuffered (`bufsize=0`). That being said, I would not at all be surprised if we need to throw a `flush()` in here somewhere. Could you please run the test with `run-tests.py -d` and see where it is deadlocking? The test failure due to the `o>` block is likely due to buffering or a race condition when writing to stdout of the `hg debugwireproto` process. I'll look into that after we fix the deadlock (since fixing might change order of things and I don't want to debug this in a system that is changing). REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
mharbison72 added a comment. This patch seems to deadlock on Windows when running test-ssh-proto-unbundle.t. There are two python processes idling: c:\Python27\python.exe c:/Users/Matt/projects/hg/hg --verbose debugwireproto --localssh --noreadstderr CWD: C:\Users\Matt\AppData\Local\Temp\hgtests.1mtivg\child1\test-ssh-proto-unbundle.t\no-bundle1\ and c:\Python27\python.exe c:/Users/Matt/projects/hg/hg -R C:\Users\Matt\AppData\Local\Temp\hgtests.1mtivg\child1\test-ssh-proto-unbundle.t\no-bundle1 debugserve --sshstdio CWD: C:\Users\Matt\AppData\Local\Temp\hgtests.1mtivg\child1\test-ssh-proto-unbundle.t\no-bundle1\ Past experience says that something needs to be flushed- stdout (and maybe stderr?) are full buffered on Windows IIRC. The following failure with this patch might also point to that: --- c:/Users/Matt/projects/hg/tests/test-ssh-proto.t +++ c:/Users/Matt/projects/hg/tests/test-ssh-proto.t.err @@ -100,12 +100,12 @@ $ hg debugserve --sshstdio --logiofd 1 << EOF > hello > EOF - o> write(4) -> 4: - o> 384\n - o> write(384) -> 384: - o> capabilities: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$unbundle=HG10GZ,HG10BZ,HG10UN\n 384 capabilities: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN + o> write(4) -> 4: + o> 384\n + o> write(384) -> 384: + o> capabilities: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN\n o> flush() -> None $ hg debugserve --sshstdio --logiofile $TESTTMP/io << EOF REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 To: indygreg, #hg-reviewers Cc: mharbison72, mercurial-devel ___ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
D2720: debugcommands: introduce actions to perform deterministic reads
indygreg created this revision. Herald added a subscriber: mercurial-devel. Herald added a reviewer: hg-reviewers. REVISION SUMMARY "readavailable" is useful as a debugging device to see what data is available on a pipe. But the mechanism isn't deterministic because what's available on a pipe is highly conditional on timing, system load, OS behavior, etc. This makes it not suitable for tests. We introduce "ereadline," "read," and "eread" for performing deterministic I/O operations (at least on blocking file descriptors). We convert uses of "readavailable" in tests to use the new primitives. This should hopefully make these tests deterministic. REPOSITORY rHG Mercurial REVISION DETAIL https://phab.mercurial-scm.org/D2720 AFFECTED FILES mercurial/debugcommands.py tests/test-ssh-proto-unbundle.t tests/test-ssh-proto.t CHANGE DETAILS diff --git a/tests/test-ssh-proto.t b/tests/test-ssh-proto.t --- a/tests/test-ssh-proto.t +++ b/tests/test-ssh-proto.t @@ -1118,7 +1118,8 @@ > upgrade another-token proto=irrelevant\n > hello\n > readline - > readavailable + > ereadline + > ereadline > EOF using raw connection to peer i> write(153) -> 153: @@ -1138,8 +1139,9 @@ i> hello\n o> readline() -> 1: o> \n - e> read(-1) -> 42: + e> readline() -> 40: e> cannot upgrade protocols multiple times\n + e> readline() -> 2: e> -\n Malformed upgrade request line (not exactly 3 space delimited tokens) @@ -1221,35 +1223,39 @@ > upgrade token proto=exp-ssh-v2-0001\n > invalid\n > readline - > readavailable + > ereadline + > ereadline > EOF using raw connection to peer i> write(44) -> 44: i> upgrade token proto=exp-ssh-v2-0001\n i> invalid\n o> readline() -> 1: o> \n - e> read(-1) -> 46: + e> readline() -> 44: e> malformed handshake protocol: missing hello\n + e> readline() -> 2: e> -\n $ hg debugwireproto --localssh --peer raw << EOF > raw > upgrade token proto=exp-ssh-v2-0001\n > hello\n > invalid\n > readline - > readavailable + > ereadline + > ereadline > EOF using raw connection to peer i> write(50) -> 50: i> upgrade token proto=exp-ssh-v2-0001\n i> hello\n i> invalid\n o> readline() -> 1: o> \n - e> read(-1) -> 48: + e> readline() -> 46: e> malformed handshake protocol: missing between\n + e> readline() -> 2: e> -\n $ hg debugwireproto --localssh --peer raw << EOF @@ -1259,7 +1265,8 @@ > between\n > invalid\n > readline - > readavailable + > ereadline + > ereadline > EOF using raw connection to peer i> write(58) -> 58: @@ -1269,8 +1276,9 @@ i> invalid\n o> readline() -> 1: o> \n - e> read(-1) -> 49: + e> readline() -> 47: e> malformed handshake protocol: missing pairs 81\n + e> readline() -> 2: e> -\n Legacy commands are not exposed to version 2 of protocol diff --git a/tests/test-ssh-proto-unbundle.t b/tests/test-ssh-proto-unbundle.t --- a/tests/test-ssh-proto-unbundle.t +++ b/tests/test-ssh-proto-unbundle.t @@ -45,7 +45,7 @@ > # This is "force" in hex. > heads 666f726365 > PUSHFILE ../initial.v1.hg - > readavailable + > eread 115 > EOF testing ssh1 creating ssh peer from handshake results @@ -93,7 +93,7 @@ o> read(1) -> 1: 0 result: 0 remote output: - e> read(-1) -> 115: + e> read(115) -> 115: e> abort: incompatible Mercurial client; bundle2 required\n e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n @@ -143,7 +143,7 @@ o> read(1) -> 1: 0 result: 0 remote output: - e> read(-1) -> 115: + e> read(115) -> 115: e> abort: incompatible Mercurial client; bundle2 required\n e> (see https://www.mercurial-scm.org/wiki/IncompatibleClient)\n @@ -212,7 +212,7 @@ > # This is "force" in hex. > heads 666f726365 > PUSHFILE ../initial.v1.hg - > readavailable + > eread 196 > EOF testing ssh1 creating ssh peer from handshake results @@ -260,7 +260,7 @@ o> read(1) -> 1: 0 result: 0 remote output: - e> read(-1) -> 196: + e> read(196) -> 196: e> adding changesets\n e> adding manifests\n e> adding file changes\n @@ -316,7 +316,7 @@ o> read(1) -> 1: 0 result: 0 remote output: - e> read(-1) -> 196: + e> read(196) -> 196: e> adding changesets\n e> adding manifests\n e> adding file changes\n @@ -338,7 +338,7 @@ > # This is "force" in hex. > heads 666f726365 > PUSHFILE ../initial.v1.hg - > readavailable + > eread 218 > EOF testing ssh1 creating ssh peer from handshake results @@ -386,7 +386,7 @@ o> read(1) -> 1: 0 result: 0 remote output: - e> read(-1) -> 218: + e> read(218) -> 218: e> adding changesets\n e> adding manifests\n e> adding file changes\n @@ -443,7 +443,7 @@ o>
