classification
Title: test_winconsoleio fails and hangs on Windows
Type: crash Stage: resolved
Components: Tests, Windows Versions: Python 3.10, Python 3.9, Python 3.8
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: eryksun, miss-islington, paul.moore, steve.dower, terry.reedy, tim.golden, zach.ware
Priority: normal Keywords: patch

Created on 2020-09-05 23:59 by terry.reedy, last changed 2020-09-12 06:19 by terry.reedy. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 22146 merged terry.reedy, 2020-09-08 04:15
PR 22211 merged miss-islington, 2020-09-12 05:52
PR 22212 merged miss-islington, 2020-09-12 05:52
Messages (11)
msg376449 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-05 23:59
f:\dev\3x>python -m test test.test_winconsoleio
Running Debug|Win32 interpreter...
0:00:00 Run tests sequentially
0:00:00 [1/1] test.test_winconsoleio
ÄÄÄÄÄÄÄÄÄÄ^Z^Z^Z^Z^Z^Z^Z^Z^Z^Z








----
It quickly fails, prints seems garbage and several blanks lines, and hangs.  Ditto for 3.9 and 3.8.  When I ran entire suite, it was still hanging after 50 minutes.

Victor's patch for issue 38325 skipped the tests that failed on Windows, but now the overall test is worse.  One must interrupt with ^C to get the test summary for the suite.
msg376452 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-06 02:35
Running test -v test_winconsoleio showed that the hang is in test_cntl_z.

With that commented out, I get failures in test_input (1st assert) and test_partial_reads and some bizarre console behavior.

F:\dev\3x>python -m test -v test_winconsoleio
Running Debug|Win32 interpreter...
== CPython 3.10.0a0 (heads/master:1264d0465a, Sep 5 2020, 18:53:05) [MSC v.1900 32 bit (Intel)]
== Windows-10-10.0.19041-SP0 little-endian
== cwd: F:\dev\3x\build\test_python_7960æ
== CPU count: 12
== encodings: locale=cp1252, FS=utf-8
0:00:00 Run tests sequentially
0:00:00 [1/1] test_winconsoleio
test_abc (test.test_winconsoleio.WindowsConsoleIOTests) ... ok
test_conin_conout_names (test.test_winconsoleio.WindowsConsoleIOTests) ... ok
test_conout_path (test.test_winconsoleio.WindowsConsoleIOTests) ... ok
test_input (test.test_winconsoleio.WindowsConsoleIOTests) ... aaaaaaaaaabbbbbbbbbbcccccccccc111111111122222222223333333333
FAIL
test_input_nonbmp (test.test_winconsoleio.WindowsConsoleIOTests) ... skipped 'Handling Non-BMP characters is broken'
test_open_fd (test.test_winconsoleio.WindowsConsoleIOTests) ... ok
test_open_name (test.test_winconsoleio.WindowsConsoleIOTests) ... ok
test_partial_reads (test.test_winconsoleio.WindowsConsoleIOTests) ...
FAIL
test_partial_surrogate_reads (test.test_winconsoleio.WindowsConsoleIOTests) ... skipped 'Handling Non-BMP characters is broken'
test_write_empty_data (test.test_winconsoleio.WindowsConsoleIOTests) ... ok

======================================================================
FAIL: test_input (test.test_winconsoleio.WindowsConsoleIOTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "f:\dev\3x\lib\test\test_winconsoleio.py", line 142, in test_input
    self.assertStdinRoundTrip('abc123')
  File "f:\dev\3x\lib\test\test_winconsoleio.py", line 138, in assertStdinRoundTrip
    self.assertEqual(actual, text)
AssertionError: 'aaaaaaaaaabbbbbbbbbbcccccccccc111111111122222222223333333333' != 'abc123'
- aaaaaaaaaabbbbbbbbbbcccccccccc111111111122222222223333333333
+ abc123


======================================================================
FAIL: test_partial_reads (test.test_winconsoleio.WindowsConsoleIOTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "f:\dev\3x\lib\test\test_winconsoleio.py", line 168, in test_partial_reads
    self.assertEqual(actual, expected, 'stdin.read({})'.format(read_count))
AssertionError: b'\r\n' != b'\xcf\xbc\xd1\x9e\xd0\xa2\xce\xbb\xd0\xa4\xd0\x99\r\n' : stdin.read(1)

----------------------------------------------------------------------

Ran 10 tests in 0.019s

FAILED (failures=2, skipped=2)
test test_winconsoleio failed
test_winconsoleio failed

== Tests result: FAILURE ==

1 test failed:
    test_winconsoleio

Total duration: 266 ms
Tests result: FAILURE

F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>ϼϼϼϼϼϼϼϼϼϼўўўўўўўўўўТТТТТТТТТТλλλλλλλλλλФФФФФФФФФФЙЙЙЙЙЙЙЙЙЙ
'ϼϼϼϼϼϼϼϼϼϼўўўўўўўўўўТТТТТТТТТТλλλλλλλλλλФФФФФФФФФФЙЙЙЙЙЙЙЙЙЙ' is not recognized as an internal or external command,
operable program or batch file.

F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>
F:\dev\3x>

Even though behavior is the same in 3 different workspaces, and the file shows no obvious sign of corruption in Notepad++, I deleted it anyway (in master) with Windows Explorer 'delete' (not git delete)  and then reverted the change.  Still, someone should verify that this is not just my machine.

Note that I just got the 2008 updates (last Tuesday?) to Win 10, 2004, some of which were apparently optional at the moment.
msg376471 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2020-09-06 23:53
> ÄÄÄÄÄÄÄÄÄÄ^Z^Z^Z^Z^Z^Z^Z^Z^Z^Z

I don't know why Steve made write_input (PC/_testconsole.c) set wRepeatCount in each KeyEvent record to 10. Maybe it was a typo. Previous console implementations have ignored the repeat count, so it wasn't an issue.

test_ctrl_z checks (1) that reading a non-ASCII character works when split across two reads and (2) that Ctrl+Z (0x1A) as the first character of a read is handled as EOF, regardless of where it occurs on the line as long as it's the first character in the buffer. The latter has to be tested because _WindowsConsoleIO has to manually implement the way that WinAPI ReadFile handles Ctrl+Z, a behavior that WinAPI ReadConsoleW does not itself implement.
msg376543 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-08 04:10
After splitting the two reads onto two lines, the indefinite hang happens in the second one, stdin.readall.  

    def test_ctrl_z(self):
        with open('CONIN$', 'rb', buffering=0) as stdin:
            source = '\xC4\x1A\r\n'.encode('utf-16-le')
            expected = '\xC4'.encode('utf-8')
            print('here')
            write_input(stdin, source)
            a = stdin.read(1)
##            b = stdin.readall()
            self.assertEqual(expected[0:1], a)
##            self.assertEqual(expected[1:], b)

The resulting failure of the first assertion results in:
FAIL: test_ctrl_z (__main__.WindowsConsoleIOTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "F:\dev\3x\lib\test\test_winconsoleio.py", line 197, in test_ctrl_z
    self.assertEqual(expected[0:1], a)
AssertionError: b'\xc3' != b'\r'

This minimal change would stop the hang crash, which is the first priority.  However, changing the repeat from 10 to 1, to look like

        prec->Event.KeyEvent.wRepeatCount = 1;


fixes all failures, including the hang.  I will submit for CI testing.
But two questions.

Is this line needed with a repeat of 1, or should it be removed?

Also, this file has a section added by arg clinic.  Does it need to be regenerated for this change?  If so, how?
msg376547 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2020-09-08 05:59
> Is this line needed with a repeat of 1, or should it be removed? 

It's not documented what it means to write a key event with wRepeatCount set to 0. It happens to work, but I'd leave it set to 1, which means the key was pressed once. Ideally, there should also be a subsequent key-up event that's the same except bKeyDown is FALSE, but test_winconsoleio doesn't need it.
msg376560 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-08 09:25
I was assuming that the default was 1, not 0.  But now that CI tests pass code as is, I will leave it alone.
msg376741 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-11 22:09
Steve, as author of the file and line in question, do you have any objection to changing it?
msg376753 - (view) Author: Steve Dower (steve.dower) * (Python committer) Date: 2020-09-11 23:45
No objections. I'd guess it was a typo.
msg376776 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-12 05:52
New changeset 31c9828ec026e5d9b9122d55bf0aa7cb45bfecc5 by Terry Jan Reedy in branch 'master':
bpo-41729: Fix test_winconsole failures (3) and hang (GH-22146)
https://github.com/python/cpython/commit/31c9828ec026e5d9b9122d55bf0aa7cb45bfecc5
msg376777 - (view) Author: miss-islington (miss-islington) Date: 2020-09-12 06:09
New changeset bbab34084e876291d96a65741f075db3adfa7733 by Miss Islington (bot) in branch '3.8':
bpo-41729: Fix test_winconsole failures (3) and hang (GH-22146)
https://github.com/python/cpython/commit/bbab34084e876291d96a65741f075db3adfa7733
msg376779 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2020-09-12 06:19
New changeset c2577b9e0e2f8652f079b4ac473347c63f15e25c by Miss Islington (bot) in branch '3.9':
bpo-41729: Fix test_winconsole failures (3) and hang (GH-22146)
https://github.com/python/cpython/commit/c2577b9e0e2f8652f079b4ac473347c63f15e25c
History
Date User Action Args
2020-09-12 06:19:44terry.reedysetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2020-09-12 06:19:02terry.reedysetmessages: + msg376779
2020-09-12 06:09:16miss-islingtonsetmessages: + msg376777
2020-09-12 05:52:25miss-islingtonsetpull_requests: + pull_request21267
2020-09-12 05:52:18miss-islingtonsetnosy: + miss-islington
pull_requests: + pull_request21266
2020-09-12 05:52:06terry.reedysetmessages: + msg376776
2020-09-11 23:45:48steve.dowersetmessages: + msg376753
2020-09-11 22:09:38terry.reedysetmessages: + msg376741
2020-09-08 09:25:07terry.reedysetmessages: + msg376560
2020-09-08 05:59:25eryksunsetmessages: + msg376547
2020-09-08 04:15:27terry.reedysetkeywords: + patch
stage: needs patch -> patch review
pull_requests: + pull_request21228
2020-09-08 04:10:02terry.reedysetmessages: + msg376543
2020-09-06 23:53:25eryksunsetmessages: + msg376471
2020-09-06 02:35:42terry.reedysetmessages: + msg376452
2020-09-05 23:59:41terry.reedycreate