[Bug 20353] New: chromium ipc_tests.exe fails when KERNEL32.GetQueuedCompletionStatus() hangs on peer disconnect of named pipe?

[wine-bugs at winehq.org]

http://bugs.winehq.org/show_bug.cgi?id=20353

           Summary: chromium ipc_tests.exe fails when
                    KERNEL32.GetQueuedCompletionStatus() hangs on peer
                    disconnect of named pipe?
           Product: Wine
           Version: unspecified
          Platform: PC
        OS/Version: Linux
            Status: NEW
          Keywords: download, source, testcase
          Severity: normal
          Priority: P2
         Component: ntdll
        AssignedTo: wine-bugs at winehq.org
        ReportedBy: dank at kegel.com


The script

wget http://kegel.com/wine/chromium/ipc_tests.exe.rz
rzip -d ipc_tests.exe.rz
WINEPREFIX=/data/dkegel/.winetest /data/dkegel/wine-git/wine notepad &
i=1
while test $i -lt 100
do
    WINEDEBUG=+process,+relay WINEPREFIX=/data/dkegel/.winetest
/data/dkegel/wine-git/wine ipc_tests.exe
--gtest_filter=IPCChannelTest.SendMessageInChannelConnected  > ipc$i.log 2>&1
    i=`expr $i + 1`
done
grep FAIL ipc*.log

shows about 10 failures of IPCChannelTest.SendMessageInChannelConnected
here (with or without logging). Looking at the logs with grep
shows that successful runs end with a call to ExitProcess(0) in
both parent and child, but failed runs end with just one ExitProcess(1)
and a call to GetQueuedCompletionStatus() that does not return.

Searching through the chromium codebase seems to indicate that
this function is called only in MessagePumpForIO::GetIOItem() in
http://src.chromium.org/viewvc/chrome/trunk/src/base/message_pump_win.cc
The IO completion events in this test seem mainly to come from
reads of a named pipe.  Grepping for the handle of that named pipe
plus a few other interesting words,
  egrep
'FAIL|Exit|error|PASS|RUN|CreateProcess|GetQueuedCompletionStatus|0x68[^0-9a-f]|00068[^0-9a-f]'

shows lots of normal operation (an NtReadFile() followed by a few 
GetQueuedCompletionStatus()'s until one succeeds, then repeat;
both parent and child process do this),
but towards the end when the test is shutting down, something funny happens:

[parent process shuts its end down]
0024:Call
KERNEL32.GetQueuedCompletionStatus(00000064,0033f9e8,0033f920,0033f914,00000000)
ret=004b9d69
trace:sync:GetQueuedCompletionStatus (0x64,0x33f9e8,0x33f920,0x33f914,0)
0024:Ret  KERNEL32.GetQueuedCompletionStatus() retval=00000000 ret=004b9d69
0024:Call KERNEL32.CancelIo(00000068) ret=00520112
trace:ntdll:NtCancelIoFile 0x68 0x33fa10
0024:Call KERNEL32.CloseHandle(00000068) ret=00520135
0024:Call
KERNEL32.GetQueuedCompletionStatus(00000064,0033fa68,0033f9a0,0033f994,ffffffff)
ret=004b9d69
trace:sync:GetQueuedCompletionStatus (0x64,0x33fa68,0x33f9a0,0x33f994,-1)
0024:Ret  KERNEL32.GetQueuedCompletionStatus() retval=00000001 ret=004b9d69
0024:Call
KERNEL32.GetQueuedCompletionStatus(00000064,0033fa68,0033f9a0,0033f994,ffffffff)
ret=004b9d69
trace:sync:GetQueuedCompletionStatus (0x64,0x33fa68,0x33f9a0,0x33f994,-1)
0024:Ret  KERNEL32.GetQueuedCompletionStatus() retval=00000001 ret=004b9d69

[child process wakes up, does some I/O, checks queue, hangs]
0037:Call KERNEL32.ReadFile(00000068,009ba620,00001000,0033f780,009ba5c4)
ret=00520f00
trace:ntdll:NtReadFile
(0x68,(nil),(nil),0x9ba5c4,0x9ba5c4,0x9ba620,0x00001000,0x33f2e0,(nil)),partial
stub!
0037:Call
KERNEL32.GetQueuedCompletionStatus(00000064,0033fa04,0033f93c,0033f930,00000000)
ret=004b9d69
trace:sync:GetQueuedCompletionStatus (0x64,0x33fa04,0x33f93c,0x33f930,0)
0037:Ret  KERNEL32.GetQueuedCompletionStatus() retval=00000000 ret=004b9d69
0037:Call
KERNEL32.GetQueuedCompletionStatus(00000064,0033f95c,0033f894,0033f888,ffffffff)
ret=004b9d69
trace:sync:GetQueuedCompletionStatus (0x64,0x33f95c,0x33f894,0x33f888,-1)

[parent process gives up and declares failure]
.\ipc_tests.cc(352): error: Value of:
base::WaitForSingleProcess(process_handle, 5000)
0024:Call KERNEL32.OutputDebugStringA(009d5f90 ".\\ipc_tests.cc(352): error:
Value of: base::WaitForSingleProcess(process_handle, 5000)\n  Actual:
false\nExpected: true") ret=00453839

This is all just extrapolation from one log, but it does seem like
wine might not be doing the right thing with GetQueuedCompletionStatus()
and named pipes.  (Dang, I should have covered that case when I wrote
my named pipe tests in 2003 :-)

-- 
Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email
Do not reply to this email, post in Bugzilla using the
above URL to reply.
------- You are receiving this mail because: -------
You are watching all bug changes.