Dmitry Timoshkov dmitry@baikal.ru writes:
This patch makes WaitCommEvent(EV_TXEMPTY) work when a serial device reports that the out queue is empty even after a successful write() which is the case for real COM ports and as well as for serial-USB adapters.
Take 2 removes special handling of FlushFileBuffers for a serial sevice, the tests show that it really should not reset the pending write state.
I'd like to see some feedback for this patch.
It doesn't work here:
../../../tools/runtest -q -P wine -T ../../.. -M kernel32.dll -p kernel32_test.exe.so comm.c && touch comm.ok comm.c:860: Test failed: WaitCommEvent failed with a timeout comm.c:881: Test failed: WaitCommEvent error 997 comm.c:882: Test failed: WaitCommEvent: expected EV_TXEMPTY, got 0 comm.c:887: Test failed: WaitCommEvent used 1003 ms for waiting comm.c:2226: Tests skipped: interactive tests (set WINETEST_INTERACTIVE=1) make: *** [comm.ok] Error 4
Am Dienstag, 22. Oktober 2013, 16:55:51 schrieb Alexandre Julliard:
Dmitry Timoshkov dmitry@baikal.ru writes:
This patch makes WaitCommEvent(EV_TXEMPTY) work when a serial device reports that the out queue is empty even after a successful write() which is the case for real COM ports and as well as for serial-USB adapters.
Take 2 removes special handling of FlushFileBuffers for a serial sevice, the tests show that it really should not reset the pending write state.
I'd like to see some feedback for this patch.
It doesn't work here:
../../../tools/runtest -q -P wine -T ../../.. -M kernel32.dll -p kernel32_test.exe.so comm.c && touch comm.ok comm.c:860: Test failed: WaitCommEvent failed with a timeout comm.c:881: Test failed: WaitCommEvent error 997 comm.c:882: Test failed: WaitCommEvent: expected EV_TXEMPTY, got 0 comm.c:887: Test failed: WaitCommEvent used 1003 ms for waiting comm.c:2226: Tests skipped: interactive tests (set WINETEST_INTERACTIVE=1) make: *** [comm.ok] Error 4
This is because the previous test fails: in the previous test wine actually write to the serial device and does not return with ERROR_INVALID_PARAMETER. These 17 bytes also need some time to be written and therefor this test fails with a timeout.
I proposed to add a sleep(TIMEOUT) if the previous test does not pass that is the write actually returns success or with error ERROR_IO_PENDING:
if (res || (!res && GetLastError() == ERROR_IO_PENDING)) /* if data has been sent: wait for termination */ Sleep(timeout);
This has been rejected because then the test passes even without changing the EV_TXEMPTY handling at all. This is because calling WaitCommEvent() while there are still bytes in the tx queue already works.
This does not mean that "Add support for pending write flag to the serial device" is not needed. It is needed to correctly signal EV_TXEMPTY if WaitCommEvent() is called later when the tx queue is already empty. I sent a patch (5 Sep) adding an additional test for this case (the patch was named
[PATCH 3/6] add another test for waiting for EV_TXEMPTY with WaitCommEvent(), try 2
It was part of a series of patches which implemented someting similar to Dmitry's patch so I hope Dmitry's patch goes in as it actually fixes an important bug.
Independently: TIMEOUT is to short anyway for (see my earlier emails and those of Francois Gouget, I attached the latter one).
Regards,
Wolfgang Walter wine@stwm.de wrote:
../../../tools/runtest -q -P wine -T ../../.. -M kernel32.dll -p kernel32_test.exe.so comm.c && touch comm.ok comm.c:860: Test failed: WaitCommEvent failed with a timeout comm.c:881: Test failed: WaitCommEvent error 997 comm.c:882: Test failed: WaitCommEvent: expected EV_TXEMPTY, got 0 comm.c:887: Test failed: WaitCommEvent used 1003 ms for waiting comm.c:2226: Tests skipped: interactive tests (set WINETEST_INTERACTIVE=1) make: *** [comm.ok] Error 4
This is because the previous test fails: in the previous test wine actually write to the serial device and does not return with ERROR_INVALID_PARAMETER.
What is this "previous test" you are talking about? Obviously there is no a failing test which checks for ERROR_INVALID_PARAMETER in the output posted by Alexandre above. And it's worth to mention that these tests pass without failures here with and without an external hardware turned on (with the patch applied).
Am Mittwoch, 23. Oktober 2013, 11:12:26 schrieben Sie:
Wolfgang Walter wine@stwm.de wrote:
../../../tools/runtest -q -P wine -T ../../.. -M kernel32.dll -p kernel32_test.exe.so comm.c && touch comm.ok comm.c:860: Test failed: WaitCommEvent failed with a timeout comm.c:881: Test failed: WaitCommEvent error 997 comm.c:882: Test failed: WaitCommEvent: expected EV_TXEMPTY, got 0 comm.c:887: Test failed: WaitCommEvent used 1003 ms for waiting comm.c:2226: Tests skipped: interactive tests (set WINETEST_INTERACTIVE=1) make: *** [comm.ok] Error 4
This is because the previous test fails: in the previous test wine actually write to the serial device and does not return with ERROR_INVALID_PARAMETER.
What is this "previous test" you are talking about? Obviously there is no a failing test which checks for ERROR_INVALID_PARAMETER in the output posted by Alexandre above. And it's worth to mention that these tests pass without failures here with and without an external hardware turned on (with the patch applied).
With privious test I mean the test which starts at line 836:
S(U(ovl_write)).Offset = 0; S(U(ovl_write)).OffsetHigh = 0; ovl_write.hEvent = CreateEventW(NULL, TRUE, FALSE, NULL); before = GetTickCount(); SetLastError(0xdeadbeef); res = WriteFile(hcom, tbuf, sizeof(tbuf), &bytes, &ovl_write); after = GetTickCount(); todo_wine ok(!res && GetLastError() == ERROR_IO_PENDING, "WriteFile returned %d, error %d\n", res, GetLastError()); todo_wine ok(!bytes, "expected 0, got %u\n", bytes); ok(after - before < 30, "WriteFile took %d ms to write %d Bytes at %d Baud\n", after - before, bytes, baud); /* don't wait for WriteFile completion */
This tests sends 17 bytes but does not wait till all have been sent. So the next test which fails under wine (comm.c:860: Test failed: WaitCommEvent failed with a timeout) does not start with a empty tx queue. There should be a sleep(TIMEOUT) after this test.
The test for ERROR_INVALID_PARAMETER before that one (starting at line 831) does indeed not contribute any more to
comm.c:860: Test failed: WaitCommEvent failed with a timeout
any more. When we discussed this it did because then the the code still was:
SetLastError(0xdeadbeef); res = WriteFile(hcom, tbuf, sizeof(tbuf), &bytes, NULL); todo_wine ok(!res, "WriteFile on an overlapped handle without ovl structure should fail\n"); todo_wine ok(GetLastError() == ERROR_INVALID_PARAMETER, "expected ERROR_INVALID_PARAMETER, got %d\n", GetLastError());
So then there were even more bytes pending in the tx queue.
Regards,
Wolfgang Walter wine@stwm.de wrote:
With privious test I mean the test which starts at line 836:
S(U(ovl_write)).Offset = 0; S(U(ovl_write)).OffsetHigh = 0; ovl_write.hEvent = CreateEventW(NULL, TRUE, FALSE, NULL); before = GetTickCount(); SetLastError(0xdeadbeef); res = WriteFile(hcom, tbuf, sizeof(tbuf), &bytes, &ovl_write); after = GetTickCount();todo_wine ok(!res && GetLastError() == ERROR_IO_PENDING, "WriteFile returned %d, error %d\n", res, GetLastError()); todo_wine ok(!bytes, "expected 0, got %u\n", bytes); ok(after - before < 30, "WriteFile took %d ms to write %d Bytes at %d Baud\n", after - before, bytes, baud); /* don't wait for WriteFile completion */
This tests sends 17 bytes but does not wait till all have been sent.
That's the point of the test.
So the next test which fails under wine (comm.c:860: Test failed: WaitCommEvent failed with a timeout) does not start with a empty tx queue. There should be a sleep(TIMEOUT) after this test.
State of the queue doesn't matter at all, the patch (which is the subject of this message) is supposed to make this test work in all cases.
Am Mittwoch, 23. Oktober 2013, 18:41:15 schrieben Sie:
Wolfgang Walter wine@stwm.de wrote:
With privious test I mean the test which starts at line 836: S(U(ovl_write)).Offset = 0; S(U(ovl_write)).OffsetHigh = 0; ovl_write.hEvent = CreateEventW(NULL, TRUE, FALSE, NULL); before = GetTickCount(); SetLastError(0xdeadbeef); res = WriteFile(hcom, tbuf, sizeof(tbuf), &bytes, &ovl_write); after = GetTickCount();
todo_wine
ok(!res && GetLastError() == ERROR_IO_PENDING, "WriteFile returned %d,error %d\n", res, GetLastError()); todo_wine
ok(!bytes, "expected 0, got %u\n", bytes); ok(after - before < 30, "WriteFile took %d ms to write %d Bytes at %dBaud\n",
after - before, bytes, baud); /* don't wait for WriteFile completion */This tests sends 17 bytes but does not wait till all have been sent.
That's the point of the test.
So the next test which fails under wine (comm.c:860: Test failed: WaitCommEvent failed with a timeout) does not start with a empty tx queue. There should be a sleep(TIMEOUT) after this test.
State of the queue doesn't matter at all, the patch (which is the subject of this message) is supposed to make this test work in all cases.
I have no intention to discuss that all again. Please think about the problem. Hint: writing twice as many bytes with 150 baud needs more time, significantly more time then TIMEOUT.
Regards,
Wolfgang Walter wine@stwm.de wrote:
I have no intention to discuss that all again. Please think about the problem. Hint: writing twice as many bytes with 150 baud needs more time, significantly more time then TIMEOUT.
Not really. Francois sent an investigation with pretty exhaustive explanation of the behvaiour of COM-port UARTs regarding timings and baud rates.
Am Mittwoch, 23. Oktober 2013, 20:44:28 schrieben Sie:
Wolfgang Walter wine@stwm.de wrote:
I have no intention to discuss that all again. Please think about the problem. Hint: writing twice as many bytes with 150 baud needs more time, significantly more time then TIMEOUT.
Not really. Francois sent an investigation with pretty exhaustive explanation of the behvaiour of COM-port UARTs regarding timings and baud rates.
Have you read it? It says that with a standard UART windows may signals after 872ms that the tx queue is empty (though there are still 4 bytes to send) when you write 17 bytes. For 34 bytes he gets 1802ms > TIMEOUT.
Here Francois' mesurements for windows:
================================== On my one Windows PC with a real UART (Intel(R) 82801DBM LPC Interface Controller - 24CC, i.e. ICH4 which emulates a 16550A UART) I get the following results which clearly illustrate the impact of the FIFO/trigger level.
comm.c:1100: WaitCommEvent(1 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(2 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(3 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(4 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(5 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(6 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(7 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(8 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(9 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(10 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(11 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(12 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(13 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(14 bytes) for EV_TXEMPTY took 0 ms comm.c:1100: WaitCommEvent(15 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(16 bytes) for EV_TXEMPTY took 872 ms comm.c:1100: WaitCommEvent(17 bytes) for EV_TXEMPTY took 872 ms comm.c:1100: WaitCommEvent(18 bytes) for EV_TXEMPTY took 872 ms comm.c:1100: WaitCommEvent(19 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(20 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(21 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(22 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(23 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(24 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(25 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(26 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(27 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(28 bytes) for EV_TXEMPTY took 871 ms comm.c:1100: WaitCommEvent(29 bytes) for EV_TXEMPTY took 1802 ms comm.c:1100: WaitCommEvent(30 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(31 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(32 bytes) for EV_TXEMPTY took 1802 ms comm.c:1100: WaitCommEvent(33 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(34 bytes) for EV_TXEMPTY took 1802 ms comm.c:1100: WaitCommEvent(35 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(36 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(37 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(38 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(39 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(40 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(41 bytes) for EV_TXEMPTY took 1802 ms comm.c:1100: WaitCommEvent(42 bytes) for EV_TXEMPTY took 1803 ms comm.c:1100: WaitCommEvent(43 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(44 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(45 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(46 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(47 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(48 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(49 bytes) for EV_TXEMPTY took 2734 ms comm.c:1100: WaitCommEvent(50 bytes) for EV_TXEMPTY took 2734 ms =================================
And I really don't think that we can expect exactly that same behaviour when using the linux serial driver, anyway.
Regards,
Wolfgang Walter wine@stwm.de wrote:
I have no intention to discuss that all again. Please think about the problem. Hint: writing twice as many bytes with 150 baud needs more time, significantly more time then TIMEOUT.
Not really. Francois sent an investigation with pretty exhaustive explanation of the behvaiour of COM-port UARTs regarding timings and baud rates.
Have you read it? It says that with a standard UART windows may signals after 872ms that the tx queue is empty (though there are still 4 bytes to send) when you write 17 bytes. For 34 bytes he gets 1802ms > TIMEOUT.
Where do you see 34 bytes to be written in that test?
And I really don't think that we can expect exactly that same behaviour when using the linux serial driver, anyway.
At the time I was reworking the EV_TXEMPTY to use overlapped IO the reasoning for using 900 ms as the designed time was simple: that was enough to make the test pass under Windows with real hardware. How the patch we are discussing makes the test pass for me under Linux with a USB-serial adapter, which confirms that there is no reasons that it can't work under Linux as well.
I understand that there are cases of (really old) hardware where this limit may not be enough, and Francois has already sent a patch which increases timeout. The Francois' patch hasn't been accepted, but that's a different matter.
Am Donnerstag, 24. Oktober 2013, 11:29:34 schrieb Dmitry Timoshkov:
Wolfgang Walter wine@stwm.de wrote:
I have no intention to discuss that all again. Please think about the problem. Hint: writing twice as many bytes with 150 baud needs more time, significantly more time then TIMEOUT.
Not really. Francois sent an investigation with pretty exhaustive explanation of the behvaiour of COM-port UARTs regarding timings and baud rates.
Have you read it? It says that with a standard UART windows may signals after 872ms that the tx queue is empty (though there are still 4 bytes to send) when you write 17 bytes. For 34 bytes he gets 1802ms > TIMEOUT.
Where do you see 34 bytes to be written in that test?
Sorry for that. I looked at the 1.7.2 codebase. There was
SetLastError(0xdeadbeef); res = WriteFile(hcom, tbuf, sizeof(tbuf), &bytes, NULL); todo_wine ok(!res, "WriteFile on an overlapped handle without ovl structure should fail\n"); todo_wine ok(GetLastError() == ERROR_INVALID_PARAMETER, "expected ERROR_INVALID_PARAMETER, got %d\n", GetLastError());
In 1.7.4 there are no todo_wine's any more so this does not fail any more and there should be no pending bytes from that test. There should only be 17 bytes in the test in question.
And I really don't think that we can expect exactly that same behaviour when using the linux serial driver, anyway.
At the time I was reworking the EV_TXEMPTY to use overlapped IO the reasoning for using 900 ms as the designed time was simple: that was enough to make the test pass under Windows with real hardware. How the patch we are discussing makes the test pass for me under Linux with a USB-serial adapter, which confirms that there is no reasons that it can't work under Linux as well.
I understand that there are cases of (really old) hardware where this limit may not be enough, and Francois has already sent a patch which increases timeout. The Francois' patch hasn't been accepted, but that's a different matter.
I built 1.7.4 here and I still get a timeout on my machine (with onboard device), though. The board has an Intel "Corporation 6 Series/C200 Series Chipset Family". I mesured the time needed to write with 150 baud on linux and it needs about 1000ms till ioctl(fd, TIOCOUTQ, &out) returns with zero. Sometimes up to 1100ms. When I mesure it I do not use select() or poll() but loop similar as wine does: call ioctl(), sleep for 1ms, ...
Regards,
Alexandre Julliard julliard@winehq.org wrote:
It doesn't work here:
../../../tools/runtest -q -P wine -T ../../.. -M kernel32.dll -p kernel32_test.exe.so comm.c && touch comm.ok comm.c:860: Test failed: WaitCommEvent failed with a timeout comm.c:881: Test failed: WaitCommEvent error 997 comm.c:882: Test failed: WaitCommEvent: expected EV_TXEMPTY, got 0 comm.c:887: Test failed: WaitCommEvent used 1003 ms for waiting
Could you please generate a +relay,+tid,+comm,+server log for me?
-
Alexandre Julliard -
Dmitry Timoshkov -
Wolfgang Walter