digitalmars.D - Where is the profile-gc instrumentation inserted
- Teodor Dutu (56/56) Nov 28 2022 Hi,
- max haughton (57/117) Nov 28 2022 Two ways of testing your assumption:
Hi, I have recently finished [translating `_d_arraycatnTX()` to a template](https://github.com/dlang/dmd/pull/14550). While cleaning up the code, I was unable to figure out why `profile-gc` also shows the new template hook in addition to its former output. This behaviour is consistent on all `profile-gc` tests in DRuntime. One example is [this one](https://github.com/dlang/dmd/blob/4db85299eba70416c2f508568aec76e430fcb575/druntime/test/profile/myprofileg .log.linux.64.exp), which I had to modify by adding the line with `_d_arraycatnTX()`: ```text bytes allocated, allocations, type, function, file:line 560 3 int[] core.internal.array.concatenation._d_arraycatnTX!(int[], string, int, string, int[], int[])._d_arraycatnTX ../../src/core/internal/array/concatenation.d:42 464 1 immutable(char)[][int] D main src/profilegc.d:23 160 1 float[][] D main src/profilegc.d:18 160 1 int[][] D main src/profilegc.d:15 64 1 double[] profilegc.main src/profilegc.d:56 48 1 float[] D main src/profilegc.d:42 48 1 int[] D main src/profilegc.d:41 32 1 profilegc.main.C D main src/profilegc.d:12 32 1 void[] profilegc.main src/profilegc.d:55 16 1 char[] D main src/profilegc.d:34 16 1 char[] D main src/profilegc.d:36 16 1 closure profilegc.main.foo src/profilegc.d:45 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:22 16 1 int[] D main src/profilegc.d:37 16 1 wchar[] D main src/profilegc.d:35 ``` My assumption is that the GC's profiling instrumentation is introduced in the semantic phase, before the new lowering, thus also taking the `_d_arraycatnTX` hook into account. If this is true, then the old lowering was not profiled because it took place in the glue layer, after the instrumentation had been introduced. Regarding this, I have 3 questions that I don't know how to answer: 1. Is my assumption above correct? 1. Are those 560 bytes an issue that means the new lowering over-allocates 560 bytes? The value is the same regardless of platform and OS. 1. Is it OK for the output to contain an "internal" function, such as a runtime hook? What do you think? Thanks, Teo
Nov 28 2022
max haughton <maxhaton gmail.com> On Monday, 28 November 2022 at 23:00:31 UTC, Teodor Dutu wrote:Hi, I have recently finished [translating `_d_arraycatnTX()` to a template](https://github.com/dlang/dmd/pull/14550). While cleaning up the code, I was unable to figure out why `profile-gc` also shows the new template hook in addition to its former output. This behaviour is consistent on all `profile-gc` tests in DRuntime. One example is [this one](https://github.com/dlang/dmd/blob/4db85299eba70416c2f508568aec76e430fcb575/druntime/test/profile/myprofileg .log.linux.64.exp), which I had to modify by adding the line with `_d_arraycatnTX()`: ```text bytes allocated, allocations, type, function, file:line 560 3 int[] core.internal.array.concatenation._d_arraycatnTX!(int[], string, int, string, int[], int[])._d_arraycatnTX ../../src/core/internal/array/concatenation.d:42 464 1 immutable(char)[][int] D main src/profilegc.d:23 160 1 float[][] D main src/profilegc.d:18 160 1 int[][] D main src/profilegc.d:15 64 1 double[] profilegc.main src/profilegc.d:56 48 1 float[] D main src/profilegc.d:42 48 1 int[] D main src/profilegc.d:41 32 1 profilegc.main.C D main src/profilegc.d:12 32 1 void[] profilegc.main src/profilegc.d:55 16 1 char[] D main src/profilegc.d:34 16 1 char[] D main src/profilegc.d:36 16 1 closure profilegc.main.foo src/profilegc.d:45 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:22 16 1 int[] D main src/profilegc.d:37 16 1 wchar[] D main src/profilegc.d:35 ``` My assumption is that the GC's profiling instrumentation is introduced in the semantic phase, before the new lowering, thus also taking the `_d_arraycatnTX` hook into account. If this is true, then the old lowering was not profiled because it took place in the glue layer, after the instrumentation had been introduced. Regarding this, I have 3 questions that I don't know how to answer: 1. Is my assumption above correct? 1. Are those 560 bytes an issue that means the new lowering over-allocates 560 bytes? The value is the same regardless of platform and OS. 1. Is it OK for the output to contain an "internal" function, such as a runtime hook? What do you think? Thanks, TeoTwo ways of testing your assumption: 0: The hidden step - locate params.tracegc as the flag for enabling tracing. 1. grep for `tracegc` in the code. This reveals that the answer is that some lowering is done in semantic but the nitty gritty is performed in the code underneath the frontend - a hint that this is the case is that profile=gc does not exist on ldc and I assume gdc too. More specifically take a look at: ```d /****************************************************** * Replace call to GC allocator with call to tracing GC allocator. * Params: * irs = to get function from * e = elem to modify in place * loc = to get file/line from */ void toTraceGC(IRState *irs, elem *e, const ref Loc loc) { ``` 2. The more fun way: Delete `tracegc` entirely and see what breaks If we do: ```diff bool obj = true; // write object file bool multiobj; // break one object file into multiple ones bool trace; // insert profiling hooks - bool tracegc; // instrument calls to 'new' + // bool tracegc; // instrument calls to 'new' bool verbose; // verbose compile bool vcg_ast; // write-out codegen-ast bool showColumns; // print character (column) numbers in diagnostics ``` then what explodes? ``` src/dmd/expressionsem.d(9619): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/expressionsem.d(9648): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/expressionsem.d(10395): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/expressionsem.d(10407): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/expressionsem.d(10437): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/expressionsem.d(10451): Error: no property `tracegc` for type `Param`, did you mean `dmd.globals.Param.trace`? src/dmd/e2ir.d(352): Error: no property `tracegc` for type `const(dmd.globals.Param*)` ``` and there we have our list of places to start looking. As for one of the other questions: Internal functions should be printed. When in doubt assume the users have a reason to want the info.
Nov 28 2022