https://bugs.winehq.org/show_bug.cgi?id=53464
Bug ID: 53464 Summary: conhost.exe:tty sometimes times out on Windows 10 Product: Wine Version: unspecified Hardware: x86-64 OS: Windows Status: NEW Severity: normal Priority: P2 Component: programs Assignee: wine-bugs@winehq.org Reporter: fgouget@codeweavers.com
conhost.exe:tty sometimes times out on Windows 10:
conhost.exe:tty start programs/conhost/tests/tty.c conhost.exe:tty:1734 done (258) in 120s
https://test.winehq.org/data/patterns.html#conhost.exe:tty
The timeouts are very frequent on Windows 10 1909 as per bug 51182.
However they also happen on other Windows 10 versions like 2004 and 21H1 where they cannot be blamed on conhost.exe being a buggy early version.
Adding more traces shows that the test gets stuck in test_read_console_control(). Depending on the run this happens in one of two locations:
1350: skip_sequence("\x1b[25l"); /* broken hide cursor */ tty.c:1370:4.047 Test succeeded tty.c:1373:4.047 Test succeeded tty.c:226:4.047 Test succeeded tty.c:1705:3.984 Test succeeded tty.c:1350:4.110 Test succeeded tty.c:603:4.tty.c:1602:4.047 Test 110 Test succeeded succeeded ttytty.c:60.c:6:4.110 T16est succeeded 04:4tty.c:.043477:4.110 Test succeeded Test succeeded tty.c:1245:4.110 Test succeeded conhost.exe:tty:1dbc done (258) in 120s
1406: skip_sequence("\x1b[?25l"); /* hide cursor */ tty.c:1647:6.578 Test succeeded tty.c:1650:tty.c6.578:140 Test5:6.6 succeeded87 Tes t succeeded tty.c:1405:6.687 Test succeeded tty.c:1405:6.687 Test succeeded tty.c:1405:6.687 Test succeeded tty.c:1406:6.687 Test succeeded tty.c:437:6.750 Test succeeded tty.c:1245:6.750 Test succeeded conhost.exe:tty:13d4 done (258) in 120s
The traces are mangled because the main test process and the child process write to stdout at the same time.
In all cases the last trace is from write_console_pipe(): 1245: ok(res, "WriteFile failed: %lu\n", GetLastError());
https://bugs.winehq.org/show_bug.cgi?id=53464
François Gouget fgouget@codeweavers.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Keywords| |source, testcase CC| |jacek@codeweavers.com
https://bugs.winehq.org/show_bug.cgi?id=53464
Eric Pouech eric.pouech@orange.fr changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |ASSIGNED CC| |eric.pouech@orange.fr
--- Comment #1 from Eric Pouech eric.pouech@orange.fr --- there's a likely synchronization issue in the test: A) parent asks child to call ReadConsole with control block B) parent writes string to child's console to be handled by ReadConsole C) parent expects results from ReadConsole() call in child
but there's no guarantee that child will actually have entered ReadConsole (from A)) before string sent in B) is actually processed by console (conhost) and test expects it
We could try adding some delay between A) & B) to see what gives (unfortunately there's no timeout option in ReadConsole)
François: do you have a way to trigger this bug in tests ? (or you just overflow Marvin with tests until it appeared?)
A+
https://bugs.winehq.org/show_bug.cgi?id=53464
--- Comment #2 from François Gouget fgouget@codeweavers.com --- I don't have a way to systematically reproduce this issue but, according to the WineTest results, it seems to happen ~80% of the time on w1064v1909. So testing on that VM should provide usable results.
https://bugs.winehq.org/show_bug.cgi?id=53464
--- Comment #3 from Eric Pouech eric.pouech@gmail.com --- Well, w1064v1909 is so bogus regarding console tests, I'd avoid it (I'm even considering dropping it from conhost tests...) Also you noted a potential crash, that may explain the 88% ratio.
Tweaking the tests (*), I isolated two spots where the timeout (not the crash) happens: 1) the one you listed in read_control_result 2) another one in expect_input
Both boil down to string sent as input not being (fully) processed. This could be a race (as when pushing another string, the first appears being processed).
More investigation (and flooding on Marvin required...)
(*) by replacing synchronous read with asynchronous reads + timeout; I get the places where it times out. However, need to run heavily the tests to grasp this kind of event :-(
-
WineHQ Bugzilla