Memory leak

[soupi]

I spotted what I believe is a memory leak trying to benchmark a very simple Spock app.

Reproduction steps in this repo.

You may need to use ulimit -n 4096 before running hello-spock, which is another indication that there's a problem.

Spock fairs rather poorly compared to twain and scotty. Here are some numbers:

Library	Get (/)	Params, query & header	Post JSON
Spock	31,321.19	25,015.61	28,924.38
scotty	269,021.44	186,814.18	194,448.40
twain	306,501.25	230,075.55	227,636.17

When trying to figure out why that is I noticed very different behaviours between Spock and twain:

Here's a -s report of the two

> Spock is running on port 3000
149,218,795,624 bytes allocated in the heap
  31,465,251,520 bytes copied during GC
     505,829,376 bytes maximum residency (198 sample(s))
      67,873,264 bytes maximum slop
            1557 MiB total memory in use (61 MiB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0     14970 colls, 14970 par   21.356s   6.710s     0.0004s    0.0044s
  Gen  1       198 colls,   197 par   39.219s   5.222s     0.0264s    0.0956s

  Parallel GC work balance: 87.24% (serial 0%, perfect 100%)

  TASKS: 123 (1 bound, 121 peak workers (122 total), using -N12)

  SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled)

  INIT    time    0.003s  (  0.002s elapsed)
  MUT     time  164.764s  ( 23.123s elapsed)
  GC      time   60.574s  ( 11.932s elapsed)
  EXIT    time    0.065s  (  0.003s elapsed)
  Total   time  225.407s  ( 35.060s elapsed)

  Alloc rate    905,650,467 bytes per MUT second

  Productivity  73.1% of total user, 66.0% of total elapsed

------

> Running twain app at http://localhost:3000 (ctrl-c to quit)
101,783,300,920 bytes allocated in the heap
   2,880,638,200 bytes copied during GC
      19,310,688 bytes maximum residency (23 sample(s))
         872,128 bytes maximum slop
             104 MiB total memory in use (0 MiB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0      3931 colls,  3931 par    7.664s   2.089s     0.0005s    0.0017s
  Gen  1        23 colls,    22 par    0.128s   0.037s     0.0016s    0.0030s

  Parallel GC work balance: 72.41% (serial 0%, perfect 100%)

  TASKS: 26 (1 bound, 25 peak workers (25 total), using -N12)

  SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled)

  INIT    time    0.003s  (  0.002s elapsed)
  MUT     time  167.343s  ( 32.921s elapsed)
  GC      time    7.792s  (  2.126s elapsed)
  EXIT    time    0.003s  (  0.001s elapsed)
  Total   time  175.141s  ( 35.051s elapsed)

  Alloc rate    608,230,568 bytes per MUT second

  Productivity  95.5% of total user, 93.9% of total elapsed

And a quick look at the hello-spock.prof reveals that Crypto.Random is doing quite a bit of work:

COST CENTRE                           MODULE                            SRC                                                      %time %alloc

supportedBackends                     Crypto.Random.Entropy.Backend     Crypto/Random/Entropy/Backend.hs:(31,1)-(41,5)            40.6   52.0

[jberryman]

@soupi I wasn't able to reproduce a space leak using a modified version of your repro. I used the following, which just depends on Spock-core:

{-# LANGUAGE OverloadedStrings #-}
{-# language ScopedTypeVariables #-}

import Data.Aeson (Value)
import Data.String (fromString)
import Data.Text (Text)
import qualified Web.Spock.Core as Spock

import System.Mem
import Control.Concurrent
import GHC.Stats
import Control.Monad (forever, void)

main :: IO ()
main = do
  void $ forkIO $ forever $ do
      threadDelay $ 30*1000*1000
      performMajorGC
      getRTSStats >>= \stats -> do
          print $ gcdetails_live_bytes $ gc stats
  Spock.runSpock 3000 $
    Spock.spockT id routes


routes :: Spock.SpockCtxT () IO ()
routes = do
  Spock.get "/" $
    Spock.text "hi"

  Spock.get ("/id/" Spock.<//> Spock.var) $ \(id' :: Int) -> do
    (name :: Text) <- Spock.param' "name"
    Spock.setHeader "x-powered-by" "benchmark"
    Spock.text (fromString (show id') <> " " <> name)

  Spock.post "/json" $ do
    (value :: Value) <- Spock.jsonBody'
    Spock.json value

I just tested it using curl, and observing the reported live bytes that get logged every 30 seconds, e.g.:

for _ in {1..1000000}; do   curl -X GET http://localhost:3000/id/3\?name\=bun  &> /dev/null; done

I tested both w ghc 9.2.7 and 9.4.5

So wrt any space leaks, it might be:

• Some issue that only gets triggered with the full Spock Library
• an artifact of compiling with profiling
• an issue that only gets triggered when compiling with GHC 9.6
• an issue that only gets triggered with your specific versions of libraries

Here’s my freeze file for 9.4

Click me

``` active-repositories: hackage.haskell.org:merge constraints: any.Cabal ==3.8.1.0, any.Cabal-syntax ==3.8.1.0, any.HUnit ==1.6.2.0, any.OneTuple ==0.4.1.1, any.QuickCheck ==2.14.3, QuickCheck -old-random +templatehaskell, any.Spock-core ==0.14.0.1, any.StateVar ==1.2.2, any.aeson ==2.1.2.1, aeson -cffi +ordered-keymap, any.ansi-terminal ==1.0, ansi-terminal -example, any.ansi-terminal-types ==0.11.5, any.appar ==0.1.8, any.array ==0.5.4.0, any.asn1-encoding ==0.9.6, any.asn1-parse ==0.9.5, any.asn1-types ==0.3.4, any.assoc ==1.1, assoc +tagged, any.async ==2.2.4, async -bench, any.attoparsec ==0.14.4, attoparsec -developer, any.attoparsec-iso8601 ==1.1.0.0, any.auto-update ==0.1.6, any.base ==4.17.1.0, any.base-compat ==0.13.0, any.base-compat-batteries ==0.13.0, any.base-orphans ==0.9.0, any.base64-bytestring ==1.2.1.0, any.basement ==0.0.16, any.bifunctors ==5.6.1, bifunctors +tagged, any.binary ==0.8.9.1, any.bsb-http-chunked ==0.0.0.4, any.byteorder ==1.0.4, any.bytestring ==0.11.4.0, any.cabal-doctest ==1.0.9, any.call-stack ==0.4.0, any.case-insensitive ==1.2.1.0, any.colour ==2.3.6, any.comonad ==5.0.8, comonad +containers +distributive +indexed-traversable, any.containers ==0.6.7, any.contravariant ==1.5.5, contravariant +semigroups +statevar +tagged, any.cookie ==0.4.6, any.crypton ==0.31, crypton -check_alignment +integer-gmp -old_toolchain_inliner +support_aesni +support_deepseq +support_pclmuldq +support_rdrand -support_sse +use_target_attributes, any.crypton-x509 ==1.7.6, any.data-default-class ==0.1.2.0, any.data-fix ==0.3.2, any.deepseq ==1.4.8.0, any.directory ==1.3.7.1, any.distributive ==0.6.2.1, distributive +semigroups +tagged, any.dlist ==1.0, dlist -werror, any.easy-file ==0.2.5, any.exceptions ==0.10.5, any.fast-logger ==3.2.1, any.filepath ==1.4.2.2, any.foldable1-classes-compat ==0.1, foldable1-classes-compat +tagged, any.generically ==0.1.1, any.ghc-bignum ==1.3, any.ghc-boot-th ==9.4.5, any.ghc-prim ==0.9.0, any.hashable ==1.4.2.0, hashable +integer-gmp -random-initial-seed, any.hourglass ==0.2.12, any.hsc2hs ==0.68.9, hsc2hs -in-ghc-tree, any.http-api-data ==0.5.1, http-api-data -use-text-show, any.http-date ==0.0.11, any.http-types ==0.12.3, any.http2 ==4.1.4, http2 -devel -h2spec, any.hvect ==0.4.0.1, any.indexed-traversable ==0.1.2.1, any.indexed-traversable-instances ==0.1.1.2, any.integer-gmp ==1.1, any.integer-logarithms ==1.0.3.1, integer-logarithms -check-bounds +integer-gmp, any.iproute ==1.7.12, any.memory ==0.18.0, memory +support_bytestring +support_deepseq, any.mmorph ==1.2.0, any.monad-control ==1.0.3.1, any.mtl ==2.2.2, any.network ==3.1.4.0, network -devel, any.network-byte-order ==0.1.6, any.old-locale ==1.0.0.7, any.old-time ==1.1.0.3, any.parsec ==3.1.16.1, any.pem ==0.2.4, any.pretty ==1.1.3.6, any.primitive ==0.8.0.0, any.process ==1.6.16.0, any.psqueues ==0.2.7.3, any.random ==1.2.1.1, any.recv ==0.1.0, any.reroute ==0.7.0.0, any.resourcet ==1.3.0, any.rts ==1.0.2, any.safe-exceptions ==0.1.7.3, any.scientific ==0.3.7.0, scientific -bytestring-builder -integer-simple, any.semialign ==1.3, semialign +semigroupoids, any.semigroupoids ==6.0.0.1, semigroupoids +comonad +containers +contravariant +distributive +tagged +unordered-containers, any.simple-sendfile ==0.2.31, simple-sendfile +allow-bsd -fallback, any.splitmix ==0.1.0.4, splitmix -optimised-mixer, any.stm ==2.5.1.0, any.streaming-commons ==0.2.2.6, streaming-commons -use-bytestring-builder, any.strict ==0.5, any.superbuffer ==0.3.1.2, any.tagged ==0.8.7, tagged +deepseq +transformers, any.template-haskell ==2.19.0.0, any.text ==2.0.2, any.text-short ==0.1.5, text-short -asserts, any.th-abstraction ==0.5.0.0, any.these ==1.2, any.time ==1.12.2, any.time-compat ==1.9.6.1, time-compat -old-locale, any.time-manager ==0.0.0, any.transformers ==0.5.6.2, any.transformers-base ==0.4.6, transformers-base +orphaninstances, any.transformers-compat ==0.7.2, transformers-compat -five +five-three -four +generic-deriving +mtl -three -two, any.unix ==2.7.3, any.unix-compat ==0.7, unix-compat -old-time, any.unix-time ==0.4.9, any.unliftio ==0.2.24.0, any.unliftio-core ==0.2.1.0, any.unordered-containers ==0.2.19.1, unordered-containers -debug, any.uuid-types ==1.0.5, any.vault ==0.3.1.5, vault +useghc, any.vector ==0.13.0.0, vector +boundschecks -internalchecks -unsafechecks -wall, any.vector-stream ==0.1.0.0, any.wai ==3.2.3, any.wai-extra ==3.1.13.0, wai-extra -build-example, any.wai-logger ==2.4.0, any.warp ==3.3.27, warp +allow-sendfilefd -network-bytestring -warp-debug +x509, any.witherable ==0.4.2, any.word8 ==0.1.3, any.zlib ==0.6.3.0, zlib -bundled-c-zlib -non-blocking-ffi -pkg-config index-state: hackage.haskell.org 2023-06-14T18:19:34Z

</details>

[soupi]

@jberryman oh nice catch. This seems to be a problem with the full Spock version and not Spock-core. I've ran your example (without the forkIO) and indeed it runs quite fast while the full Spock version does not. This is the diff that will make it run fast:

 {-# LANGUAGE OverloadedStrings #-}
 {-# language ScopedTypeVariables #-}
 
 import Data.Aeson (Value)
 import Data.String (fromString)
 import Data.Text (Text)
-import qualified Web.Spock as Spock
-import qualified Web.Spock.Config as Spock
+import qualified Web.Spock.Core as Spock


 main :: IO ()
 main = do
-  config <- mkConfig
   Spock.runSpock 3000 $
-    Spock.spock config routes
+    Spock.spockT id routes

-mkConfig :: IO (Spock.SpockCfg () () ())
-mkConfig = Spock.defaultSpockCfg () Spock.PCNoDatabase ()

-routes :: Spock.SpockM () () () ()
+routes :: Spock.SpockCtxT () IO ()
 routes = do
   Spock.get "/" $
     Spock.text "hi"
 
   Spock.get ("/id/" Spock.<//> Spock.var) $ \(id' :: Int) -> do
     (name :: Text) <- Spock.param' "name"
     Spock.setHeader "x-powered-by" "benchmark"
     Spock.text (fromString (show id') <> " " <> name)
 
   Spock.post "/json" $ do
     (value :: Value) <- Spock.jsonBody'
     Spock.json value

And the profile looks fine as well: