classification
Title: test_asyncio hanging for 1 hour (non-AIX version)
Type: behavior Stage:
Components: Versions: Python 3.4
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: David.Edelsohn, db3l, gvanrossum, koobs, larry, ncoghlan, neologix, pitrou, python-dev, sbt, skrah, vstinner
Priority: normal Keywords:

Created on 2013-10-21 14:45 by gvanrossum, last changed 2014-02-03 01:30 by vstinner. This issue is now closed.

Files
File name Uploaded Description Edit
koobs-freebsd9-py3x-build180.log koobs, 2013-10-22 08:27
Messages (17)
msg200790 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2013-10-21 14:45
There are still some problems with asyncio tests hanging on FreeBSD and possibly other platforms.

While these were originally conflated with a hang on AIX, the root causes are different; just the symptoms are the same (the test hangs forever and after exactly one hour the test runner kills the process).

I'm opening a new issue to discuss the issues on platforms other than AIX.
msg200850 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2013-10-21 21:24
I haven't seen any such hangs. I've seen one test_asyncio failure on FreeBSD 6.4 3.x, which is the following weirdness.

http://buildbot.python.org/all/builders/x86%20FreeBSD%206.4%203.x/builds/4116/steps/test/logs/stdio

test test_asyncio crashed -- Traceback (most recent call last):
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/test/regrtest.py", line 1276, in runtest_inner
    test_runner()
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/test/test_asyncio/__init__.py", line 31, in test_main
    run_unittest(suite())
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/test/test_asyncio/__init__.py", line 21, in suite
    __import__(mod_name)
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/test/test_asyncio/test_base_events.py", line 10, in <module>
    from asyncio import base_events
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/asyncio/__init__.py", line 13, in <module>
    from .futures import *
  File "/usr/home/db3l/buildarea/3.x.bolen-freebsd/build/Lib/asyncio/futures.py", line 12, in <module>
    from . import events
ImportError: cannot import name 'events'

Sadly there's no more info about this -- does this mean events.py is corrupt? Or is one of the imports in events.py breaking? Then why doesn't it show the failing line?
msg200890 - (view) Author: Kubilay Kocak (koobs) (Python triager) Date: 2013-10-22 08:27
The original report and build logs were attached to the original issue covering the import of asyncio: #19262

Also attaching here.
msg200893 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-22 08:28
The hangs have been sporadic:
http://buildbot.python.org/all/builders/x86%20RHEL%206%203.x/builds/2916/steps/test/logs/stdio
http://buildbot.python.org/all/builders/x86%20Ubuntu%20Shared%203.x/builds/8795/steps/test/logs/stdio

Perhaps Nick can run test_subprocess_close_after_finish in a loop and tell us if the issue still happens.
msg200894 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-22 08:29
Hmm, test_signal_handling_while_selecting is a different one. Perhaps koobs can investigate it :)
msg200897 - (view) Author: Kubilay Kocak (koobs) (Python triager) Date: 2013-10-22 09:03
@antoine, would love some direction/guidance on ways to isolate.

For what it's worth, the incidence of this failure dropped sharply over the subsequent 24 hours after the initial report. Could the relaxation of the timers in 042deeeb703 have had an effect?

Thus far I've checked out default, and ran test_asyncio at -j16 -j32 and -j64 with no reproduction
msg200898 - (view) Author: Kubilay Kocak (koobs) (Python triager) Date: 2013-10-22 09:07
Correct changeset ID: e042deeeb703
msg200900 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-10-22 09:16
> Thus far I've checked out default, and ran test_asyncio at -j16 -j32
> and -j64 with no reproduction

you can use -F to run the test forever.
msg200951 - (view) Author: Nick Coghlan (ncoghlan) * (Python committer) Date: 2013-10-22 13:47
I started "strace ./python -m test -vF test_asyncio" running under screen on the RHEL6 buildbot (so it will keep running when I log out in a moment).

If I don't report back the results in the next day or two, ping the issue to remind me to log back in and see if it eventually got stuck.
msg200962 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-10-22 14:29
> I started "strace ./python -m test -vF test_asyncio" running under screen on the RHEL6 buildbot (so it will keep running when I log out in a moment).

Trace also child processes: add -f. And add maybe also timestamps: -tt.
msg203359 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-11-19 11:20
I created the issue #19652: test_asyncio: test_subprocess_send_signal() hangs on buildbot "AMD64 Snow Leop 3.x".
msg203360 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2013-11-19 11:21
> The original report and build logs were attached to the original issue covering the import of asyncio: #19262
> Also attaching here.

Extract of the most important part:

[382/382] test_asyncio
Timeout (1:00:00)!
Thread 0x0000000805c18000:
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/threading.py", line 290 in wait
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/queue.py", line 167 in get
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/concurrent/futures/thread.py", line 63 in _worker
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/threading.py", line 869 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/threading.py", line 921 in _bootstrap_inner
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/threading.py", line 889 in _bootstrap

Thread 0x0000000801407400:
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/selectors.py", line 265 in select
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/asyncio/base_events.py", line 576 in _run_once
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/asyncio/base_events.py", line 153 in run_forever
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/test_asyncio/test_events.py", line 450 in test_signal_handling_while_selecting
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/case.py", line 571 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/case.py", line 610 in __call__
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 117 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 79 in __call__
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 117 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 79 in __call__
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 117 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/suite.py", line 79 in __call__
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/unittest/runner.py", line 168 in run
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/support/__init__.py", line 1661 in _run_suite
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/support/__init__.py", line 1695 in run_unittest
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/test_asyncio/__init__.py", line 26 in test_main
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 1276 in runtest_inner
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 965 in runtest
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 532 in main
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 1560 in main_in_temp_cwd
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 1585 in <module>
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/runpy.py", line 73 in _run_code
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/runpy.py", line 160 in _run_module_as_main
Traceback (most recent call last):
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/runpy.py", line 160, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/runpy.py", line 73, in _run_code
    exec(code, run_globals)
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/__main__.py", line 3, in <module>
    regrtest.main_in_temp_cwd()
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 1560, in main_in_temp_cwd
    main()
  File "/usr/home/buildbot/python/3.x.koobs-freebsd9/build/Lib/test/regrtest.py", line 736, in main
    raise Exception("Child error on {}: {}".format(test, result[1]))
Exception: Child error on test_asyncio: Exit code 1
*** [buildbottest] Error code 1
msg208929 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2014-01-23 14:10
I looked at last tests of "FreeBSD 6.4 3.x" between builds 4400 and 4432. The builds 4401, 4408, 4416 and 4421 hanged but because of check_interrupted_write_retry() of test_io, but none hanged because of test_asyncio.

I also checked builds 3620..3643 of "x86 RHEL 6 3.x": all succeeded.

Same on "x86 Ubuntu Shared 3.x": no hang between builds 9560 and 9568.

So I consider this issue as fixed.
msg208932 - (view) Author: Stefan Krah (skrah) * (Python committer) Date: 2014-01-23 14:21
It was hanging on FreeBSD 7.2 recently:

http://buildbot.python.org/all/builders/x86%20FreeBSD%207.2%203.x/builds/4917/steps/test/logs/stdio

The older FreeBSD systems have broken threading though, so we could just
disable the offending tests.  I would not waste time debugging anything
threading related before FreeBSD 9.0.
msg208938 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2014-01-23 14:32
> It was hanging on FreeBSD 7.2 recently:
> http://buildbot.python.org/all/builders/x86%20FreeBSD%207.2%203.x/builds/4917/steps/test/logs/stdio

This is a new issue, test_read_pty_output() is a recent feature which came with a new test. The previous blocking test was test_signal_handling_while_selecting(). Please open a new issue.
msg208958 - (view) Author: Stefan Krah (skrah) * (Python committer) Date: 2014-01-23 15:23
OK, I have not seen the original issue in any recent builds either.
msg210073 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2014-02-03 01:30
> It was hanging on FreeBSD 7.2 recently:
> http://buildbot.python.org/all/builders/x86%20FreeBSD%207.2%203.x/builds/4917/steps/test/logs/stdio

Oh, it still hangs on the latest version of the code. I opened #20495 to track this bug.
History
Date User Action Args
2014-02-03 01:30:04vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg210073
2014-01-23 15:23:31skrahsetmessages: + msg208958
2014-01-23 14:32:09vstinnersetmessages: + msg208938
2014-01-23 14:21:31skrahsetmessages: + msg208932
2014-01-23 14:10:12vstinnersetmessages: + msg208929
2013-11-19 11:21:45vstinnersetmessages: + msg203360
2013-11-19 11:20:49vstinnersetmessages: + msg203359
2013-10-22 14:29:28vstinnersetmessages: + msg200962
2013-10-22 13:47:49ncoghlansetmessages: + msg200951
2013-10-22 09:16:31pitrousetmessages: + msg200900
2013-10-22 09:07:40koobssetmessages: + msg200898
2013-10-22 09:03:54koobssetmessages: + msg200897
2013-10-22 08:29:48pitrousetmessages: + msg200894
2013-10-22 08:28:57pitrousetmessages: + msg200893
2013-10-22 08:27:11koobssetfiles: + koobs-freebsd9-py3x-build180.log
nosy: + koobs
messages: + msg200890

2013-10-22 02:44:57David.Edelsohnsetnosy: + David.Edelsohn
2013-10-21 21:24:35gvanrossumsetmessages: + msg200850
2013-10-21 14:45:17gvanrossumcreate