From 77f663489fa8f3d0945459f2c54c165ab3fa8547 Mon Sep 17 00:00:00 2001 From: Matt Haggard Date: Thu, 24 Jan 2019 13:42:10 -0700 Subject: [PATCH 1/2] Increase verbosity of logGC --- doc/nimc.rst | 1 + lib/system/gc.nim | 31 +++++++++++++++++++------------ 2 files changed, 20 insertions(+), 12 deletions(-) diff --git a/doc/nimc.rst b/doc/nimc.rst index 4ffb595c0e12..7c07e09d8efa 100644 --- a/doc/nimc.rst +++ b/doc/nimc.rst @@ -362,6 +362,7 @@ Define Effect ``useRealtimeGC`` Enables support of Nim's GC for *soft* realtime systems. See the documentation of the `gc `_ for further information. +``logGC`` Enable GC logging to stdout. ``nodejs`` The JS target is actually ``node.js``. ``ssl`` Enables OpenSSL support for the sockets module. ``memProfiler`` Enables memory profiling for the native GC. diff --git a/lib/system/gc.nim b/lib/system/gc.nim index 9ae388aa9010..70fa0d5db3c0 100644 --- a/lib/system/gc.nim +++ b/lib/system/gc.nim @@ -105,6 +105,8 @@ template gcAssert(cond: bool, msg: string) = when defined(useGcAssert): if not cond: echo "[GCASSERT] ", msg + when defined(logGC): + echo "[GCASSERT] statistics:\L", GC_getStatistics() GC_disable() writeStackTrace() #var x: ptr int @@ -159,6 +161,10 @@ when defined(logGC): c_fprintf(stdout, "[GC] %s: %p %d %s rc=%ld; thread=%ld\n", msg, c, kind, typName, c.refcount shr rcShift, gch.gcThreadId) +template logCell(msg: cstring, c: PCell) = + when defined(logGC): + writeCell(msg, c) + template gcTrace(cell, state: untyped) = when traceGC: traceCell(cell, state) @@ -171,10 +177,10 @@ proc forAllChildrenAux(dest: pointer, mt: PNimType, op: WalkOp) {.benign.} # we need the prototype here for debugging purposes proc incRef(c: PCell) {.inline.} = - gcAssert(isAllocatedPtr(gch.region, c), "incRef: interiorPtr") + gcAssert(isAllocatedPtr(gch.region, c), "incRef: interiorPtr " & c.repr) c.refcount = c.refcount +% rcIncrement # and not colorMask - #writeCell("incRef", c) + logCell("incRef", c) proc nimGCref(p: pointer) {.compilerProc.} = # we keep it from being collected by pretending it's not even allocated: @@ -187,11 +193,12 @@ proc rtlAddZCT(c: PCell) {.rtl, inl.} = addZCT(gch.zct, c) proc decRef(c: PCell) {.inline.} = - gcAssert(isAllocatedPtr(gch.region, c), "decRef: interiorPtr") - gcAssert(c.refcount >=% rcIncrement, "decRef") + gcAssert(isAllocatedPtr(gch.region, c), "decRef: interiorPtr " & c.repr) + gcAssert(c.refcount >=% rcIncrement, "decRef: " & c.repr) c.refcount = c.refcount -% rcIncrement if c.refcount <% rcIncrement: rtlAddZCT(c) + logCell("decRef", c) proc nimGCunref(p: pointer) {.compilerProc.} = let cell = usrToCell(p) @@ -410,7 +417,7 @@ proc rawNewObj(typ: PNimType, size: int, gch: var GcHeap): pointer = sysAssert(isAllocatedPtr(gch.region, res), "newObj: 3") # its refcount is zero, so add it to the ZCT: addNewObjToZCT(res, gch) - when logGC: writeCell("new cell", res) + logCell("new cell", res) track("rawNewObj", res, size) gcTrace(res, csAllocated) when useCellIds: @@ -455,7 +462,7 @@ proc newObjRC1(typ: PNimType, size: int): pointer {.compilerRtl.} = setFrameInfo(res) res.refcount = rcIncrement # refcount is 1 sysAssert(isAllocatedPtr(gch.region, res), "newObj: 3") - when logGC: writeCell("new cell", res) + logCell("new cell", res) track("newObjRC1", res, size) gcTrace(res, csAllocated) when useCellIds: @@ -493,9 +500,8 @@ proc growObj(old: pointer, newsize: int, gch: var GcHeap): pointer = # This can be wrong for intermediate temps that are nevertheless on the # heap because of lambda lifting: #gcAssert(res.refcount shr rcShift <=% 1, "growObj: 4") - when logGC: - writeCell("growObj old cell", ol) - writeCell("growObj new cell", res) + logCell("growObj old cell", ol) + logCell("growObj new cell", res) gcTrace(ol, csZctFreed) gcTrace(res, csAllocated) track("growObj old", ol, 0) @@ -547,7 +553,7 @@ proc freeCyclicCell(gch: var GcHeap, c: PCell) = prepareDealloc(c) gcTrace(c, csCycFreed) track("cycle collector dealloc cell", c, 0) - when logGC: writeCell("cycle collector dealloc cell", c) + logCell("cycle collector dealloc cell", c) when reallyDealloc: sysAssert(allocInv(gch.region), "free cyclic cell") beforeDealloc(gch, c, "freeCyclicCell: stack trash") @@ -616,7 +622,7 @@ proc doOperation(p: pointer, op: WalkOp) = # c_fprintf(stdout, "[GC] decref bug: %p", c) gcAssert(isAllocatedPtr(gch.region, c), "decRef: waZctDecRef") gcAssert(c.refcount >=% rcIncrement, "doOperation 2") - when logGC: writeCell("decref (from doOperation)", c) + logCell("decref (from doOperation)", c) track("waZctDecref", p, 0) decRef(c) of waPush: @@ -704,7 +710,7 @@ proc collectZCT(gch: var GcHeap): bool = # as this might be too slow. # In any case, it should be removed from the ZCT. But not # freed. **KEEP THIS IN MIND WHEN MAKING THIS INCREMENTAL!** - when logGC: writeCell("zct dealloc cell", c) + logCell("zct dealloc cell", c) track("zct dealloc cell", c, 0) gcTrace(c, csZctFreed) # We are about to free the object, call the finalizer BEFORE its @@ -858,6 +864,7 @@ when not defined(useNimRtl): for stack in items(gch.stack): result.add "[GC] stack " & stack.bottom.repr & "[GC] max stack size " & cast[pointer](stack.maxStackSize).repr & "\n" else: + result.add "[GC] stack bottom: " & gch.stack.bottom.repr result.add "[GC] max stack size: " & $gch.stat.maxStackSize & "\n" {.pop.} # profiler: off, stackTrace: off From 00437dfbe76685220c64f08de394c0237dfb17e1 Mon Sep 17 00:00:00 2001 From: Matt Haggard Date: Fri, 25 Jan 2019 09:26:26 -0700 Subject: [PATCH 2/2] Remove & c.repr to avoid re-entering the GC --- lib/system/gc.nim | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/system/gc.nim b/lib/system/gc.nim index 70fa0d5db3c0..416827f21f3d 100644 --- a/lib/system/gc.nim +++ b/lib/system/gc.nim @@ -177,7 +177,7 @@ proc forAllChildrenAux(dest: pointer, mt: PNimType, op: WalkOp) {.benign.} # we need the prototype here for debugging purposes proc incRef(c: PCell) {.inline.} = - gcAssert(isAllocatedPtr(gch.region, c), "incRef: interiorPtr " & c.repr) + gcAssert(isAllocatedPtr(gch.region, c), "incRef: interiorPtr") c.refcount = c.refcount +% rcIncrement # and not colorMask logCell("incRef", c) @@ -193,8 +193,8 @@ proc rtlAddZCT(c: PCell) {.rtl, inl.} = addZCT(gch.zct, c) proc decRef(c: PCell) {.inline.} = - gcAssert(isAllocatedPtr(gch.region, c), "decRef: interiorPtr " & c.repr) - gcAssert(c.refcount >=% rcIncrement, "decRef: " & c.repr) + gcAssert(isAllocatedPtr(gch.region, c), "decRef: interiorPtr") + gcAssert(c.refcount >=% rcIncrement, "decRef") c.refcount = c.refcount -% rcIncrement if c.refcount <% rcIncrement: rtlAddZCT(c)