Patchwork Windows test suite timeouts

login
register
mail settings
Submitter Mads Kiilerich
Date Jan. 5, 2013, 2:04 a.m.
Message ID <50E78A3D.5090206@kiilerich.com>
Download mbox | patch
Permalink /patch/399/
State Not Applicable
Headers show

Comments

Mads Kiilerich - Jan. 5, 2013, 2:04 a.m.
Matt Harbison wrote, On 01/05/2013 01:35 AM:
> Mads Kiilerich wrote:
>> On 01/04/2013 04:06 AM, Matt Harbison wrote:
>>> Every so often, I've noticed that some tests on Windows will take a
>>> really long time, and then timeout:
>>>
>>> $ python run-tests.py -i test-largefiles.t
>>>
>>> ERROR: c:\Users\Matt\Projects\hg\tests\test-largefiles.t timed out
>>> t
>>> Failed test-largefiles.t: timed out
>>> # Ran 1 tests, 0 skipped, 1 failed.
>>>
>>> It seems like once this occurs, it will occur every time until a
>>> reboot. Some other tests (I randomly tried
>>> test-subrepo-deep-nested-change.t) run fine even after the timeout. I
>>> haven't noticed a pattern of events leading up to the problem.
>>>
>>> Is there something I can do to debug this?
>>
>> You could try to run run-tests with -d. That will show you were it is
>> hanging and give a hint what the problem could be. One reason could be a
>> hanging hg serve.
>>
>> /Mads
>
> This is curious... I got a ton out output and then it came grinding to 
> a halt:
>
> + hg pull ../e
> pulling from ../e
> searching for changes
> adding changesets
> adding manifests
> adding file changes
> added 2 changesets with 4 changes to 4 files (+1 heads)
> (run 'hg heads' to see heads, 'hg merge' to merge)
> caching new largefiles
> 2 largefiles cached
> + echo SALT1357343164.18 1147 0
> SALT1357343164.18 1147 0
> + hg merge
> merging sub/large4
> largefile sub/large4 has a merge conflict
> keep (l)ocal or take (o)ther?
>
> (the test file has 'l' hardcoded in it at the end of that last line).  
> I answered 'l' and ...

That is probably another bug. Tests are usually run with a closed stdin 
which isn't interactive, and ui.promptchoice() will thus automatically 
choose the default. The same should happen when running with -d.

Try something like this:



I guess the non-debug hangs you see could be caused by how run-tests 
reads from the process without using .communicate(). You could try 
something like this and see if it helps:

@@ -759,11 +760,8 @@ def run(cmd, wd, options, replacements):
          killdaemons()
          return ret

-    output = ''
-    proc.tochild.close()
-
      try:
-        output = proc.fromchild.read()
+        output, err = proc.communicate()
      except KeyboardInterrupt:
          vlog('# Handling keyboard interrupt')
          cleanup()

/Mads
Matt Harbison - Jan. 5, 2013, 2:42 a.m.
Mads Kiilerich wrote:
> Matt Harbison wrote, On 01/05/2013 01:35 AM:
>> Mads Kiilerich wrote:
>>> On 01/04/2013 04:06 AM, Matt Harbison wrote:
>>>> Every so often, I've noticed that some tests on Windows will take a
>>>> really long time, and then timeout:
>>>>
>>>> $ python run-tests.py -i test-largefiles.t
>>>>
>>>> ERROR: c:\Users\Matt\Projects\hg\tests\test-largefiles.t timed out
>>>> t
>>>> Failed test-largefiles.t: timed out
>>>> # Ran 1 tests, 0 skipped, 1 failed.
>>>>
>>>> It seems like once this occurs, it will occur every time until a
>>>> reboot. Some other tests (I randomly tried
>>>> test-subrepo-deep-nested-change.t) run fine even after the timeout. I
>>>> haven't noticed a pattern of events leading up to the problem.
>>>>
>>>> Is there something I can do to debug this?
>>>
>>> You could try to run run-tests with -d. That will show you were it is
>>> hanging and give a hint what the problem could be. One reason could be a
>>> hanging hg serve.
>>>
>>> /Mads
>>
>> This is curious... I got a ton out output and then it came grinding to
>> a halt:
>>
>> + hg pull ../e
>> pulling from ../e
>> searching for changes
>> adding changesets
>> adding manifests
>> adding file changes
>> added 2 changesets with 4 changes to 4 files (+1 heads)
>> (run 'hg heads' to see heads, 'hg merge' to merge)
>> caching new largefiles
>> 2 largefiles cached
>> + echo SALT1357343164.18 1147 0
>> SALT1357343164.18 1147 0
>> + hg merge
>> merging sub/large4
>> largefile sub/large4 has a merge conflict
>> keep (l)ocal or take (o)ther?
>>
>> (the test file has 'l' hardcoded in it at the end of that last line).
>> I answered 'l' and ...
>
> That is probably another bug. Tests are usually run with a closed stdin
> which isn't interactive, and ui.promptchoice() will thus automatically
> choose the default. The same should happen when running with -d.
>
> Try something like this:
>
> --- a/tests/run-tests.py
> +++ b/tests/run-tests.py
> @@ -746,7 +746,8 @@ def run(cmd, wd, options, replacements):
> Return a tuple (exitcode, output). output is None in debug mode."""
> # TODO: Use subprocess.Popen if we're running on Python 2.4
> if options.debug:
> - proc = subprocess.Popen(cmd, shell=True, cwd=wd)
> + proc = subprocess.Popen(cmd, shell=True, cwd=wd, stdin=subprocess.PIPE)
> + proc.stdin.close()
> ret = proc.wait()
> return (ret, None)

This by itself fixes the debug mode hang...

> I guess the non-debug hangs you see could be caused by how run-tests
> reads from the process without using .communicate(). You could try
> something like this and see if it helps:
>
> @@ -759,11 +760,8 @@ def run(cmd, wd, options, replacements):
> killdaemons()
> return ret
>
> - output = ''
> - proc.tochild.close()
> -
> try:
> - output = proc.fromchild.read()
> + output, err = proc.communicate()
> except KeyboardInterrupt:
> vlog('# Handling keyboard interrupt')
> cleanup()

... but this didn't help the non debug mode.  I'm not sure if this 
helps, but after the timeout, there is a test-largefiles.t.err that is 
an exact duplicate of the *.t that got run, and this gets regenerated 
each time.  So it seems like that means the full test runs.

--Matt

Patch

--- a/tests/run-tests.py
+++ b/tests/run-tests.py
@@ -746,7 +746,8 @@  def run(cmd, wd, options, replacements):
      Return a tuple (exitcode, output).  output is None in debug mode."""
      # TODO: Use subprocess.Popen if we're running on Python 2.4
      if options.debug:
-        proc = subprocess.Popen(cmd, shell=True, cwd=wd)
+        proc = subprocess.Popen(cmd, shell=True, cwd=wd, 
stdin=subprocess.PIPE)
+        proc.stdin.close()
          ret = proc.wait()
          return (ret, None)