winio: use synchronous access explicitly for handles that may not be asynchronous.

Problem

Currently when running a Haskell application under winio and using stderr, stdout or stdin and running under an msys2 console the application would hang.

As an example, this simple application

main = getLine >>= putStrLn

Will hang.

The reason for this is that the I/O manager waits for an I/O notification that the read has finished but it never arrives. In winio we have designed it to work in asynchronous mode always. According to the MSDN documentation[1][2], when a handle is not opened in asynchronous mode then the operation would simply work but operate synchronously.

This seems to happen as documented for File handles, but pipes don't seem to follow this documented behavior and so are a problem. Under msys2 your standard handles are actually pipes, not console handles or files. As such running under an msys2 console causes a hang as the pipe read never returns.

[1] https://docs.microsoft.com/en-us/windows/win32/fileio/synchronous-and-asynchronous-i-o

[2] https://docs.microsoft.com/en-us/windows/win32/sync/synchronization-and-overlapped-input-and-output

Solution

The solution added here adds support for explicitly marking a handle as async or not. This allows us to manually wait for the completion instead of relying on the I/O system to do the right thing. As we have been using the buffers in async mode we may not have moved the file pointer on the kernel object, as such we still need to give an OVERLAPPED structure, but we instead create an event object that we can wait on.

As documented in MSDN this even object must be in manual reset mode. This approach gives us the flexibility, with minimum impact to support both synchronous and asynchronous access.

Additional approaches explored

Normally the I/O system is in full control of all Handles it creates, with one big exception: inheritance.

For any HANDLE we inherit we don't know how it's been open. A different solution I have explored was to try to detect the HANDLE mode. But this approach would never work for a few reasons:

1. The presence of an asynchronous flag does not indicate that we are able to handle the operation asynchronously. In particular, just because a HANDLE is open in async mode, it may not be associated with our completion port.
2. One can only associate a HANDLE to a single completion port. As such, if the handle is opened in async mode but already registered to a completion port then we can't use it asynchronously.
3. You can only associate a completion port once, even if it's the same port. This means were we to strap a HANDLE of it's NativeHandle wrapper and then wrap it again, we can't retest as the result would be invalid. This is an issue because to pass HANDLEs we have to pass the native OS Handle not the Haskell one. i.e. remote-iserv.

As such, detection can't work reliably and instead I have chosen to manually annotate the Handles.

Impact

Because manual annotations are required there needs to be a small update on all libraries that manually create Haskell Handle from native OS HANDLEs. As far as I know, the only two impacted libraries are:

• Process
• Win32

We need to investigate what we can do to remove these leaky abstractions. But process is quite low level.. but perhaps Pipe support should be in base instead. It seems useful in general.

Testing

Unfortunately, this cannot be tested automatically in the CI. Because the CI does std handles redirections, and these end up being file handles and not the same kind of full duplex pipes as msys2 creates. So testing has been done manually testing the above application read.exe

msys2 pipes

Pinky@Rage /c/U/x/s/r/ghc (winio-check-handle-type-on-create)> ./read.exe
        winio: Starting io-manager... (ThreadId 1)
        winio: iocp: IOCP 0x0000000000000178 (ThreadId 1)
        winio: waking up I/O manager. (ThreadId 1)
        winio: startIOManagerThread old=Nothing (ThreadId 1)
        winio: spawning worker threads.. (ThreadId 1)
        winio: io_mngr_loop:WinIORunning (ThreadId 2)
        winio: expired calls: 0 (ThreadId 2)
        winio: next timer: 120000 (ThreadId 2)
        winio: I/O manager pausing: maxDelay=False (ThreadId 2)
-- call getQueuedCompletionStatusEx
        winio: created io-manager threads. (ThreadId 1)
making handle for <stdin>
Registering finalizer: "<stdin>"
hGetLineBufferedLoop: r=0, w=0, off=0
readTextDevice: cbuf=0x7ef4fe3fa010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=0)
readBuf at 0
readBuf handle=0x0000000000000454 0x7ef4fe3fd010@buf8192(0-0) (>=0)

{{ event 0x0000000000000188 for 0x00007ef4fe305b40
        winio: +1.. 1 requests queued. | 0x00007ef4fe305b40 (ThreadId 3)
        winio: hs_lpol:0x00007ef4fe305b40 cdData:0x00007ef4fe305b78 ptr_lpol:0x00007ef4fe305b60 *ptr_lpol:0x00007ef4fe305b78 (ThreadId 3)
:: hwndRead
hello
        winio: == Just 6 (ThreadId 3)
        winio: == >< 0 (ThreadId 3)
        winio: == >*< (Just 6,True,False,0x0000000000000454,0x00007ef4fe305b40,0) (ThreadId 3)
        winio: request handled immediately (o/b), not queued. (ThreadId 3)
        winio: -1.. 0 requests queued. (ThreadId 3)
        winio: :: done 0x00007ef4fe305b40 - Just 6 (0x0000000000000454:0) (ThreadId 3)
        winio: :: exit *ptr_lpol: 0x0000000002daa3a0 (0x0000000000000454:0) (ThreadId 3)
        winio: :: done bytes: Just 6 (0x0000000000000454:0) (ThreadId 3)
after: 0x7ef4fe3fd010@buf8192(0-6) (>=6)

readBuf after 6
readTextDevice after reading: bbuf=0x7ef4fe3fd010@buf8192(0-6) (>=6)
readTextDevice after decoding: cbuf=0x7ef4fe3fa010@buf2048(0-6) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=6)
hGetLineBufferedLoop: r=0, w=6, off=5
making handle for <stdout>
Registering finalizer: "<stdout>"
commitBuffer: sz=2048, count=7, flush=False, release=True, handle={handle: <stdout>}
writeCharBuffer: cbuf=0x7ef4fe3e8010@buf2048(0-7) (>=0) bbuf=0x7ef4fe3ee010@buf8192(0-0) (>=0)
writeCharBuffer after encoding: cbuf=0x7ef4fe3e8010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3ee010@buf8192(0-7) (>=0)
writeBuf handle=0x000000000000045c 0x7ef4fe3ee010@buf8192(0-7) (>=0)

{{ event 0x0000000000000188 for 0x00007ef4fe307e10
        winio: +1.. 1 requests queued. | 0x00007ef4fe307e10 (ThreadId 4)
        winio: hs_lpol:0x00007ef4fe307e10 cdData:0x00007ef4fe307e48 ptr_lpol:0x00007ef4fe307e30 *ptr_lpol:0x00007ef4fe307e48 (ThreadId 4)
:: hwndWrite
hello
        winio: request handled immediately (o), not queued. (ThreadId 4)
        winio: -1.. 0 requests queued. (ThreadId 4)
        winio: :: done 0x00007ef4fe307e10 - Nothing (0x000000000000045c:0) (ThreadId 4)
        winio: :: exit *ptr_lpol: 0x0000000002daa3a0 (0x000000000000045c:0) (ThreadId 4)
        winio: :: done bytes: Just 7 (0x000000000000045c:0) (ThreadId 4)
flushByteWriteBuffer: bbuf=0x7ef4fe3ee010@buf8192(0-0) (>=7)
making handle for <stderr>
Registering finalizer: "<stderr>"

msys2 file redirects

Pinky@Rage /c/U/x/s/r/ghc (winio-check-handle-type-on-create)> echo ff | ./read.exe
        winio: Starting io-manager... (ThreadId 1)
        winio: iocp: IOCP 0x0000000000000180 (ThreadId 1)
        winio: waking up I/O manager. (ThreadId 1)
        winio: startIOManagerThread old=Nothing (ThreadId 1)
        winio: spawning worker threads.. (ThreadId 1)
        winio: io_mngr_loop:WinIORunning (ThreadId 2)
        winio: expired calls: 0 (ThreadId 2)
        winio: next timer: 120000 (ThreadId 2)
        winio: I/O manager pausing: maxDelay=False (ThreadId 2)
-- call getQueuedCompletionStatusEx
        winio: created io-manager threads. (ThreadId 1)
making handle for <stdin>
Registering finalizer: "<stdin>"
hGetLineBufferedLoop: r=0, w=0, off=0
readTextDevice: cbuf=0x7ef4fe3fa010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=0)
readBuf at 0
readBuf handle=0x00000000000063a8 0x7ef4fe3fd010@buf8192(0-0) (>=0)

{{ event 0x000000000000018c for 0x00007ef4fe305b40
        winio: +1.. 1 requests queued. | 0x00007ef4fe305b40 (ThreadId 3)
        winio: hs_lpol:0x00007ef4fe305b40 cdData:0x00007ef4fe305b78 ptr_lpol:0x00007ef4fe305b60 *ptr_lpol:0x00007ef4fe305b78 (ThreadId 3)
:: hwndRead
        winio: request handled immediately (o), not queued. (ThreadId 3)
        winio: -1.. 0 requests queued. (ThreadId 3)
        winio: :: done 0x00007ef4fe305b40 - Nothing (0x00000000000063a8:0) (ThreadId 3)
        winio: :: exit *ptr_lpol: 0x00000000015fa3a0 (0x00000000000063a8:0) (ThreadId 3)
        winio: :: done bytes: Just 3 (0x00000000000063a8:0) (ThreadId 3)
after: 0x7ef4fe3fd010@buf8192(0-3) (>=3)

readBuf after 3
readTextDevice after reading: bbuf=0x7ef4fe3fd010@buf8192(0-3) (>=3)
readTextDevice after decoding: cbuf=0x7ef4fe3fa010@buf2048(0-3) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=3)
hGetLineBufferedLoop: r=0, w=3, off=2
making handle for <stdout>
Registering finalizer: "<stdout>"
commitBuffer: sz=2048, count=4, flush=False, release=True, handle={handle: <stdout>}
writeCharBuffer: cbuf=0x7ef4fe3e8010@buf2048(0-4) (>=0) bbuf=0x7ef4fe3ee010@buf8192(0-0) (>=0)
writeCharBuffer after encoding: cbuf=0x7ef4fe3e8010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3ee010@buf8192(0-4) (>=0)
writeBuf handle=0x000000000000045c 0x7ef4fe3ee010@buf8192(0-4) (>=0)

{{ event 0x000000000000018c for 0x00007ef4fe307a40
        winio: +1.. 1 requests queued. | 0x00007ef4fe307a40 (ThreadId 4)
        winio: hs_lpol:0x00007ef4fe307a40 cdData:0x00007ef4fe307a78 ptr_lpol:0x00007ef4fe307a60 *ptr_lpol:0x00007ef4fe307a78 (ThreadId 4)
:: hwndWrite
ff
        winio: request handled immediately (o), not queued. (ThreadId 4)
        winio: -1.. 0 requests queued. (ThreadId 4)
        winio: :: done 0x00007ef4fe307a40 - Nothing (0x000000000000045c:0) (ThreadId 4)
        winio: :: exit *ptr_lpol: 0x00000000015fa3a0 (0x000000000000045c:0) (ThreadId 4)
        winio: :: done bytes: Just 4 (0x000000000000045c:0) (ThreadId 4)
flushByteWriteBuffer: bbuf=0x7ef4fe3ee010@buf8192(0-0) (>=4)
making handle for <stderr>
Registering finalizer: "<stderr>"

native windows console

Pinky@Rage /c/U/x/s/r/ghc (winio-check-handle-type-on-create)> winpty ./read.exe
        winio: Starting io-manager... (ThreadId 1)
        winio: iocp: IOCP 0x000000000000018c (ThreadId 1)
        winio: waking up I/O manager. (ThreadId 1)
        winio: startIOManagerThread old=Nothing (ThreadId 1)
        winio: spawning worker threads.. (ThreadId 1)
        winio: io_mngr_loop:WinIORunning (ThreadId 2)
        winio: expired calls: 0 (ThreadId 2)
        winio: next timer: 120000 (ThreadId 2)
        winio: I/O manager pausing: maxDelay=False (ThreadId 2)
-- call getQueuedCompletionStatusEx
        winio: created io-manager threads. (ThreadId 1)
making handle for <stdin>
Registering finalizer: "<stdin>"
hGetLineBufferedLoop: r=0, w=0, off=0
readTextDevice: cbuf=0x7ef4fe3fa010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=0)
readBuf at 0
readBuf handle=0x0000000000000008 0x7ef4fe3fd010@buf8192(0-0) (>=0)

consoleRead :: un-cooked I/O read.
ffff
after: 0x7ef4fe3fd010@buf8192(0-6) (>=6)

readBuf after 6
readTextDevice after reading: bbuf=0x7ef4fe3fd010@buf8192(0-6) (>=6)
readTextDevice after decoding: cbuf=0x7ef4fe3fa010@buf2048(0-6) (>=0) bbuf=0x7ef4fe3fd010@buf8192(0-0) (>=6)
hGetLineBufferedLoop: r=0, w=6, off=5
making handle for <stdout>
Registering finalizer: "<stdout>"
commitBuffer: sz=2048, count=6, flush=True, release=False, handle={handle: <stdout>}
writeCharBuffer: cbuf=0x7ef4fe3d6010@buf2048(0-6) (>=0) bbuf=0x7ef4fe3ec010@buf8192(0-0) (>=0)
writeCharBuffer after encoding: cbuf=0x7ef4fe3d6010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3ec010@buf8192(0-6) (>=0)
writeBuf handle=0x000000000000000c 0x7ef4fe3ec010@buf8192(0-6) (>=0)

:: consoleWrite
ffff
flushByteWriteBuffer: bbuf=0x7ef4fe3ec010@buf8192(0-0) (>=6)
commitBuffer: sz=2048, count=0, flush=False, release=True, handle={handle: <stdout>}
writeCharBuffer: cbuf=0x7ef4fe3d6010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3ec010@buf8192(0-0) (>=6)
writeCharBuffer after encoding: cbuf=0x7ef4fe3d6010@buf2048(0-0) (>=0) bbuf=0x7ef4fe3ec010@buf8192(0-0) (>=6)
making handle for <stderr>
Registering finalizer: "<stderr>"