Skip to content

test_io.test_interrupted_write_text() hangs on the buildbot FreeBSD 7.2 #66527

New issue
New issue
Closed
Closed
test_io.test_interrupted_write_text() hangs on the buildbot FreeBSD 7.2#66527
Labels
testsTests in the Lib/test dir

Description

@vstinner
vstinner
opened on Sep 3, 2014
BPO 22331
Nosy @vstinner, @vadmium
Files
  • int-write.patch
    		•

    Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
closed_at = <Date 2017-06-28.01:26:58.778>
created_at = <Date 2014-09-03.21:31:48.852>
labels = ['tests']
title = 'test_io.test_interrupted_write_text() hangs on the buildbot FreeBSD 7.2'
updated_at = <Date 2017-06-28.01:26:58.777>
user = 'https://github.com/vstinner'

    bugs.python.org fields:

    activity = <Date 2017-06-28.01:26:58.777>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2017-06-28.01:26:58.778>
closer = 'vstinner'
components = ['Tests']
creation = <Date 2014-09-03.21:31:48.852>
creator = 'vstinner'
dependencies = []
files = ['43147']
hgrepos = []
issue_num = 22331
keywords = ['patch', 'buildbot']
message_count = 10.0
messages = ['226326', '226327', '228577', '266688', '266691', '266692', '266723', '266725', '267100', '297114']
nosy_count = 3.0
nosy_names = ['vstinner', 'python-dev', 'martin.panter']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue22331'
versions = ['Python 2.7', 'Python 3.5', 'Python 3.6']

    Activity

    1. vstinner commented on Sep 3, 2014

      @vstinner
      vstinner
      on Sep 3, 2014
      MemberAuthor

      http://buildbot.python.org/all/builders/x86%20FreeBSD%207.2%203.4/builds/332/steps/test/logs/stdio

      Log:
      ---
      [157/389/1] test_io
      Timeout (1:00:00)!
      Thread 0x2a4f0790 (most recent call first):
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/test_io.py", line 3257 in _read
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/threading.py", line 869 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/threading.py", line 921 in _bootstrap_inner
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/threading.py", line 889 in _bootstrap

      Thread 0x28401040 (most recent call first):
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/threading.py", line 1077 in _wait_for_tstate_lock
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/threading.py", line 1061 in join
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/test_io.py", line 3278 in check_interrupted_write
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/test_io.py", line 3302 in test_interrupted_write_text
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/case.py", line 577 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/case.py", line 625 in __call__
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 125 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 87 in __call__
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 125 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 87 in __call__
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 125 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/suite.py", line 87 in __call__
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/unittest/runner.py", line 168 in run
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/support/init.py", line 1750 in _run_suite
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/support/init.py", line 1784 in run_unittest
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/regrtest.py", line 1279 in test_runner
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/regrtest.py", line 1280 in runtest_inner
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/regrtest.py", line 967 in runtest
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/regrtest.py", line 763 in main
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/regrtest.py", line 1564 in main_in_temp_cwd
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/test/main.py", line 3 in <module>
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/runpy.py", line 85 in _run_code
      File "/usr/home/db3l/buildarea/3.4.bolen-freebsd7/build/Lib/runpy.py", line 170 in _run_module_as_main
      ---

      See also the issue bpo-11859 (fixed).

    2. vstinner
      added
      testsTests in the Lib/test dir
      on Sep 3, 2014

    3. python-dev commented on Sep 3, 2014

      @python-dev
      python-devmannequin
      on Sep 3, 2014
      Mannequin

      New changeset baa372eb731c by Victor Stinner in branch '3.4':
      Issue bpo-22331: Skip test_interrupted_write_text() on FreeBSD older than 8.0
      http://hg.python.org/cpython/rev/baa372eb731c

      New changeset 340d48347295 by Victor Stinner in branch 'default':
      (Merge 3.4) Issue bpo-22331: Skip test_interrupted_write_text() on FreeBSD older
      http://hg.python.org/cpython/rev/340d48347295

    4. vstinner commented on Oct 5, 2014

      @vstinner
      vstinner
      on Oct 5, 2014
      MemberAuthor

      The test now pass on the buildbot FreeBSD 7.2.

    5. vstinner
      closed this as completedon Oct 5, 2014

    6. vadmium commented on May 30, 2016

      @vadmium
      vadmium
      on May 30, 2016
      Member

      This recently hung AMD64 FreeBSD 9.x 3.5. The stack trace was different, and there is only one thread:

      http://buildbot.python.org/all/builders/AMD64%20FreeBSD%209.x%203.5/builds/828/steps/test/logs/stdio
      [398/398] test_io
      Timeout (0:15:00)!
      Thread 0x0000000801807400 (most recent call first):
      File "/usr/home/buildbot/python/3.5.koobs-freebsd9/build/Lib/unittest/case.py", line 176 in handle
      File "/usr/home/buildbot/python/3.5.koobs-freebsd9/build/Lib/unittest/case.py", line 727 in assertRaises
      File "/usr/home/buildbot/python/3.5.koobs-freebsd9/build/Lib/test/test_io.py", line 3714 in check_interrupted_write
      File "/usr/home/buildbot/python/3.5.koobs-freebsd9/build/Lib/test/test_io.py", line 3743 in test_interrupted_write_text

      Also, x86 Ubuntu Shared 2.7 hung, but the only information I have is it was running test_io.

      In my Free BSD case, the write() call is stuck, but in Victor’s original case, the background read() call is stuck. I could explain both cases as a race condition with the alarm signal being delivered:

      Victor’s case: SIGALRM delivered somewhere inside assertRaises(), but before the write() system call, and Python has a chance to call the Python signal handler. No data is ever written, so the background read() hangs.

      My case: SIGALRM delivered just before or as write() starts, so Python has no chance to interrupt the system call and call its own Python handler.

      I wonder if we can change the test to only deliver a signal after first reading one byte, i.e. send the signal directly from the background thread. I think that should cover 99% of cases, though in theory it is possible for something else to interrupt write(), and our signal to be delivered while write() was restarting, causing it to hang. But the combination of those two events would be so unlikely it may not be worth worrying about.

      Also, if you close the read end of the pipe before the write end, it should protect against flush() hanging without the EBADF hack by raising EPIPE instead.

      I suggest rewriting the background thread like:

      def _read():
    s = os.read(r, 1)
    read_results.append(s)
    # The main thread is very likely to be inside the write() syscall now, so interrupt it
    os.kill(os.getpid(), SIGALRM)

      and cleaning up the pipe like:

      finally:
      os.close(r)
      try:
      wio.close()
      except BrokenPipeError:
      pass

    7. vadmium
      reopened this on May 30, 2016

    8. vstinner commented on May 30, 2016

      @vstinner
      vstinner
      on May 30, 2016
      MemberAuthor

      When we talk about signals, we must always be careful of threads. Python unit tests are known (at least by me ;-)) to "leak" threads. IMO the first step to make the test more reliable is to start it in a fresh process to control exactly the number of threads.

      A fresh process avoids also to inherit an expected signal and/or signal handler.

      I modified test_eintr recently to do something similar.

    9. vstinner commented on May 30, 2016

      @vstinner
      vstinner
      on May 30, 2016
      MemberAuthor

      I also modified Python 3.6 to run each test file in a fresh process to avoid leaking too much things between tests, to isolate them better.

    10. vadmium commented on May 31, 2016

      @vadmium
      vadmium
      on May 31, 2016
      Member

      Thanks, that is a very good point about threads. I remember that testing tkinter leaves an internal TK or TCL thread running in the background. And I understand Free BSD delivers process signals to arbitrary threads (not necessarily the main thread).

      But the FreeBSD 3.5 buildbot looks like it ran test_io in a separate process (-j4 specified). Anyway it is another possible explanation of the hang (signal delivered to wrong thread, so write() call not interrupted).

      Perhaps it is better to use signal.pthread_kill() instead of os.kill() in my proposal.

    11. vadmium commented on May 31, 2016

      @vadmium
      vadmium
      on May 31, 2016
      Member

      Found the same hang on the 3.6 branch, which was definitely running separate processes:

      http://buildbot.python.org/all/builders/AMD64%20FreeBSD%209.x%203.x/builds/4210/steps/test/logs/stdio
      == CPython 3.6.0a0 (default:ed6345cb08ab, Apr 29 2016, 18:35:36) [GCC 4.2.1 20070831 patched [FreeBSD]]
      Run tests in parallel using 4 child processes

    12. vadmium commented on Jun 3, 2016

      @vadmium
      vadmium
      on Jun 3, 2016
      Member

      Here is a patch with my suggestion to send the signal only when read() returns, and also closing the read end of the pipe before the write end.

    13. vstinner commented on Jun 28, 2017

      @vstinner
      vstinner
      on Jun 28, 2017
      MemberAuthor

      Hum, the resolution is already set to Fixed, and I didn't see this bug last months on buildbots, so I consider that yes, it's fixed.

      Sorry Martin, I lost track of this issue and so I don't know what to do with your patch :-/ I will just close the issue.

    14. vstinner
      closed this as completedon Jun 28, 2017
    15. ezio-melotti
      transferred this issue fromon Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

    Metadata

    Metadata

    Assignees

    No one assigned

      Labels

      testsTests in the Lib/test dir

      Projects

      No projects

        Milestone

        No milestone

        Relationships

        None yet

        Development

        No branches or pull requests

        Issue actions