Streaming database response seemingly leak file descriptors?

[dacto]

I have basic yesod web application with a handler that streams a database response. It seems like database file descriptors are leaked.

Using sqlite3 backend and for purposes of these tests, I've limited the database pool size to 1.

Observing open files every second with: lsof -n -r 1 -p "$(pgrep -f stream-vs-buffer)"

simple streaming response handler
It seems that the following streaming response handler keeps the database file handles open indefinitely.

getStreamR :: Handler TypedContent
getStreamR =
    respondSourceDB typePlain $ selectSource [] [Asc PersonName] .| awaitForever toBuilder
  where
    toBuilder (Entity _ (Person name)) = do
        sendChunkText name
        sendChunkText "\n"
        sendFlush

stream-vs 4016 dacto  168ur     REG   8,18     8192 11163556 /home/dacto/work/stream-vs-buffer/db.sqlite3
stream-vs 4016 dacto  169u      REG   8,18        0 11163590 /home/dacto/work/stream-vs-buffer/db.sqlite3-wal
stream-vs 4016 dacto  170u     IPv4 254105      0t0      TCP *:3000 (LISTEN)
stream-vs 4016 dacto  171ur     REG   8,18    32768 11163591 /home/dacto/work/stream-vs-buffer/db.sqlite3-shm

simple non-streaming response
However, the following non-streaming response opens the database file handles and then reasonably closes them after several seconds.

getBufferedR :: Handler TypedContent
getBufferedR = do
    names <- runDB $ selectList [] [Asc PersonName]
    return $ toTypedContent $ intercalate "\n" $ map (personName . entityVal) names

This is especially concerning, with a non-trival application with larger database pools in which streaming database response handlers accumulate many file handles.

Am I doing something wrong? What am I missing?

git repository to reproduce: https://github.com/dacto/stream-vs-buffer

stack resolver: lts-14.12
Note: this is also known to exist on resolver lts-9.21

additional details

> uname -a
Linux 5.0.0-32-generic #34~18.04.2-Ubuntu SMP Thu Oct 10 10:36:02 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

> stack --version
Version 2.1.3, Git revision 636e3a759d51127df2b62f90772def126cdf6d1f (7735 commits) x86_64 hpack-0.31.2

> stack ghc -- --version
The Glorious Glasgow Haskell Compilation System, version 8.6.5

> stack ls dependencies
Cabal 2.4.1.0
aeson 1.4.5.0
aeson-compat 0.3.9
ansi-terminal 0.9.1
appar 0.1.8
array 0.5.3.0
async 2.2.2
attoparsec 0.13.2.3
attoparsec-iso8601 1.0.1.0
auto-update 0.1.6
base 4.12.0.0
base-compat 0.10.5
base-orphans 0.8.1
base64-bytestring 1.0.0.2
basement 0.0.11
binary 0.8.6.0
blaze-builder 0.4.1.0
blaze-html 0.9.1.2
blaze-markup 0.8.2.3
bsb-http-chunked 0.0.0.4
byteable 0.1.1
byteorder 1.0.4
bytestring 0.10.8.2
cabal-doctest 1.0.8
case-insensitive 1.2.0.11
cereal 0.5.8.1
cipher-aes 0.2.11
clientsession 0.9.1.2
colour 2.3.5
conduit 1.3.1.1
conduit-extra 1.3.4
containers 0.6.0.1
cookie 0.4.4
cprng-aes 0.6.1
crypto-api 0.13.3
crypto-cipher-types 0.0.9
crypto-random 0.0.9
data-default-class 0.1.2.0
deepseq 1.4.4.0
directory 1.3.3.0
dlist 0.8.0.7
easy-file 0.2.2
entropy 0.4.1.5
exceptions 0.10.3
fast-logger 2.4.17
filepath 1.4.2.1
ghc-boot-th 8.6.5
ghc-prim 0.5.3
hashable 1.2.7.0
http-api-data 0.4.1
http-date 0.0.8
http-types 0.12.3
http2 1.6.5
integer-gmp 1.0.2.0
integer-logarithms 1.0.3
iproute 1.7.7
lifted-base 0.2.3.12
memory 0.14.18
microlens 0.4.10
microlens-th 0.4.2.3
monad-control 1.0.2.3
monad-logger 0.3.30
monad-loops 0.4.3
mono-traversable 1.0.13.0
mtl 2.2.2
network 2.8.0.1
network-byte-order 0.1.1.1
old-locale 1.0.0.7
old-time 1.1.0.3
parsec 3.1.14.0
path-pieces 0.2.1
persistent 2.9.2
persistent-sqlite 2.9.3
persistent-template 2.6.0
pretty 1.1.3.6
primitive 0.6.4.0
process 1.6.5.0
psqueues 0.2.7.2
random 1.1
resource-pool 0.2.3.2
resourcet 1.2.2
rio 0.1.12.0
rts 1.0
scientific 0.3.6.2
securemem 0.1.10
semigroups 0.18.5
setenv 0.1.1.3
shakespeare 2.0.22
silently 1.2.5.1
simple-sendfile 0.2.30
skein 1.0.9.4
split 0.2.3.3
stm 2.5.0.0
stm-chans 3.0.0.4
stream-vs-buffer 0.0.1
streaming-commons 0.2.1.1
tagged 0.8.6
template-haskell 2.14.0.0
text 1.2.3.1
th-abstraction 0.3.1.0
time 1.8.0.2
time-compat 1.9.2.2
time-locale-compat 0.1.1.5
time-manager 0.0.0
transformers 0.5.6.2
transformers-base 0.4.5.2
transformers-compat 0.6.5
typed-process 0.2.6.0
unix 2.7.2.2
unix-compat 0.5.2
unix-time 0.4.7
unliftio 0.2.12
unliftio-core 0.1.2.0
unordered-containers 0.2.10.0
uuid-types 1.0.3
vault 0.3.1.3
vector 0.12.0.3
vector-algorithms 0.8.0.1
void 0.7.3
wai 3.2.2.1
wai-extra 3.0.28
wai-logger 2.3.5
warp 3.2.28
word8 0.1.3
yesod-core 1.6.16.1
yesod-persistent 1.6.0.2
zlib 0.6.2.1

[snoyberg]

Good catch, this is in fact a real issue. Digging through the underlying libraries and adding some printf debugging, I see the following:

ErrorBusy while attempting to perform close: unable to close due to unfinalized statements or unfinished backups

So there are two problems:

1. The exception is getting swallowed instead of reported properly
2. The exception is occurring at all

[snoyberg]

(1) seems to be addressed by yesodweb/persistent#978.

[snoyberg]

Can you confirm that 7839de4 fixes the issue?

[dacto]

• With only yesodweb/persistent#978 I am able to see that the error is no longer swallowed; the error is now emitted in the log.

• With 7839de4 I can confirm that the database file descriptors are closed in a reasonable amount of time following the streaming response. Tested with the trivial example and a larger application.

Thanks for the prompt investigation and resolution. Looking forward to the new releases!

[snoyberg]

New releases now on Hackage.