cardano-tracer: Lower allocation by persisting file handles

[Icelandjack]

Description

Add Handle Registry feature to the TracerEnv, to track handles that have been opened.

-- Cardano.Tracer.Types
type    Registry :: Type -> Type -> Type
newtype Registry a b = Registry { getRegistry :: MVar (Map a b) }

type HandleRegistry :: Type
type HandleRegistry = Registry (NodeName, LoggingParams) (Handle, FilePath)

Checklist

• Commit sequence broadly makes sense and commits have useful messages
• New tests are added if needed and existing tests are updated. These may include:
  • golden tests
  • property tests
  • roundtrip tests
  • integration tests
    See Runnings tests for more details
• Any changes are noted in the CHANGELOG.md for affected package
• The version bounds in .cabal files are updated
• CI passes. See note on CI. The following CI checks are required:
  • Code is linted with hlint. See .github/workflows/check-hlint.yml to get the hlint version
  • Code is formatted with stylish-haskell. See .github/workflows/stylish-haskell.yml to get the stylish-haskell version
  • Code builds on Linux, MacOS and Windows for ghc-8.10.7 and ghc-9.2.7
• Self-reviewed the diff

Graphs

RTS allocation rate:

RTS live dataset:

Profiling comparison (tracer/cardano-tracer.gcstats)

Compiled with WB_PROFILING=time

Without Handle Registry (old)

'/nix/store/q42z21kj9ic12hmmk39ncfkcjhxpn57j-cardano-tracer-exe-cardano-tracer-0.2.2/bin/cardano-tracer' '--config' 'config.json' +RTS '-T' '-scardano-tracer.gcstats'
  14,894,377,592 bytes allocated in the heap
     758,763,144 bytes copied during GC
       2,956,296 bytes maximum residency (383 sample(s))
         107,528 bytes maximum slop
               9 MiB total memory in use (0 MB lost due to fragmentation)

With Handle Registry (new):

• Allocation decreased to 66.7%.
• GC copies decreased to 26.3%.

'/nix/store/r9mwrmw7xv3k35czq8gan6v3n0k0sp55-cardano-tracer-exe-cardano-tracer-0.2.2/bin/cardano-tracer' '--config' 'config.json' +RTS '-T' '-scardano-tracer.gcstats'
   4,961,702,600 bytes allocated in the heap
     559,019,608 bytes copied during GC
       2,979,504 bytes maximum residency (763 sample(s))
         137,216 bytes maximum slop
               9 MiB total memory in use (0 MB lost due to fragmentation)

Compiled with WB_PROFILING=time-detail

Without Handle Registry (old)

'/nix/store/q42z21kj9ic12hmmk39ncfkcjhxpn57j-cardano-tracer-exe-cardano-tracer-0.2.2/bin/cardano-tracer' '--config' 'config.json' +RTS '-T' '-scardano-tracer.gcstats'
  15,246,669,176 bytes allocated in the heap
     768,850,304 bytes copied during GC
       2,992,552 bytes maximum residency (453 sample(s))
         101,104 bytes maximum slop
               9 MiB total memory in use (0 MB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0     11343 colls,     0 par    2.872s   3.949s     0.0003s    0.0445s
  Gen  1       453 colls,     0 par    1.576s   2.102s     0.0046s    0.0587s

  TASKS: 6 (1 bound, 5 peak workers (5 total), using -N1)

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

  INIT    time    0.000s  (  0.000s elapsed)
  MUT     time   42.008s  (1250.051s elapsed)
  GC      time    4.448s  (  6.052s elapsed)
  EXIT    time    0.001s  (  0.007s elapsed)
  Total   time   46.458s  (1256.110s elapsed)

  Alloc rate    362,948,083 bytes per MUT second

  Productivity  90.4% of total user, 99.5% of total elapsed

With Handle Registry (new)

• Allocation decreased to 57.6%
• GC copies decreased to 40.53%.
• Max. residency increased to 26.3%.
• Max. slop increased to 41.9%.

'/nix/store/r9mwrmw7xv3k35czq8gan6v3n0k0sp55-cardano-tracer-exe-cardano-tracer-0.2.2/bin/cardano-tracer' '--config' 'config.json' +RTS '-T' '-scardano-tracer.gcstats'
   6,462,101,600 bytes allocated in the heap
     457,230,328 bytes copied during GC
       3,000,408 bytes maximum residency (519 sample(s))
         143,496 bytes maximum slop
               9 MiB total memory in use (0 MB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0      5509 colls,     0 par    1.447s   1.513s     0.0003s    0.0106s
  Gen  1       519 colls,     0 par    2.180s   2.289s     0.0044s    0.0640s

  TASKS: 5 (1 bound, 4 peak workers (4 total), using -N1)

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

  INIT    time    0.007s  (  0.074s elapsed)
  MUT     time   34.640s  (1271.401s elapsed)
  GC      time    3.627s  (  3.802s elapsed)
  EXIT    time    0.000s  (  0.002s elapsed)
  Total   time   38.274s  (1275.279s elapsed)

  Alloc rate    186,549,800 bytes per MUT second

  Productivity  90.5% of total user, 99.7% of total elapsed

[mgmeier]

Great @Icelandjack thank you!

[NadiaYvette]

I think GHC.IO.Handle has hFileSize as a more direct equivalent of getFileSize (fstat vs. stat vs. lseek(fd, 0, SEEK_CUR) etc.). In principle, the handle could have seeked within the file, though append mode pins the position to the end of the file. It doesn't necessarily need anything to be changed, but I thought about it while reviewing.

[jutaro]

Looks good!!!

[NadiaYvette]

This is shockingly clean code!