From bdb493947ef1b581f0219919299fa7203ff5b5fe Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Thu, 6 Apr 2017 13:56:47 +0200 Subject: [PATCH 01/10] TMP --- src/rt/profilegc.d | 16 ++++++---------- 1 file changed, 6 insertions(+), 10 deletions(-) diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index a3c5ce6235..a5ec1a8396 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -89,18 +89,14 @@ static ~this() { synchronized { - if (globalNewCounts.length) + foreach (name, entry; newCounts) { - // Merge - foreach (name, entry; newCounts) - { - globalNewCounts[name].count += entry.count; - globalNewCounts[name].size += entry.size; - } + if (!(name in globalNewCounts)) + globalNewCounts[name] = Entry.init; + + globalNewCounts[name].count += entry.count; + globalNewCounts[name].size += entry.size; } - else - // Assign - globalNewCounts = newCounts; } newCounts = null; } From 9b41d5b5c92193929567483901c68fe51042a936 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Thu, 6 Apr 2017 12:59:17 +0200 Subject: [PATCH 02/10] Introduce `GC.Stats.totalCollected` --- changelog/collect-stats.dd | 5 +++++ src/core/memory.d | 7 +++++-- src/gc/impl/conservative/gc.d | 6 +++++- 3 files changed, 15 insertions(+), 3 deletions(-) create mode 100644 changelog/collect-stats.dd diff --git a/changelog/collect-stats.dd b/changelog/collect-stats.dd new file mode 100644 index 0000000000..26c14e76b2 --- /dev/null +++ b/changelog/collect-stats.dd @@ -0,0 +1,5 @@ +`GC.Stats` provide new metric, total collected memory. + +Result struct of `core.memory.GC.stats()` method now provides additional field, +`totalCollected`, which is set to total amount of bytes reclaimed by GC during +collection cycles since the program start. diff --git a/src/core/memory.d b/src/core/memory.d index 573ed2e8b2..5f73a32fcd 100644 --- a/src/core/memory.d +++ b/src/core/memory.d @@ -165,9 +165,12 @@ struct GC static struct Stats { /// number of used bytes on the GC heap (might only get updated after a collection) - size_t usedSize; + ulong usedSize; /// number of free bytes on the GC heap (might only get updated after a collection) - size_t freeSize; + ulong freeSize; + /// number of bytes freed during collections through program lifetime so + /// far (will count same memory multiple times if re-used) + ulong totalCollected; } /** diff --git a/src/gc/impl/conservative/gc.d b/src/gc/impl/conservative/gc.d index fe1ca5f858..08ff730135 100644 --- a/src/gc/impl/conservative/gc.d +++ b/src/gc/impl/conservative/gc.d @@ -115,6 +115,7 @@ __gshared long numFrees; __gshared long numReallocs; __gshared long numExtends; __gshared long numOthers; +__gshared long totalCollectedPages; __gshared long mallocTime; // using ticks instead of MonoTime for better performance __gshared long freeTime; __gshared long reallocTime; @@ -1227,6 +1228,7 @@ class ConservativeGC : GC stats.usedSize -= freeListSize; stats.freeSize += freeListSize; + stats.totalCollected = .totalCollectedPages * PAGESIZE; } } @@ -2434,7 +2436,9 @@ struct Gcx updateCollectThresholds(); - return freedLargePages + freedSmallPages; + auto total = freedLargePages + freedSmallPages; + totalCollectedPages += total; + return total; } /** From 61024844462648198991e1645ccd496f79553935 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 13:45:55 +0200 Subject: [PATCH 03/10] Use ulong instead of size_t by -profile=gc --- src/rt/profilegc.d | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index a5ec1a8396..e8e0bde969 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -21,7 +21,7 @@ import core.stdc.string; import core.exception : onOutOfMemoryError; -struct Entry { size_t count, size; } +struct Entry { ulong count, size; } char[] buffer; Entry[string] newCounts; @@ -46,7 +46,8 @@ extern (C) void profilegc_setlogfilename(string name) -public void accumulate(string file, uint line, string funcname, string type, size_t sz) +public void accumulate(string file, uint line, string funcname, string type, + ulong sz) { char[3 * line.sizeof + 1] buf; auto buflen = snprintf(buf.ptr, buf.length, "%u", line); @@ -117,7 +118,7 @@ shared static ~this() { auto result1 = cast(Result*)r1; auto result2 = cast(Result*)r2; - ptrdiff_t cmp = result2.entry.size - result1.entry.size; + long cmp = result2.entry.size - result1.entry.size; if (cmp) return cmp < 0 ? -1 : 1; cmp = result2.entry.count - result1.entry.count; return cmp < 0 ? -1 : (cmp > 0 ? 1 : 0); From 9ffc9473cd2d9f52367227837679787b8eacd817 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Thu, 6 Apr 2017 13:10:29 +0200 Subject: [PATCH 04/10] Replace manual trace printfs with a mixin Comes at cost of losing some custom function arguments but is much more maintainable and readable. --- src/rt/tracegc.d | 287 +++++++---------------------------------------- 1 file changed, 41 insertions(+), 246 deletions(-) diff --git a/src/rt/tracegc.d b/src/rt/tracegc.d index 708ca347be..8845dd9ba6 100644 --- a/src/rt/tracegc.d +++ b/src/rt/tracegc.d @@ -13,7 +13,7 @@ module rt.tracegc; -//version = tracegc; +// version = tracegc; import rt.profilegc; @@ -91,65 +91,47 @@ extern (C) void[] _d_newarraymiTX(const TypeInfo ti, size_t[] dims); extern (C) void* _d_newitemT(in TypeInfo _ti); extern (C) void* _d_newitemiT(in TypeInfo _ti); -extern (C) Object _d_newclassTrace(string file, int line, string funcname, const ClassInfo ci) +private string generatePrintf ( ) { version (tracegc) { - printf("_d_newclassTrace class = %s file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ci.name, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); + return q{ + printf("%s file = '%.*s' line = %d function = '%.*s'\n", + __FUNCTION__.ptr, + file.length, file.ptr, + line, + funcname.length, funcname.ptr + ); + }; } + else + return ""; +} + +extern (C) Object _d_newclassTrace(string file, int line, string funcname, const ClassInfo ci) +{ + mixin(generatePrintf()); accumulate(file, line, funcname, ci.name, ci.initializer.length); return _d_newclass(ci); } extern (C) void[] _d_newarrayTTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) { - version (tracegc) - { - printf("_d_newarrayTTrace type = %s length = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.tsize * length); return _d_newarrayT(ti, length); } extern (C) void[] _d_newarrayiTTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) { - version (tracegc) - { - printf("_d_newarrayiTTrace type = %s length = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.tsize * length); return _d_newarrayiT(ti, length); } extern (C) void[] _d_newarraymTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t[] dims) { - version (tracegc) - { - printf("_d_newarraymTXTrace type = %s dims = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)dims.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); size_t n = 1; foreach (dim; dims) n *= dim; @@ -159,16 +141,7 @@ extern (C) void[] _d_newarraymTXTrace(string file, int line, string funcname, co extern (C) void[] _d_newarraymiTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t[] dims) { - version (tracegc) - { - printf("_d_newarraymiTXTrace type = %s dims = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)dims.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); size_t n = 1; foreach (dim; dims) n *= dim; @@ -178,30 +151,14 @@ extern (C) void[] _d_newarraymiTXTrace(string file, int line, string funcname, c extern (C) void* _d_newitemTTrace(string file, int line, string funcname, in TypeInfo ti) { - version (tracegc) - { - printf("_d_newitemTTrace type = %s file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.tsize); return _d_newitemT(ti); } extern (C) void* _d_newitemiTTrace(string file, int line, string funcname, in TypeInfo ti) { - version (tracegc) - { - printf("_d_newitemiTTrace type = %s file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.tsize); return _d_newitemiT(ti); } @@ -217,101 +174,43 @@ extern (C) void _d_delmemory(void* *p); extern (C) void _d_callfinalizerTrace(string file, int line, string funcname, void* p) { - version (tracegc) - { - printf("_d_callfinalizerTrace %p file = '%.*s' line = %d function = '%.*s'\n", - p, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_callfinalizer(p); } extern (C) void _d_callinterfacefinalizerTrace(string file, int line, string funcname, void *p) { - version (tracegc) - { - printf("_d_callinterfacefinalizerTrace %p file = '%.*s' line = %d function = '%.*s'\n", - p, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_callinterfacefinalizer(p); } extern (C) void _d_delclassTrace(string file, int line, string funcname, Object* p) { - version (tracegc) - { - printf("_d_delclassTrace %p file = '%.*s' line = %d function = '%.*s'\n", - *p, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_delclass(p); } extern (C) void _d_delinterfaceTrace(string file, int line, string funcname, void** p) { - version (tracegc) - { - printf("_d_delinterfaceTrace %p file = '%.*s' line = %d function = '%.*s'\n", - *p, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_delinterface(p); } extern (C) void _d_delstructTrace(string file, int line, string funcname, void** p, TypeInfo_Struct inf) { - version (tracegc) - { - printf("_d_delstructTrace %p type = %s file = '%.*s' line = %d function = '%.*s'\n", - *p, - cast(char *)inf.toString().ptr, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_delstruct(p, inf); } extern (C) void _d_delarray_tTrace(string file, int line, string funcname, void[]* p, const TypeInfo_Struct ti) { - version (tracegc) - { - printf("_d_delarray_tTrace %p[%llu] type = %s file = '%.*s' line = %d function = '%.*s'\n", - (*p).ptr, cast(ulong)(*p).length, - ti ? cast(char *)ti.toString().ptr : cast(char*)"".ptr, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_delarray_t(p, ti); } extern (C) void _d_delmemoryTrace(string file, int line, string funcname, void* *p) { - version (tracegc) - { - printf("_d_delmemoryTrace %p file = '%.*s' line = %d function = '%.*s'\n", - *p, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); _d_delmemory(p); } @@ -321,16 +220,7 @@ extern (C) void* _d_assocarrayliteralTX(const TypeInfo_AssociativeArray ti, void extern (C) void* _d_arrayliteralTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) { - version (tracegc) - { - printf("_d_arrayliteralTXTrace type = %s length = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.next.tsize * length); return _d_arrayliteralTX(ti, length); } @@ -338,17 +228,7 @@ extern (C) void* _d_arrayliteralTXTrace(string file, int line, string funcname, extern (C) void* _d_assocarrayliteralTXTrace(string file, int line, string funcname, const TypeInfo_AssociativeArray ti, void[] keys, void[] vals) { - version (tracegc) - { - printf("_d_assocarrayliteralTXTrace type = %s keys = %llu values = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)keys.length, - cast(ulong)vals.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), (ti.key.tsize + ti.value.tsize) * keys.length); return _d_assocarrayliteralTX(ti, keys, vals); } @@ -360,33 +240,14 @@ extern (C) void[] _d_arraycatnTX(const TypeInfo ti, byte[][] arrs); extern (C) byte[] _d_arraycatTTrace(string file, int line, string funcname, const TypeInfo ti, byte[] x, byte[] y) { - version (tracegc) - { - printf("_d_arraycatT type = %s x = %llu y = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)x.length, - cast(ulong)y.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), (x.length + y.length) * ti.next.tsize); return _d_arraycatT(ti, x, y); } extern (C) void[] _d_arraycatnTXTrace(string file, int line, string funcname, const TypeInfo ti, byte[][] arrs) { - version (tracegc) - { - printf("_d_arraycatnTX type = %s arrs = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)arrs.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); size_t length; foreach (b; arrs) length += b.length; @@ -401,50 +262,21 @@ extern (C) void[] _d_arrayappendwd(ref byte[] x, dchar c); extern (C) void[] _d_arrayappendTTrace(string file, int line, string funcname, const TypeInfo ti, ref byte[] x, byte[] y) { - version (tracegc) - { - printf("_d_arrayappendT type = %s x = %llu y = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)x.length, - cast(ulong)y.length, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.next.tsize * y.length); return _d_arrayappendT(ti, x, y); } extern (C) byte[] _d_arrayappendcTXTrace(string file, int line, string funcname, const TypeInfo ti, ref byte[] px, size_t n) { - version (tracegc) - { - printf("_d_arrayappendcTX type = %s x = %llu n = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)px.length, - cast(ulong)n, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.next.tsize * n); return _d_arrayappendcTX(ti, px, n); } extern (C) void[] _d_arrayappendcdTrace(string file, int line, string funcname, ref byte[] x, dchar c) { - version (tracegc) - { - printf("_d_arrayappendcd x = %llu c = x%x file = '%.*s' line = %d function = '%.*s'\n", - cast(ulong)x.length, - c, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); size_t n; if (c <= 0x7F) n = 1; @@ -462,16 +294,7 @@ extern (C) void[] _d_arrayappendcdTrace(string file, int line, string funcname, extern (C) void[] _d_arrayappendwdTrace(string file, int line, string funcname, ref byte[] x, dchar c) { - version (tracegc) - { - printf("_d_arrayappendwd x = %llu c = x%x file = '%.*s' line = %d function = '%.*s'\n", - cast(ulong)x.length, - c, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); size_t n = 1 + (c > 0xFFFF); accumulate(file, line, funcname, "wchar[]", n * wchar.sizeof); return _d_arrayappendwd(x, c); @@ -482,34 +305,14 @@ extern (C) void[] _d_arraysetlengthiT(const TypeInfo ti, size_t newlength, void[ extern (C) void[] _d_arraysetlengthTTrace(string file, int line, string funcname, const TypeInfo ti, size_t newlength, void[]* p) { - version (tracegc) - { - printf("_d_arraysetlengthT type = %s length = %llu newlength = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)(*p).length, - cast(ulong)newlength, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.next.tsize * newlength); return _d_arraysetlengthT(ti, newlength, p); } extern (C) void[] _d_arraysetlengthiTTrace(string file, int line, string funcname, const TypeInfo ti, size_t newlength, void[]* p) { - version (tracegc) - { - printf("_d_arraysetlengthiT type = %s length = %llu newlength = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(char *)ti.toString().ptr, - cast(ulong)(*p).length, - cast(ulong)newlength, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, ti.toString(), ti.next.tsize * newlength); return _d_arraysetlengthiT(ti, newlength, p); } @@ -519,15 +322,7 @@ extern (C) void* _d_allocmemory(size_t sz); extern (C) void* _d_allocmemoryTrace(string file, int line, string funcname, size_t sz) { - version (tracegc) - { - printf("_d_allocmemory sz = %llu file = '%.*s' line = %d function = '%.*s'\n", - cast(ulong)sz, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - } + mixin(generatePrintf()); accumulate(file, line, funcname, "closure", sz); return _d_allocmemory(sz); } From 3bec1bfe39035afd1fe905a88b51f9f7b0890805 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Sun, 9 Apr 2017 16:01:14 +0200 Subject: [PATCH 05/10] Rework how -profile=gc output is calculated Replaced approximation based of function arguments with a call to GC stats to always get exact amount of bytes allocated. As new implementation is generic and suitable for any wrapped function, manual wrappers have been replaced with string mixin approach. --- src/core/internal/traits.d | 1 + src/rt/tracegc.d | 335 +++++++++++-------------------- test/profile/bothgc.log.exp | 2 +- test/profile/myprofilegc.log.exp | 2 +- 4 files changed, 125 insertions(+), 215 deletions(-) diff --git a/src/core/internal/traits.d b/src/core/internal/traits.d index 8142f90c51..7b1b7bdf69 100644 --- a/src/core/internal/traits.d +++ b/src/core/internal/traits.d @@ -187,3 +187,4 @@ template hasElaborateCopyConstructor(T...) else enum bool hasElaborateCopyConstructor = false; } + diff --git a/src/rt/tracegc.d b/src/rt/tracegc.d index 8845dd9ba6..9cabf2fdcc 100644 --- a/src/rt/tracegc.d +++ b/src/rt/tracegc.d @@ -15,10 +15,6 @@ module rt.tracegc; // version = tracegc; -import rt.profilegc; - -version (tracegc) import core.stdc.stdio; - version (none) { // this exercises each function @@ -88,243 +84,156 @@ extern (C) void[] _d_newarrayT(const TypeInfo ti, size_t length); extern (C) void[] _d_newarrayiT(const TypeInfo ti, size_t length); extern (C) void[] _d_newarraymTX(const TypeInfo ti, size_t[] dims); extern (C) void[] _d_newarraymiTX(const TypeInfo ti, size_t[] dims); -extern (C) void* _d_newitemT(in TypeInfo _ti); -extern (C) void* _d_newitemiT(in TypeInfo _ti); - -private string generatePrintf ( ) -{ - version (tracegc) - { - return q{ - printf("%s file = '%.*s' line = %d function = '%.*s'\n", - __FUNCTION__.ptr, - file.length, file.ptr, - line, - funcname.length, funcname.ptr - ); - }; - } - else - return ""; -} - -extern (C) Object _d_newclassTrace(string file, int line, string funcname, const ClassInfo ci) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ci.name, ci.initializer.length); - return _d_newclass(ci); -} - -extern (C) void[] _d_newarrayTTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.tsize * length); - return _d_newarrayT(ti, length); -} - -extern (C) void[] _d_newarrayiTTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.tsize * length); - return _d_newarrayiT(ti, length); -} - -extern (C) void[] _d_newarraymTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t[] dims) -{ - mixin(generatePrintf()); - size_t n = 1; - foreach (dim; dims) - n *= dim; - accumulate(file, line, funcname, ti.toString(), ti.tsize * n); - return _d_newarraymTX(ti, dims); -} - -extern (C) void[] _d_newarraymiTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t[] dims) -{ - mixin(generatePrintf()); - size_t n = 1; - foreach (dim; dims) - n *= dim; - accumulate(file, line, funcname, ti.toString(), ti.tsize * n); - return _d_newarraymiTX(ti, dims); -} - -extern (C) void* _d_newitemTTrace(string file, int line, string funcname, in TypeInfo ti) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.tsize); - return _d_newitemT(ti); -} - -extern (C) void* _d_newitemiTTrace(string file, int line, string funcname, in TypeInfo ti) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.tsize); - return _d_newitemiT(ti); -} - - +extern (C) void* _d_newitemT(in TypeInfo ti); +extern (C) void* _d_newitemiT(in TypeInfo ti); extern (C) void _d_callfinalizer(void* p); extern (C) void _d_callinterfacefinalizer(void *p); extern (C) void _d_delclass(Object* p); extern (C) void _d_delinterface(void** p); extern (C) void _d_delstruct(void** p, TypeInfo_Struct inf); -extern (C) void _d_delarray_t(void[]* p, const TypeInfo_Struct ti); +extern (C) void _d_delarray_t(void[]* p, const TypeInfo_Struct _); extern (C) void _d_delmemory(void* *p); - -extern (C) void _d_callfinalizerTrace(string file, int line, string funcname, void* p) -{ - mixin(generatePrintf()); - _d_callfinalizer(p); -} - -extern (C) void _d_callinterfacefinalizerTrace(string file, int line, string funcname, void *p) -{ - mixin(generatePrintf()); - _d_callinterfacefinalizer(p); -} - -extern (C) void _d_delclassTrace(string file, int line, string funcname, Object* p) -{ - mixin(generatePrintf()); - _d_delclass(p); -} - -extern (C) void _d_delinterfaceTrace(string file, int line, string funcname, void** p) -{ - mixin(generatePrintf()); - _d_delinterface(p); -} - -extern (C) void _d_delstructTrace(string file, int line, string funcname, void** p, TypeInfo_Struct inf) -{ - mixin(generatePrintf()); - _d_delstruct(p, inf); -} - -extern (C) void _d_delarray_tTrace(string file, int line, string funcname, void[]* p, const TypeInfo_Struct ti) -{ - mixin(generatePrintf()); - _d_delarray_t(p, ti); -} - -extern (C) void _d_delmemoryTrace(string file, int line, string funcname, void* *p) -{ - mixin(generatePrintf()); - _d_delmemory(p); -} - - +extern (C) byte[] _d_arraycatT(const TypeInfo ti, byte[] x, byte[] y); +extern (C) void[] _d_arraycatnTX(const TypeInfo ti, byte[][] arrs); extern (C) void* _d_arrayliteralTX(const TypeInfo ti, size_t length); -extern (C) void* _d_assocarrayliteralTX(const TypeInfo_AssociativeArray ti, void[] keys, void[] vals); +extern (C) void* _d_assocarrayliteralTX(const TypeInfo_AssociativeArray ti, + void[] keys, void[] vals); +extern (C) void[] _d_arrayappendT(const TypeInfo ti, ref byte[] x, byte[] y); +extern (C) byte[] _d_arrayappendcTX(const TypeInfo ti, ref byte[] px, size_t n); +extern (C) void[] _d_arrayappendcd(ref byte[] x, dchar c); +extern (C) void[] _d_arrayappendwd(ref byte[] x, dchar c); +extern (C) void[] _d_arraysetlengthT(const TypeInfo ti, size_t newlength, void[]* p); +extern (C) void[] _d_arraysetlengthiT(const TypeInfo ti, size_t newlength, void[]* p); +extern (C) void* _d_allocmemory(size_t sz); -extern (C) void* _d_arrayliteralTXTrace(string file, int line, string funcname, const TypeInfo ti, size_t length) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.next.tsize * length); - return _d_arrayliteralTX(ti, length); -} +// Used as wrapper function body to get actual stats. Calling `original_func()` +// will call wrapped function with all required arguments. +// +// Placed here as a separate string constant to simplify maintenance as it is +// much more likely to be modified than rest of generation code. +enum accumulator = q{ + import rt.profilegc : accumulate; + import core.memory : GC; + + static if (is(typeof(ci))) + string name = ci.name; + else static if (is(typeof(ti))) + string name = ti.toString(); + else static if (__FUNCTION__ == "rt.tracegc._d_arrayappendcdTrace") + string name = "char[]"; + else static if (__FUNCTION__ == "rt.tracegc._d_arrayappendwdTrace") + string name = "wchar[]"; + else static if (__FUNCTION__ == "rt.tracegc._d_allocmemoryTrace") + string name = "closure"; + else + string name = ""; -extern (C) void* _d_assocarrayliteralTXTrace(string file, int line, string funcname, - const TypeInfo_AssociativeArray ti, void[] keys, void[] vals) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), (ti.key.tsize + ti.value.tsize) * keys.length); - return _d_assocarrayliteralTX(ti, keys, vals); -} + version(tracegc) + { + import core.stdc.stdio; + + printf("%s file = '%.*s' line = %d function = '%.*s' type = %.*s\n", + __FUNCTION__.ptr, + file.length, file.ptr, + line, + funcname.length, funcname.ptr, + name.length, name.ptr + ); + } + auto stats1 = GC.stats(); + scope(exit) + { + auto stats2 = GC.stats(); + if (stats2.totalCollected < stats1.totalCollected) + { + // need to account for unsigned overflow possibility if app is being + // run very long + stats2.totalCollected += typeof(stats1.totalCollected).max + - stats1.totalCollected; + stats1.totalCollected = 0; + } + ulong size = (stats2.usedSize + stats2.totalCollected) - + (stats1.usedSize + stats1.totalCollected); + if (size > 0) + accumulate(file, line, funcname, name, size); + } + return original_func(); +}; -extern (C) byte[] _d_arraycatT(const TypeInfo ti, byte[] x, byte[] y); -extern (C) void[] _d_arraycatnTX(const TypeInfo ti, byte[][] arrs); +mixin(generateTraceWrappers()); +//pragma(msg, generateTraceWrappers()); -extern (C) byte[] _d_arraycatTTrace(string file, int line, string funcname, const TypeInfo ti, byte[] x, byte[] y) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), (x.length + y.length) * ti.next.tsize); - return _d_arraycatT(ti, x, y); -} +//////////////////////////////////////////////////////////////////////////////// +// code gen implementation -extern (C) void[] _d_arraycatnTXTrace(string file, int line, string funcname, const TypeInfo ti, byte[][] arrs) +private string generateTraceWrappers() { - mixin(generatePrintf()); - size_t length; - foreach (b; arrs) - length += b.length; - accumulate(file, line, funcname, ti.toString(), length * ti.next.tsize); - return _d_arraycatnTX(ti, arrs); -} + string code; -extern (C) void[] _d_arrayappendT(const TypeInfo ti, ref byte[] x, byte[] y); -extern (C) byte[] _d_arrayappendcTX(const TypeInfo ti, ref byte[] px, size_t n); -extern (C) void[] _d_arrayappendcd(ref byte[] x, dchar c); -extern (C) void[] _d_arrayappendwd(ref byte[] x, dchar c); + foreach (name; __traits(allMembers, mixin(__MODULE__))) + { + static if (name.length > 3 && name[0..3] == "_d_") + { + mixin("alias Declaration = " ~ name ~ ";"); + code ~= generateWrapper!Declaration(); + } + } -extern (C) void[] _d_arrayappendTTrace(string file, int line, string funcname, const TypeInfo ti, ref byte[] x, byte[] y) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.next.tsize * y.length); - return _d_arrayappendT(ti, x, y); + return code; } -extern (C) byte[] _d_arrayappendcTXTrace(string file, int line, string funcname, const TypeInfo ti, ref byte[] px, size_t n) +private string generateWrapper(alias Declaration)() { - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.next.tsize * n); - return _d_arrayappendcTX(ti, px, n); -} + static size_t findParamIndex(string s) + { + assert (s[$-1] == ')'); + size_t brackets = 1; + while (brackets != 0) + { + s = s[0 .. $-1]; + if (s[$-1] == ')') + ++brackets; + if (s[$-1] == '(') + --brackets; + } + + assert(s.length > 1); + return s.length - 1; + } -extern (C) void[] _d_arrayappendcdTrace(string file, int line, string funcname, ref byte[] x, dchar c) -{ - mixin(generatePrintf()); - size_t n; - if (c <= 0x7F) - n = 1; - else if (c <= 0x7FF) - n = 2; - else if (c <= 0xFFFF) - n = 3; - else if (c <= 0x10FFFF) - n = 4; - else - assert(0); - accumulate(file, line, funcname, "char[]", n * char.sizeof); - return _d_arrayappendcd(x, c); -} + auto type_string = typeof(Declaration).stringof; + auto name = __traits(identifier, Declaration); + auto param_idx = findParamIndex(type_string); -extern (C) void[] _d_arrayappendwdTrace(string file, int line, string funcname, ref byte[] x, dchar c) -{ - mixin(generatePrintf()); - size_t n = 1 + (c > 0xFFFF); - accumulate(file, line, funcname, "wchar[]", n * wchar.sizeof); - return _d_arrayappendwd(x, c); -} - -extern (C) void[] _d_arraysetlengthT(const TypeInfo ti, size_t newlength, void[]* p); -extern (C) void[] _d_arraysetlengthiT(const TypeInfo ti, size_t newlength, void[]* p); + auto new_declaration = type_string[0 .. param_idx] ~ " " ~ name + ~ "Trace(string file, int line, string funcname, " + ~ type_string[param_idx+1 .. $]; + auto call_original = " scope original_func = { return " + ~ __traits(identifier, Declaration) ~ "(" ~ Arguments!Declaration() ~ "); };"; -extern (C) void[] _d_arraysetlengthTTrace(string file, int line, string funcname, const TypeInfo ti, size_t newlength, void[]* p) -{ - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.next.tsize * newlength); - return _d_arraysetlengthT(ti, newlength, p); + return new_declaration ~ "\n{\n" ~ + call_original ~ "\n" ~ + accumulator ~ "\n" ~ + "}\n"; } -extern (C) void[] _d_arraysetlengthiTTrace(string file, int line, string funcname, const TypeInfo ti, size_t newlength, void[]* p) +string Arguments(alias Func)() { - mixin(generatePrintf()); - accumulate(file, line, funcname, ti.toString(), ti.next.tsize * newlength); - return _d_arraysetlengthiT(ti, newlength, p); -} + string result = ""; + static if (is(typeof(Func) PT == __parameters)) + { + foreach (idx, _; PT) + result ~= __traits(identifier, PT[idx .. idx + 1]) ~ ", "; + } -extern (C) void* _d_allocmemory(size_t sz); + return result; +} -extern (C) void* _d_allocmemoryTrace(string file, int line, string funcname, size_t sz) +unittest { - mixin(generatePrintf()); - accumulate(file, line, funcname, "closure", sz); - return _d_allocmemory(sz); + void foo(int x, double y) { } + static assert (Arguments!foo == "x, y, "); } - - diff --git a/test/profile/bothgc.log.exp b/test/profile/bothgc.log.exp index 6d389adbac..884f24c2a3 100644 --- a/test/profile/bothgc.log.exp +++ b/test/profile/bothgc.log.exp @@ -1,2 +1,2 @@ bytes allocated, allocations, type, function, file:line - 4000 1000 both.Num both.foo src/both.d:15 + 16000 1000 both.Num both.foo src/both.d:15 diff --git a/test/profile/myprofilegc.log.exp b/test/profile/myprofilegc.log.exp index f2337d8c54..9d36ec5424 100644 --- a/test/profile/myprofilegc.log.exp +++ b/test/profile/myprofilegc.log.exp @@ -1,2 +1,2 @@ bytes allocated, allocations, type, function, file:line - 4 1 uint D main src/profilegc.d:6 + 16 1 uint D main src/profilegc.d:6 From bde07926b0d001fc95a257b62982749f56c66367 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 12:42:59 +0200 Subject: [PATCH 06/10] Ensure consistent trace entry order Ordering by name as last measure means order of lines in the generate trace will be reproducible, allowing for easy test cases. --- src/rt/profilegc.d | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index e8e0bde969..49c68a6d9d 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -121,7 +121,8 @@ shared static ~this() long cmp = result2.entry.size - result1.entry.size; if (cmp) return cmp < 0 ? -1 : 1; cmp = result2.entry.count - result1.entry.count; - return cmp < 0 ? -1 : (cmp > 0 ? 1 : 0); + if (cmp) return cmp < 0 ? -1 : 1; + return result2.name < result1.name; } } From 59a53c47820cf4132c23524bf2b276c3aed593a4 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 12:44:48 +0200 Subject: [PATCH 07/10] Enhance -profile=gc test case Moves code snippet which refers to various language features that allocate to actual test to ensure better functionality coverage. --- src/rt/tracegc.d | 66 +------------------------------- test/profile/myprofilegc.log.exp | 17 +++++++- test/profile/src/profilegc.d | 58 +++++++++++++++++++++++++++- 3 files changed, 75 insertions(+), 66 deletions(-) diff --git a/src/rt/tracegc.d b/src/rt/tracegc.d index 9cabf2fdcc..65fe679302 100644 --- a/src/rt/tracegc.d +++ b/src/rt/tracegc.d @@ -3,6 +3,8 @@ * -profile=gc * switch is thrown. * + * Tests for this functionality can be found in test/profile/src/profilegc.d + * * Copyright: Copyright Digital Mars 2015 - 2015. * License: Distributed under the * $(LINK2 http://www.boost.org/LICENSE_1_0.txt, Boost Software License 1.0). @@ -15,70 +17,6 @@ module rt.tracegc; // version = tracegc; -version (none) -{ - // this exercises each function - - struct S { ~this() { } } - class C { } - interface I { } - - void main() - { - { - auto a = new C(); - auto b = new int; - auto c = new int[3]; - auto d = new int[][](3,4); - auto e = new float; - auto f = new float[3]; - auto g = new float[][](3,4); - } - printf("\n"); - { - int[] a; delete a; - S[] as; delete as; - C c; delete c; - I i; delete i; - C* pc = &c; delete *pc; - I* pi = &i; delete *pi; - int* pint; delete pint; - S* ps; delete ps; - } - printf("\n"); - { - int[] a = [1, 2, 3]; - string[int] aa = [1:"one", 2:"two", 3:"three"]; - } - printf("\n"); - { - int[] a, b, c; - c = a ~ b; - c = a ~ b ~ c; - } - printf("\n"); - { - dchar dc = 'a'; - char[] ac; ac ~= dc; - wchar[] aw; aw ~= dc; - char[] ac2; ac2 ~= ac; - int[] ai; ai ~= 3; - } - printf("\n"); - { - int[] ai; ai.length = 10; - float[] af; af.length = 10; - } - printf("\n"); - int v; - { - int foo() { return v; } - static int delegate() dg; - dg = &foo; // dynamic closure - } - } -} - extern (C) Object _d_newclass(const ClassInfo ci); extern (C) void[] _d_newarrayT(const TypeInfo ti, size_t length); extern (C) void[] _d_newarrayiT(const TypeInfo ti, size_t length); diff --git a/test/profile/myprofilegc.log.exp b/test/profile/myprofilegc.log.exp index 9d36ec5424..f356148e15 100644 --- a/test/profile/myprofilegc.log.exp +++ b/test/profile/myprofilegc.log.exp @@ -1,2 +1,17 @@ bytes allocated, allocations, type, function, file:line - 16 1 uint D main src/profilegc.d:6 + 288 1 immutable(char)[][int] D main src/profilegc.d:34 + 160 1 float[][] D main src/profilegc.d:18 + 160 1 int[][] D main src/profilegc.d:15 + 64 1 float[] D main src/profilegc.d:53 + 64 1 int[] D main src/profilegc.d:52 + 32 1 profilegc.main.C D main src/profilegc.d:12 + 16 1 char[] D main src/profilegc.d:45 + 16 1 char[] D main src/profilegc.d:47 + 16 1 closure profilegc.main.foo src/profilegc.d:56 + 16 1 float D main src/profilegc.d:16 + 16 1 float[] D main src/profilegc.d:17 + 16 1 int D main src/profilegc.d:13 + 16 1 int[] D main src/profilegc.d:14 + 16 1 int[] D main src/profilegc.d:33 + 16 1 int[] D main src/profilegc.d:48 + 16 1 wchar[] D main src/profilegc.d:46 diff --git a/test/profile/src/profilegc.d b/test/profile/src/profilegc.d index 25e76fbe68..686dc9a162 100644 --- a/test/profile/src/profilegc.d +++ b/test/profile/src/profilegc.d @@ -3,5 +3,61 @@ import core.runtime; void main(string[] args) { profilegc_setlogfilename(args[1]); - auto p = new uint; + + struct S { ~this() { } } + class C { } + interface I { } + + { + auto a = new C(); + auto b = new int; + auto c = new int[3]; + auto d = new int[][](3,4); + auto e = new float; + auto f = new float[3]; + auto g = new float[][](3,4); + } + + { + int[] a; delete a; + S[] as; delete as; + C c; delete c; + I i; delete i; + C* pc = &c; delete *pc; + I* pi = &i; delete *pi; + int* pint; delete pint; + S* ps; delete ps; + } + + { + int[] a = [1, 2, 3]; + string[int] aa = [1:"one", 2:"two", 3:"three"]; + } + + { + int[] a, b, c; + c = a ~ b; + c = a ~ b ~ c; + } + + { + dchar dc = 'a'; + char[] ac; ac ~= dc; + wchar[] aw; aw ~= dc; + char[] ac2; ac2 ~= ac; + int[] ai; ai ~= 3; + } + + { + int[] ai; ai.length = 10; + float[] af; af.length = 10; + } + + auto foo ( ) + { + int v = 42; + return { return v; }; + } + + auto x = foo()(); } From f85c720a126881f4cad43fc20317e0bd4807f11e Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 12:51:38 +0200 Subject: [PATCH 08/10] Synchronize -profile=gc trace calls on single lock After switching to `GC.stats` implementation of calculating allocated amount, it has become necessary to ensure that no other thread affects those stats in between two calculations points. Fixes issue https://issues.dlang.org/show_bug.cgi?id=17294 Fixes issue https://issues.dlang.org/show_bug.cgi?id=16280 Fixes issue https://issues.dlang.org/show_bug.cgi?id=15481 --- src/rt/profilegc.d | 7 ++++++- src/rt/tracegc.d | 36 ++++++++++++++++++-------------- test/profile/myprofilegc.log.exp | 5 ++++- test/profile/src/profilegc.d | 27 ++++++++++++++++++++---- 4 files changed, 53 insertions(+), 22 deletions(-) diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index 49c68a6d9d..2a73ba842b 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -30,6 +30,11 @@ __gshared { Entry[string] globalNewCounts; string logfilename = "profilegc.log"; + + // used to synchronize trace calls caused by allocations from multiple threads, + // not doing so would interfere with checking `GC.stats` as those are reported + // in global manner. + Object traceLock = new Object; } /**** @@ -88,7 +93,7 @@ static ~this() { if (newCounts.length) { - synchronized + synchronized(traceLock) { foreach (name, entry; newCounts) { diff --git a/src/rt/tracegc.d b/src/rt/tracegc.d index 65fe679302..23b9296d3b 100644 --- a/src/rt/tracegc.d +++ b/src/rt/tracegc.d @@ -50,7 +50,7 @@ extern (C) void* _d_allocmemory(size_t sz); // Placed here as a separate string constant to simplify maintenance as it is // much more likely to be modified than rest of generation code. enum accumulator = q{ - import rt.profilegc : accumulate; + import rt.profilegc : accumulate, traceLock; import core.memory : GC; static if (is(typeof(ci))) @@ -79,25 +79,29 @@ enum accumulator = q{ ); } - auto stats1 = GC.stats(); - scope(exit) + synchronized (traceLock) { - auto stats2 = GC.stats(); - if (stats2.totalCollected < stats1.totalCollected) + auto stats1 = GC.stats(); + scope(exit) { - // need to account for unsigned overflow possibility if app is being - // run very long - stats2.totalCollected += typeof(stats1.totalCollected).max - - stats1.totalCollected; - stats1.totalCollected = 0; + auto stats2 = GC.stats(); + if (stats2.totalCollected < stats1.totalCollected) + { + // need to account for unsigned overflow possibility if app is being + // run very long + stats2.totalCollected += typeof(stats1.totalCollected).max + - stats1.totalCollected; + stats1.totalCollected = 0; + } + + ulong size = (stats2.usedSize + stats2.totalCollected) - + (stats1.usedSize + stats1.totalCollected); + if (size > 0) + accumulate(file, line, funcname, name, size); } - ulong size = (stats2.usedSize + stats2.totalCollected) - - (stats1.usedSize + stats1.totalCollected); - if (size > 0) - accumulate(file, line, funcname, name, size); - } - return original_func(); + return original_func(); + } }; mixin(generateTraceWrappers()); diff --git a/test/profile/myprofilegc.log.exp b/test/profile/myprofilegc.log.exp index f356148e15..d37028b3d0 100644 --- a/test/profile/myprofilegc.log.exp +++ b/test/profile/myprofilegc.log.exp @@ -1,5 +1,8 @@ bytes allocated, allocations, type, function, file:line + 2560 10 core.thread.Thread D main src/profilegc.d:77 + 640 10 int[] profilegc.main.bar src/profilegc.d:73 288 1 immutable(char)[][int] D main src/profilegc.d:34 + 240 4 core.thread.Thread[] D main src/profilegc.d:77 160 1 float[][] D main src/profilegc.d:18 160 1 int[][] D main src/profilegc.d:15 64 1 float[] D main src/profilegc.d:53 @@ -7,7 +10,7 @@ bytes allocated, allocations, type, function, file:line 32 1 profilegc.main.C D main src/profilegc.d:12 16 1 char[] D main src/profilegc.d:45 16 1 char[] D main src/profilegc.d:47 - 16 1 closure profilegc.main.foo src/profilegc.d:56 + 16 1 closure profilegc.main.foo src/profilegc.d:57 16 1 float D main src/profilegc.d:16 16 1 float[] D main src/profilegc.d:17 16 1 int D main src/profilegc.d:13 diff --git a/test/profile/src/profilegc.d b/test/profile/src/profilegc.d index 686dc9a162..22a9676db2 100644 --- a/test/profile/src/profilegc.d +++ b/test/profile/src/profilegc.d @@ -53,11 +53,30 @@ void main(string[] args) float[] af; af.length = 10; } - auto foo ( ) { - int v = 42; - return { return v; }; + auto foo ( ) + { + int v = 42; + return { return v; }; + } + + auto x = foo()(); } - auto x = foo()(); + { + import core.thread; + + Thread[] arr; + + void bar ( ) + { + auto x = new int[10]; + } + + for (int i = 0; i < 10; ++i) + arr ~= new Thread(&bar, 1024).start(); + + foreach (t; arr) + t.join(); + } } From dd28709ad2d85f3ff4b240fab3266e2f22cce26d Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 13:29:55 +0200 Subject: [PATCH 09/10] Order -profile=gc entries by total size first It is more useful than plain size or plain count --- src/rt/profilegc.d | 6 +++++- test/profile/myprofilegc.log.exp | 2 +- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index 2a73ba842b..895076e901 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -123,7 +123,11 @@ shared static ~this() { auto result1 = cast(Result*)r1; auto result2 = cast(Result*)r2; - long cmp = result2.entry.size - result1.entry.size; + auto totalSize1 = result1.entry.size * result1.entry.count; + auto totalSize2 = result2.entry.size * result2.entry.count; + long cmp = totalSize2 - totalSize1; + if (cmp) return cmp < 0 ? -1 : 1; + cmp = result2.entry.size - result1.entry.size; if (cmp) return cmp < 0 ? -1 : 1; cmp = result2.entry.count - result1.entry.count; if (cmp) return cmp < 0 ? -1 : 1; diff --git a/test/profile/myprofilegc.log.exp b/test/profile/myprofilegc.log.exp index d37028b3d0..34fb40aa61 100644 --- a/test/profile/myprofilegc.log.exp +++ b/test/profile/myprofilegc.log.exp @@ -1,8 +1,8 @@ bytes allocated, allocations, type, function, file:line 2560 10 core.thread.Thread D main src/profilegc.d:77 640 10 int[] profilegc.main.bar src/profilegc.d:73 - 288 1 immutable(char)[][int] D main src/profilegc.d:34 240 4 core.thread.Thread[] D main src/profilegc.d:77 + 288 1 immutable(char)[][int] D main src/profilegc.d:34 160 1 float[][] D main src/profilegc.d:18 160 1 int[][] D main src/profilegc.d:15 64 1 float[] D main src/profilegc.d:53 From 8d16e58ddf5507cae7706c454f44357aa768b677 Mon Sep 17 00:00:00 2001 From: Mihails Strasuns Date: Mon, 10 Apr 2017 17:48:07 +0200 Subject: [PATCH 10/10] PoC: try using single mutex in both profiler and gc --- src/gc/gcinterface.d | 5 +++++ src/gc/impl/conservative/gc.d | 26 ++++++++++++++++++++++ src/gc/impl/manual/gc.d | 10 +++++++++ src/rt/profilegc.d | 27 ++++++++++++----------- src/rt/tracegc.d | 41 +++++++++++++++++++---------------- 5 files changed, 77 insertions(+), 32 deletions(-) diff --git a/src/gc/gcinterface.d b/src/gc/gcinterface.d index abe88f1c82..ad9449e1fe 100644 --- a/src/gc/gcinterface.d +++ b/src/gc/gcinterface.d @@ -17,6 +17,8 @@ static import core.memory; alias BlkAttr = core.memory.GC.BlkAttr; alias BlkInfo = core.memory.GC.BlkInfo; +static import core.sync.mutex; + alias RootIterator = int delegate(scope int delegate(ref Root) nothrow dg); alias RangeIterator = int delegate(scope int delegate(ref Range) nothrow dg); @@ -187,4 +189,7 @@ interface GC * */ bool inFinalizer() nothrow; + + void enableProfiling() nothrow @nogc; + shared(core.sync.mutex.Mutex) profilerLock() nothrow @nogc; } diff --git a/src/gc/impl/conservative/gc.d b/src/gc/impl/conservative/gc.d index 08ff730135..bffbf76e38 100644 --- a/src/gc/impl/conservative/gc.d +++ b/src/gc/impl/conservative/gc.d @@ -49,6 +49,7 @@ import cstdlib = core.stdc.stdlib : calloc, free, malloc, realloc; import core.stdc.string : memcpy, memset, memmove; import core.bitop; import core.thread; +import core.sync.mutex; static import core.memory; version (GNU) import gcc.builtins; @@ -252,6 +253,10 @@ debug (LOGGING) class ConservativeGC : GC { + bool profiling_enabled; + shared Mutex profiler_lock; + shared void[__traits(classInstanceSize, Mutex)] profiler_lock_bytes; + // For passing to debug code (not thread safe) __gshared size_t line; __gshared char* file; @@ -316,6 +321,10 @@ class ConservativeGC : GC gcx.reserve(config.initReserve << 20); if (config.disable) gcx.disabled++; + + this.profiler_lock_bytes[0..$] = typeid(Mutex).initializer[]; + this.profiler_lock = cast(shared(Mutex)) this.profiler_lock_bytes.ptr; + this.profiler_lock.__ctor(); } @@ -359,6 +368,13 @@ class ConservativeGC : GC auto runLocked(alias func, Args...)(auto ref Args args) { + if (this.profiling_enabled) + { + this.profiler_lock.lock_nothrow(); + scope(exit) + this.profiler_lock.unlock_nothrow(); + } + debug(PROFILE_API) immutable tm = (config.profile > 1 ? currTime.ticks : 0); lockNR(); scope (failure) gcLock.unlock(); @@ -1230,6 +1246,16 @@ class ConservativeGC : GC stats.freeSize += freeListSize; stats.totalCollected = .totalCollectedPages * PAGESIZE; } + + void enableProfiling() nothrow @nogc + { + this.profiling_enabled = true; + } + + shared(Mutex) profilerLock() nothrow @nogc + { + return this.profiler_lock; + } } diff --git a/src/gc/impl/manual/gc.d b/src/gc/impl/manual/gc.d index 84712d410d..a768cd4ce7 100644 --- a/src/gc/impl/manual/gc.d +++ b/src/gc/impl/manual/gc.d @@ -31,6 +31,7 @@ import gc.gcinterface; import rt.util.container.array; import cstdlib = core.stdc.stdlib : calloc, free, malloc, realloc; +import core.sync.mutex; static import core.memory; extern (C) void onOutOfMemoryError(void* pretend_sideffect = null) @trusted pure nothrow @nogc; /* dmd @@@BUG11461@@@ */ @@ -271,4 +272,13 @@ class ManualGC : GC { return false; } + + void enableProfiling() nothrow @nogc + { + } + + shared(Mutex) profilerLock() nothrow @nogc + { + return null; + } } diff --git a/src/rt/profilegc.d b/src/rt/profilegc.d index 895076e901..f0a1d46949 100644 --- a/src/rt/profilegc.d +++ b/src/rt/profilegc.d @@ -30,11 +30,6 @@ __gshared { Entry[string] globalNewCounts; string logfilename = "profilegc.log"; - - // used to synchronize trace calls caused by allocations from multiple threads, - // not doing so would interfere with checking `GC.stats` as those are reported - // in global manner. - Object traceLock = new Object; } /**** @@ -46,6 +41,8 @@ __gshared extern (C) void profilegc_setlogfilename(string name) { + import gc.proxy : gc_getProxy; + gc_getProxy().enableProfiling(); logfilename = name; } @@ -91,19 +88,23 @@ public void accumulate(string file, uint line, string funcname, string type, // Merge thread local newCounts into globalNewCounts static ~this() { + import gc.proxy : gc_getProxy; + auto mtx = gc_getProxy().profilerLock(); + if (newCounts.length) { - synchronized(traceLock) + mtx.lock(); + scope(exit) mtx.unlock(); + + foreach (name, entry; newCounts) { - foreach (name, entry; newCounts) - { - if (!(name in globalNewCounts)) - globalNewCounts[name] = Entry.init; + if (!(name in globalNewCounts)) + globalNewCounts[name] = Entry.init; - globalNewCounts[name].count += entry.count; - globalNewCounts[name].size += entry.size; - } + globalNewCounts[name].count += entry.count; + globalNewCounts[name].size += entry.size; } + newCounts = null; } free(buffer.ptr); diff --git a/src/rt/tracegc.d b/src/rt/tracegc.d index 23b9296d3b..49fb4c1d1f 100644 --- a/src/rt/tracegc.d +++ b/src/rt/tracegc.d @@ -50,7 +50,7 @@ extern (C) void* _d_allocmemory(size_t sz); // Placed here as a separate string constant to simplify maintenance as it is // much more likely to be modified than rest of generation code. enum accumulator = q{ - import rt.profilegc : accumulate, traceLock; + import rt.profilegc : accumulate; import core.memory : GC; static if (is(typeof(ci))) @@ -79,29 +79,32 @@ enum accumulator = q{ ); } - synchronized (traceLock) + import gc.proxy : gc_getProxy; + auto mtx = gc_getProxy().profilerLock(); + + mtx.lock(); + scope(exit) mtx.unlock(); + + auto stats1 = GC.stats(); + scope(exit) { - auto stats1 = GC.stats(); - scope(exit) + auto stats2 = GC.stats(); + if (stats2.totalCollected < stats1.totalCollected) { - auto stats2 = GC.stats(); - if (stats2.totalCollected < stats1.totalCollected) - { - // need to account for unsigned overflow possibility if app is being - // run very long - stats2.totalCollected += typeof(stats1.totalCollected).max - - stats1.totalCollected; - stats1.totalCollected = 0; - } - - ulong size = (stats2.usedSize + stats2.totalCollected) - - (stats1.usedSize + stats1.totalCollected); - if (size > 0) - accumulate(file, line, funcname, name, size); + // need to account for unsigned overflow possibility if app is being + // run very long + stats2.totalCollected += typeof(stats1.totalCollected).max + - stats1.totalCollected; + stats1.totalCollected = 0; } - return original_func(); + ulong size = (stats2.usedSize + stats2.totalCollected) - + (stats1.usedSize + stats1.totalCollected); + if (size > 0) + accumulate(file, line, funcname, name, size); } + + return original_func(); }; mixin(generateTraceWrappers());