Where is the profile-gc instrumentation inserted

[max haughton]

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/myprofilegc.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

Two 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.