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

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: [e-mail]
        ReportedBy: [e-mail]

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 :-)

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

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

Alexandre Julliard  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|                            |FIXED

--- Comment #1 from Alexandre Julliard   2009-10-28 10:17:34 ---
Should be fixed by e487b560d9a54a5f21274ca5722bb2b268b9424e.

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

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

--- Comment #2 from Dan Kegel   2009-10-31 06:35:59 ---
Yes, the test passes now.  
The user code (not that I understand it) sees appropriate-looking errors from
the pipe closure:
      5 ipc_channel_win.cc(262)] pipe error: 109 ERROR_BROKEN_PIPE
     38 ipc_channel_win.cc(329)] pipe error: 995 ERROR_OPERATION_ABORTED
Thanks!

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

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

Alexandre Julliard  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #3 from Alexandre Julliard   2009-11-13 12:44:33 ---
Closing bugs fixed in 1.1.33.