status-im / nim-chronos

Chronos - An efficient library for asynchronous programming
https://status-im.github.io/nim-chronos/docs/chronos
Apache License 2.0
353 stars 51 forks source link

Cycle-based memory Leak under --mm:arc #496

Open PhilippMDoerner opened 5 months ago

PhilippMDoerner commented 5 months ago

Heyho,

While writing code for a library of mine with chronos I noticed that some of my tests were showing leaks under address sanitizer, but only under --mm:arc. I managed to reduce it down to a minimal example - The main thread sends 10 messages to a receiver thread, which processes them in an async proc.

Given that the leaks only occurs under arc and the number of leaks scales perfectly with the number of messages sent (3 per message) I'm prone to assuming that there's a cycle occuring somewhere, though I can't claim to understand where or how.

Example

# playground.nim
import chronos
import chronos/threadsync
import std/[os, sequtils, atomics]
import threading/channels

var chan = newChan[int](50)
let signal = ThreadSignalPtr.new()[]
var receiver = Thread[void]()
var counter: Atomic[int]

const MESSAGE_COUNT = 10

proc process1Message() {.async.} =
  await sleepAsync(100)
  counter.atomicInc
  echo "after ", counter.load()

proc receiverThread() {.thread.} =
  var msg: int

  while counter.load() != MESSAGE_COUNT:
    let success = chan.tryRecv(msg)
    if success:
      asyncSpawn process1Message()

    waitFor signal.wait()

  {.gcsafe.}:
    `=destroy`(getThreadDispatcher())
    when defined(gcOrc):
      GC_fullCollect() # from orc.nim. Has no destructor.

proc main() = 
  receiver.createThread(receiverThread)

  for y in 0 ..< MESSAGE_COUNT:
    chan.send(y)
    discard signal.fireSync()

  while counter.load() != MESSAGE_COUNT:
    discard signal.fireSync()

  joinThread(receiver)
  echo "FINISHED"

main()

When running this with the following command with orc it will not show any leaks:

nim r -f --cc:clang --mm:orc -d:useMalloc --passc:"-fsanitize=address -fno-omit-frame-pointer -mno-omit-leaf-frame-pointer" --passl:"-fsanitize=address -fno-omit-frame-pointer -mno-omit-leaf-frame-pointer" --debugger:native -d:release src/playground.nim

When running this with the same command but with arc it will show leaks:

nim r -f --cc:clang --mm:arc -d:useMalloc --passc:"-fsanitize=address -fno-omit-frame-pointer -mno-omit-leaf-frame-pointer" --passl:"-fsanitize=address -fno-omit-frame-pointer -mno-omit-leaf-frame-pointer" --debugger:native -d:release src/playground.nim

This will find around 3 leaks per message

Stacktrace

=================================================================
==165270==ERROR: LeakSanitizer: detected memory leaks

Indirect leak of 1040 byte(s) in 10 object(s) allocated from:
    #0 0x5c5bac26ed51 in __interceptor_calloc (/home/philipp/.cache/nim/playground_r/playground_C5C9B22B806F68CBB192150CD91671297767D678+0x111d51) (BuildId: c43984a443732182d47afff91b6ea6b0a6fe14b1)
    #1 0x5c5bac2bb573 in nimNewObj /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/arc.nim:81:343
    #2 0x5c5bac2e23f9 in newInternalRaisesFutureImpl__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u1318 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:97:312
    #3 0x5c5bac2e23f9 in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2454 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:118:23
    #4 0x5c5bac2e822a in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2507 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:1349:230
    #5 0x5c5bac2e822a in process1Message__playground_u231 /home/philipp/dev/playground/src/playground.nim:14:27
    #6 0x5c5bac2e2d53 in futureContinue__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u702 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:378:97
    #7 0x5c5bac2e966e in process1Message__playground_u232 /home/philipp/dev/playground/src/playground.nim:14:2
    #8 0x5c5bac2e9a93 in receiverThread__playground_u383 /home/philipp/dev/playground/src/playground.nim:25:47
    #9 0x5c5bac2bd95a in threadProcWrapDispatch__stdZtypedthreads_u105 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:66:2
    #10 0x5c5bac2bd95a in threadProcWrapStackFrame__stdZtypedthreads_u95 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:95:2
    #11 0x5c5bac2b8128 in threadProcWrapper__stdZtypedthreads_u81 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:101:2
    #12 0x7bcf18de89ea  (/usr/lib/libc.so.6+0x8c9ea) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)

Indirect leak of 400 byte(s) in 10 object(s) allocated from:
    #0 0x5c5bac26e9e9 in __interceptor_malloc (/home/philipp/.cache/nim/playground_r/playground_C5C9B22B806F68CBB192150CD91671297767D678+0x1119e9) (BuildId: c43984a443732182d47afff91b6ea6b0a6fe14b1)
    #1 0x5c5bac2c0e29 in allocImpl__system_u1761 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/mm/malloc.nim:5:11
    #2 0x5c5bac2c0e29 in allocSharedImpl /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/mm/malloc.nim:34:11
    #3 0x5c5bac2c0e29 in alignedAlloc__system_u1901 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/memalloc.nim:331:12
    #4 0x5c5bac2c0e29 in nimNewObjUninit /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/arc.nim:99:343
    #5 0x5c5bac2d8f35 in setTimer__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncengine_u14160 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncengine.nim:1108:90
    #6 0x5c5bac2e25bf in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2454 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:1343:284
    #7 0x5c5bac2e822a in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2507 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:1349:230
    #8 0x5c5bac2e822a in process1Message__playground_u231 /home/philipp/dev/playground/src/playground.nim:14:27
    #9 0x5c5bac2e2d53 in futureContinue__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u702 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:378:97
    #10 0x5c5bac2e966e in process1Message__playground_u232 /home/philipp/dev/playground/src/playground.nim:14:2
    #11 0x5c5bac2e9a93 in receiverThread__playground_u383 /home/philipp/dev/playground/src/playground.nim:25:47
    #12 0x5c5bac2bd95a in threadProcWrapDispatch__stdZtypedthreads_u105 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:66:2
    #13 0x5c5bac2bd95a in threadProcWrapStackFrame__stdZtypedthreads_u95 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:95:2
    #14 0x5c5bac2b8128 in threadProcWrapper__stdZtypedthreads_u81 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:101:2
    #15 0x7bcf18de89ea  (/usr/lib/libc.so.6+0x8c9ea) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)

Indirect leak of 400 byte(s) in 10 object(s) allocated from:
    #0 0x5c5bac26ed51 in __interceptor_calloc (/home/philipp/.cache/nim/playground_r/playground_C5C9B22B806F68CBB192150CD91671297767D678+0x111d51) (BuildId: c43984a443732182d47afff91b6ea6b0a6fe14b1)
    #1 0x5c5bac2bb573 in nimNewObj /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/arc.nim:81:343
    #2 0x5c5bac2e2392 in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2454 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:1331:390
    #3 0x5c5bac2e822a in sleepAsync__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u2507 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:1349:230
    #4 0x5c5bac2e822a in process1Message__playground_u231 /home/philipp/dev/playground/src/playground.nim:14:27
    #5 0x5c5bac2e2d53 in futureContinue__OOZnimbledepsZpkgs50Zchronos4551O50O4845f53d564848dc555350d52f5353b57485357575154535157525657e484856f504849faZchronosZinternalZasyncfutures_u702 /home/philipp/dev/playground/nimbledeps/pkgs2/chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa/chronos/internal/asyncfutures.nim:378:97
    #6 0x5c5bac2e966e in process1Message__playground_u232 /home/philipp/dev/playground/src/playground.nim:14:2
    #7 0x5c5bac2e9a93 in receiverThread__playground_u383 /home/philipp/dev/playground/src/playground.nim:25:47
    #8 0x5c5bac2bd95a in threadProcWrapDispatch__stdZtypedthreads_u105 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:66:2
    #9 0x5c5bac2bd95a in threadProcWrapStackFrame__stdZtypedthreads_u95 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:95:2
    #10 0x5c5bac2b8128 in threadProcWrapper__stdZtypedthreads_u81 /home/philipp/.choosenim/toolchains/nim-2.0.2/lib/system/threadimpl.nim:101:2
    #11 0x7bcf18de89ea  (/usr/lib/libc.so.6+0x8c9ea) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)

SUMMARY: AddressSanitizer: 1840 byte(s) leaked in 30 allocation(s).

Nim Version:

Nim Compiler Version 2.0.2 [Linux: amd64]
Compiled at 2023-12-15
Copyright (c) 2006-2023 by Andreas Rumpf

git hash: c4c44d10df8a14204a75c34e499def200589cb7c
active boot switches: -d:release

Chronos version:

chronos-3.2.0-f5d800dc752d4f55b9059936539489e008f201fa

That should be the last or second-to-last commit on the repo since I installed the chronos version via requires "chronos#head" around 5h ago.

arnetheduck commented 4 months ago

simplified version:

import chronos

var counter{.threadvar.}: int

const MESSAGE_COUNT = 10

proc process1Message() {.async.} =
  await sleepAsync(100)
  counter.inc
  echo "after ", counter

proc main() =
  for i in 0..<MESSAGE_COUNT:
    asyncSpawn process1Message()

  while counter != MESSAGE_COUNT:
    poll()

  echo "FINISHED"

  when defined(gcOrc):
    GC_fullCollect() # from orc.nim. Has no destructor.

main()