test_winconsoleio fails and hangs on Windows

[terryjreedy]

BPO	41729
Nosy	@terryjreedy, @pfmoore, @tjguk, @zware, @eryksun, @zooba, @miss-islington
PRs	bpo-41729: Fix test_winconsole failures (3) and hang. #22146 [3.9] bpo-41729: Fix test_winconsole failures (3) and hang (GH-22146) #22211 [3.8] bpo-41729: Fix test_winconsole failures (3) and hang (GH-22146) #22212

^{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 2020-09-12.06:19:44.045>
created_at = <Date 2020-09-05.23:59:41.785>
labels = ['3.8', 'type-crash', '3.10', 'tests', 'OS-windows', '3.9']
title = 'test_winconsoleio fails and hangs on Windows'
updated_at = <Date 2020-09-12.06:19:44.045>
user = 'https://github.com/terryjreedy'

bugs.python.org fields:

activity = <Date 2020-09-12.06:19:44.045>
actor = 'terry.reedy'
assignee = 'none'
closed = True
closed_date = <Date 2020-09-12.06:19:44.045>
closer = 'terry.reedy'
components = ['Tests', 'Windows']
creation = <Date 2020-09-05.23:59:41.785>
creator = 'terry.reedy'
dependencies = []
files = []
hgrepos = []
issue_num = 41729
keywords = ['patch']
message_count = 11.0
messages = ['376449', '376452', '376471', '376543', '376547', '376560', '376741', '376753', '376776', '376777', '376779']
nosy_count = 7.0
nosy_names = ['terry.reedy', 'paul.moore', 'tim.golden', 'zach.ware', 'eryksun', 'steve.dower', 'miss-islington']
pr_nums = ['22146', '22211', '22212']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'crash'
url = 'https://bugs.python.org/issue41729'
versions = ['Python 3.8', 'Python 3.9', 'Python 3.10']

[terryjreedy]

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 bpo-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.

[terryjreedy]

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.

[eryksun]

ÄÄÄÄÄÄÄÄÄÄ^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.

[terryjreedy]

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?

[eryksun]

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.

[terryjreedy]

I was assuming that the default was 1, not 0. But now that CI tests pass code as is, I will leave it alone.