KQueue evtmgr backend fails to register for write events
The root of the problem is that the `GHC.Event.KQueue.toFilter` function has type `GHC.Event.Internal.Event -> Filter` with GHC's `Event` being a bitmask which can represent read events, write events or a combination of those.
It happens that the event manager requests it's backend to be notified about read *and* write events on some fd, and because the kqueue `EVFILT_*`s are *not* bitmasks, the above function cannot capture this, silently dropping the desire to be notified about write events.
The following program triggers the problematic behaviour:
```
import Control.Concurrent ( forkIO, killThread )
import Control.Exception ( finally )
import Control.Monad.Trans.Resource ( runResourceT )
import Control.Monad.IO.Class ( liftIO )
import qualified Data.ByteString as BS
import Data.Conduit ( ($$), ($=) )
import qualified Data.Conduit.Binary as CB
import qualified Data.Conduit.List as CL
import qualified Data.Conduit.Network as CN
import Data.IORef ( newIORef, modifyIORef', readIORef)
main :: IO ()
main = CN.runTCPClient (CN.clientSettings 5555 "192.168.2.11") client
where
logMsg cnt = CL.mapM $ \bs -> liftIO $ do
modifyIORef' cnt (+ 1)
readIORef cnt >>= \x -> putStrLn $
"msg #" ++ show x ++ " of size: " ++ show (BS.length bs)
return bs
client ad = do
reader <- forkIO (runResourceT $ CN.appSource ad
$$ CL.mapM_ ( \bs -> (liftIO . putStrLn) $
"read " ++ show (BS.length bs) ++ " bytes"))
cnt <- newIORef ( 0 :: Int )
let
runPipe = runResourceT $ CB.sourceFile "cool-linux-distro.iso"
$$ logMsg cnt
$= CN.appSink ad
runPipe `finally` (killThread reader)
```
Having a `nc -l -p 5555 > /dev/null` running on another machine is sufficient to sink the data.
Assuming that we can read `bigfile.iso` faster than we can send out over the socket, the `send` syscall will at some point give an `EAGAIN` as can be seen in the `truss` output:
```
write(1,"msg #20 of size: 32752\n",23) = 23 (0x17)
sendto(12,"\f\2409\0\M^RA\^T\M-&A\M-'\M-d8"...,32752,0x0,NULL,0x0) = 32752 (0x7ff0)
read(13,"\M^?\0'\\\M-B\M-:+\^]D\M-0\M-="...,32752) = 32752 (0x7ff0)
poll({ 1/POLLOUT },1,0) = 1 (0x1)
msg #21 of size: 32752
write(1,"msg #21 of size: 32752\n",23) = 23 (0x17)
sendto(12,"\M^?\0'\\\M-B\M-:+\^]D\M-0\M-="...,32752,0x0,NULL,0x0) = 19204 (0x4b04)
sendto(12,"\M-j$2\M^BH\M-#-\^A\M-E\^O\M^Y\a"...,13548,0x0,NULL,0x0) ERR#35 'Resource temporarily unavailable'
SIGNAL 26 (SIGVTALRM)
sigprocmask(SIG_SETMASK,{ SIGVTALRM },0x0) = 0 (0x0)
sigreturn(0x7fffffff9c60) ERR#35 'Resource temporarily unavailable'
kevent(3,{ 12,EVFILT_READ,EV_ADD|EV_ONESHOT,0x0,0x0,0x0 },1,0x0,0,{ 0.000000000 }) = 0 (0x0)
_umtx_op(0x800c71ed0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
SIGNAL 26 (SIGVTALRM)
sigprocmask(SIG_SETMASK,{ SIGVTALRM },0x0) = 0 (0x0)
sigreturn(0x7fffffffdc00) ERR#4 'Interrupted system call'
_umtx_op(0x800c71ed0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
SIGNAL 26 (SIGVTALRM)
```
Not the `sendto` call on fd 12 resulting in `ERR#35`, soon followed by an `kevent` call for that same fd and only `EVFILT_READ` set. This makes little sense as it was an attempt to *write* that just failed. This is caused by `toFilter` giving precedence to `read` events, dropping the write event. Not starting the `reader` thread prevents bad things from happening as then the `write` events are properly passed thru to kqueue.
I have an initial version of a patch fixing this.
<details><summary>Trac metadata</summary>
| Trac field | Value |
| ---------------------- | -------------- |
| Version | 8.0.2 |
| Type | Bug |
| TypeOfFailure | OtherFailure |
| Priority | normal |
| Resolution | Unresolved |
| Component | Runtime System |
| Test case | |
| Differential revisions | |
| BlockedBy | |
| Related | |
| Blocking | |
| CC | |
| Operating system | |
| Architecture | |
</details>
<!-- {"blocked_by":[],"summary":"KQueue evtmgr backend fails to register for write events","status":"New","operating_system":"","component":"Runtime System","related":[],"milestone":"","resolution":"Unresolved","owner":{"tag":"Unowned"},"version":"8.0.2","keywords":[],"differentials":[],"test_case":"","architecture":"","cc":[""],"type":"Bug","description":"The root of the problem is that the `GHC.Event.KQueue.toFilter` function has type `GHC.Event.Internal.Event -> Filter` with GHC's `Event` being a bitmask which can represent read events, write events or a combination of those.\r\n\r\nIt happens that the event manager requests it's backend to be notified about read ''and'' write events on some fd, and because the kqueue `EVFILT_*`s are ''not'' bitmasks, the above function cannot capture this, silently dropping the desire to be notified about write events.\r\n\r\nThe following program triggers the problematic behaviour:\r\n\r\n{{{\r\n\r\nimport Control.Concurrent ( forkIO, killThread )\r\nimport Control.Exception ( finally )\r\nimport Control.Monad.Trans.Resource ( runResourceT )\r\nimport Control.Monad.IO.Class ( liftIO )\r\nimport qualified Data.ByteString as BS\r\nimport Data.Conduit ( ($$), ($=) )\r\nimport qualified Data.Conduit.Binary as CB\r\nimport qualified Data.Conduit.List as CL\r\nimport qualified Data.Conduit.Network as CN\r\nimport Data.IORef ( newIORef, modifyIORef', readIORef)\r\n\r\nmain :: IO ()\r\nmain = CN.runTCPClient (CN.clientSettings 5555 \"192.168.2.11\") client\r\n where\r\n logMsg cnt = CL.mapM $ \\bs -> liftIO $ do\r\n modifyIORef' cnt (+ 1)\r\n readIORef cnt >>= \\x -> putStrLn $\r\n \"msg #\" ++ show x ++ \" of size: \" ++ show (BS.length bs)\r\n return bs\r\n\r\n client ad = do\r\n reader <- forkIO (runResourceT $ CN.appSource ad\r\n $$ CL.mapM_ ( \\bs -> (liftIO . putStrLn) $\r\n \"read \" ++ show (BS.length bs) ++ \" bytes\"))\r\n cnt <- newIORef ( 0 :: Int )\r\n\r\n let\r\n runPipe = runResourceT $ CB.sourceFile \"cool-linux-distro.iso\"\r\n $$ logMsg cnt\r\n $= CN.appSink ad\r\n\r\n runPipe `finally` (killThread reader)\r\n}}}\r\n\r\nHaving a `nc -l -p 5555 > /dev/null` running on another machine is sufficient to sink the data.\r\n\r\nAssuming that we can read `bigfile.iso` faster than we can send out over the socket, the `send` syscall will at some point give an `EAGAIN` as can be seen in the `truss` output:\r\n\r\n{{{\r\nwrite(1,\"msg #20 of size: 32752\\n\",23) = 23 (0x17)\r\nsendto(12,\"\\f\\2409\\0\\M^RA\\^T\\M-&A\\M-'\\M-d8\"...,32752,0x0,NULL,0x0) = 32752 (0x7ff0)\r\nread(13,\"\\M^?\\0'\\\\\\M-B\\M-:+\\^]D\\M-0\\M-=\"...,32752) = 32752 (0x7ff0)\r\npoll({ 1/POLLOUT },1,0) = 1 (0x1)\r\nmsg #21 of size: 32752\r\nwrite(1,\"msg #21 of size: 32752\\n\",23) = 23 (0x17)\r\nsendto(12,\"\\M^?\\0'\\\\\\M-B\\M-:+\\^]D\\M-0\\M-=\"...,32752,0x0,NULL,0x0) = 19204 (0x4b04)\r\nsendto(12,\"\\M-j$2\\M^BH\\M-#-\\^A\\M-E\\^O\\M^Y\\a\"...,13548,0x0,NULL,0x0) ERR#35 'Resource temporarily unavailable'\r\nSIGNAL 26 (SIGVTALRM)\r\nsigprocmask(SIG_SETMASK,{ SIGVTALRM },0x0) = 0 (0x0)\r\nsigreturn(0x7fffffff9c60) ERR#35 'Resource temporarily unavailable'\r\nkevent(3,{ 12,EVFILT_READ,EV_ADD|EV_ONESHOT,0x0,0x0,0x0 },1,0x0,0,{ 0.000000000 }) = 0 (0x0)\r\n_umtx_op(0x800c71ed0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'\r\nSIGNAL 26 (SIGVTALRM)\r\nsigprocmask(SIG_SETMASK,{ SIGVTALRM },0x0) = 0 (0x0)\r\nsigreturn(0x7fffffffdc00) ERR#4 'Interrupted system call'\r\n_umtx_op(0x800c71ed0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'\r\nSIGNAL 26 (SIGVTALRM)\r\n}}}\r\n\r\nNot the `sendto` call on fd 12 resulting in `ERR#35`, soon followed by an `kevent` call for that same fd and only `EVFILT_READ` set. This makes little sense as it was an attempt to ''write'' that just failed. This is caused by `toFilter` giving precedence to `read` events, dropping the write event. Not starting the `reader` thread prevents bad things from happening as then the `write` events are properly passed thru to kqueue.\r\n\r\nI have an initial version of a patch fixing this.","type_of_failure":"OtherFailure","blocking":[]} -->
issue