classification
Title: test_read_pty_output() of test_asyncio hangs on macOS 10.13.2 (darwin 17.3.0)
Type: Stage: resolved
Components: asyncio, macOS, Tests Versions: Python 3.8, Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: asvetlov, mattbillenstein, miss-islington, n8henrie, ned.deily, ronaldoussoren, vstinner, yselivanov
Priority: Keywords: patch

Created on 2018-01-07 23:03 by vstinner, last changed 2018-03-27 21:19 by ned.deily. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 6037 merged n8henrie, 2018-03-09 06:15
PR 6038 merged miss-islington, 2018-03-09 17:44
PR 6112 merged ned.deily, 2018-03-14 06:49
PR 6113 merged ned.deily, 2018-03-14 07:07
Messages (14)
msg309650 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-01-07 23:03
On buildbot x86-64 Sierra 3.6, since build 163, test_read_pty_output() of test_asyncio started to hang:

http://buildbot.python.org/all/#/builders/20/builds/163/steps/4/logs/stdio

0:22:40 load avg: 1.73 [329/406/1] test_asyncio crashed (Exit code 1)
Timeout (0:15:00)!
Thread 0x00007fffb5eee340 (most recent call first):
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/selectors.py", line 577 in select
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/asyncio/base_events.py", line 1396 in _run_once
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/asyncio/base_events.py", line 422 in run_forever
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/asyncio/base_events.py", line 455 in run_until_complete
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/test/test_asyncio/test_events.py", line 1536 in test_read_pty_output
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/test/support/__init__.py", line 555 in wrapper
  File "/Users/buildbot/buildarea/3.6.billenstein-sierra/build/Lib/test/support/__init__.py", line 600 in wrapper
(...)

Difference between pythoninfo of build 162 and 163:

-os.login: buildbot
+os.login: _timed

-os.uname: posix.uname_result(sysname='Darwin', nodename='mattb-mbp2.local', release='17.2.0', version='Darwin Kernel Version 17.2.0: Fri Sep 29 18:27:05 PDT 2017; root:xnu-4570.20.62~3/RELEASE_X86_64', machine='x86_64')
+os.uname: posix.uname_result(sysname='Darwin', nodename='mattb-mbp2.local', release='17.3.0', version='Darwin Kernel Version 17.3.0: Thu Nov  9 18:09:22 PST 2017; root:xnu-4570.31.3~1/RELEASE_X86_64', machine='x86_64')

-platform.platform: Darwin-17.2.0-x86_64-i386-64bit
+platform.platform: Darwin-17.3.0-x86_64-i386-64bit

-sys.version: 3.6.4+ (heads/3.6:aea95c2fbd, Jan  2 2018, 00:22:06)  [GCC 4.2.1 Compatible Apple LLVM 9.0.0 (clang-900.0.39.2)]
+sys.version: 3.6.4+ (heads/3.6:a70d5ff992, Jan  4 2018, 01:35:13)  [GCC 4.2.1 Compatible Apple LLVM 9.0.0 (clang-900.0.39.2)]

-sysconfig[HOST_GNU_TYPE]: x86_64-apple-darwin17.2.0
+sysconfig[HOST_GNU_TYPE]: x86_64-apple-darwin17.3.0

The os.login change is interesting and curious, and it also looks like a macOS upgrade from Darwin 17.2.0 to 17.3.0.
msg309665 - (view) Author: Ronald Oussoren (ronaldoussoren) * (Python committer) Date: 2018-01-08 14:40
The darwin version change is likely due to an upgrade from macOS 10.13.1 to 10.13.2.

The user change can be due to the introduction of a new system user, but I don't know when user _timed was introduced and don't have 10.3 VMs other than one running 10.13.2.  User _timed does not exist on 10.12.6, and is hence a fairly recent addition.

The buildbot operator could verify this by checking the UID for user buildbot, this likely conflicts with user _timed. The fix for that would be the give user buildbot a new UID and chown all files in the buildbot tree to the new UID.
msg309690 - (view) Author: Matt Billenstein (mattbillenstein) Date: 2018-01-09 08:45
I don't see a conflict in the uids:

mattb@mattb-mbp2:~ $ id -u buildbot
506
mattb@mattb-mbp2:~ $ id -u _timed
266
mattb@mattb-mbp2:~ $ grep _timed /etc/passwd
_timed:*:266:266:Time Sync Daemon:/var/db/timed:/usr/bin/false
mattb@mattb-mbp2:~ $ grep 506 /etc/passwd
mattb@mattb-mbp2:~ $

Buildbot is started via launchd:

mattb@mattb-mbp2:~ $ sudo cat /Library/LaunchDaemons/net.buildbot.slave.plist
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>Label</key>
    <string>net.buildbot.slave</string>
    <key>UserName</key>
    <string>buildbot</string>
    <key>WorkingDirectory</key>
    <string>/Users/buildbot/buildarea</string>
    <key>ProgramArguments</key>
    <array>
        <string>/Users/buildbot/bin/run_slave.sh</string>
    </array>
    <key>StandardOutPath</key>
    <string>twistd.log</string>
    <key>StandardErrorPath</key>
    <string>twistd.log</string>
    <key>KeepAlive</key>
    <true/>
    <key>SessionCreate</key>
    <true/>
</dict>
</plist>
msg309727 - (view) Author: Matt Billenstein (mattbillenstein) Date: 2018-01-09 19:27
Note, I can repro running it by hand from the cli.  And I cannot repro on 3.x, only 3.6 on the same machine.
msg310274 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-01-19 11:03
bpo-32578 has been marked as a duplicate of this issue.
msg310276 - (view) Author: Nathan Henrie (n8henrie) * Date: 2018-01-19 13:45
I can reproduce on my local machine.

MacOS 10.13.2, trying to build 3.6.4. Waited for up to 6 hours for it to fail or finish, never does, just hangs at `test_asyncio`.
msg313014 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2018-02-27 15:10
Since this is still happening on current macOS 10.13.3, we should get a fix for this in before 3.6.5rc1.  PR's welcome!
msg313473 - (view) Author: Nathan Henrie (n8henrie) * Date: 2018-03-09 06:16
It seems to work if you close proto.transport (as is done in `test_write_pty()`).
msg313491 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-03-09 17:43
New changeset 12f74d8608c15cacd9d5786524e2be9ca36f007e by Yury Selivanov (Nathan Henrie) in branch '3.6':
bpo-32517: fix test_read_pty_output() hangs on macOS 10.13.2+ (GH-6037)
https://github.com/python/cpython/commit/12f74d8608c15cacd9d5786524e2be9ca36f007e
msg313492 - (view) Author: miss-islington (miss-islington) Date: 2018-03-09 18:14
New changeset 3c39beb65d003b209a98a79af4aaf94ba16d0d29 by Miss Islington (bot) in branch '3.7':
bpo-32517: fix test_read_pty_output() hangs on macOS 10.13.2+ (GH-6037)
https://github.com/python/cpython/commit/3c39beb65d003b209a98a79af4aaf94ba16d0d29
msg313812 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2018-03-14 07:13
Thanks for the fix, Nathan.  Yury has already committed the fix for 3.6.5 and for 3.7.0.  I've just pushed PR 6112 and PR 6113 to forward port to the master branch (for 3.8) and to re-enable the failing tests on 3.7 and master.  Once they are merged, I think we can close this.
msg313813 - (view) Author: Nathan Henrie (n8henrie) * Date: 2018-03-14 07:24
Awesome, I'm really excited to have contributed something, no matter how small.
msg314550 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2018-03-27 21:16
New changeset 8534d53333e4e918be82b041754ecd89af519e5b by Ned Deily in branch 'master':
bpo-32517: fix test_read_pty_output() hangs on macOS 10.13.2+ (GH-6037) (GH-6113)
https://github.com/python/cpython/commit/8534d53333e4e918be82b041754ecd89af519e5b
msg314551 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2018-03-27 21:17
New changeset 6a2539c43412567a4c693da8e7fdf5e73191fd16 by Ned Deily in branch '3.7':
bpo-32517: re-enable test_read_pty_output on macOS (GH-6112)
https://github.com/python/cpython/commit/6a2539c43412567a4c693da8e7fdf5e73191fd16
History
Date User Action Args
2018-03-27 21:19:53ned.deilysetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2018-03-27 21:17:32ned.deilysetmessages: + msg314551
2018-03-27 21:16:57ned.deilysetmessages: + msg314550
2018-03-14 07:24:12n8henriesetmessages: + msg313813
2018-03-14 07:13:36ned.deilysetpriority: release blocker ->

messages: + msg313812
versions: + Python 3.7, Python 3.8
2018-03-14 07:07:38ned.deilysetpull_requests: + pull_request5876
2018-03-14 06:49:35ned.deilysetpull_requests: + pull_request5875
2018-03-09 18:14:17miss-islingtonsetnosy: + miss-islington
messages: + msg313492
2018-03-09 17:44:07miss-islingtonsetpull_requests: + pull_request5801
2018-03-09 17:43:47yselivanovsetmessages: + msg313491
2018-03-09 06:16:09n8henriesetmessages: + msg313473
2018-03-09 06:15:25n8henriesetkeywords: + patch
stage: needs patch -> patch review
pull_requests: + pull_request5799
2018-02-27 15:10:36ned.deilysetpriority: normal -> release blocker

messages: + msg313014
stage: needs patch
2018-01-28 17:30:13ned.deilylinkissue32686 superseder
2018-01-19 13:45:57n8henriesetnosy: + n8henrie
messages: + msg310276
2018-01-19 11:03:36vstinnersetmessages: + msg310274
2018-01-19 11:03:20vstinnerlinkissue32578 superseder
2018-01-09 19:27:23mattbillensteinsetmessages: + msg309727
2018-01-09 08:45:58mattbillensteinsetmessages: + msg309690
2018-01-09 06:07:30ned.deilysetnosy: + mattbillenstein
2018-01-08 15:28:00vstinnersettitle: test_read_pty_output() of test_asyncio hangs on x86-64 Sierra 3.6 -> test_read_pty_output() of test_asyncio hangs on macOS 10.13.2 (darwin 17.3.0)
2018-01-08 14:40:40ronaldoussorensetmessages: + msg309665
2018-01-07 23:03:38vstinnercreate