Callstack in last call within method with generic function name only

[CCRDude]

TL;DR: I've got a "debug logger" that I'm extending to help as a sort of profiler. I'm doing one call at the begin and one at the end of a method using the callstack. At the end of methods, the callstacks returns a more generic function name.

What I want to do is, and I prefer this one to the two below because of
* readability
* performance (without the compiler directive to enable profiling, these lines call simple inline procedures without active code inside)
* ease of maybe automatically adding code

Code: Pascal  [Select][+][-]

1. function TTestClass.DoSomeThing(var AText: string): integer;
2. begin
3.    StartProfiling(Self, [AText]);
4.    try
5.       Result := Length(AText);
6.    finally
7.       EndProfiling([Result]);
8.    end;
9. end;
10.  

I currently use the callstack (get_caller_stackinfo and GetLineInfo) to determine the method name. But during EndProfiling, those return $fin$0000002A instead.

If that would work during EndProfiling, I would use a TDictionary to simply locate the TFireflyProfilerMethod that was used to start the call (with some ugly stuff dealing with recursive calls probably).

My current workaround:

Code: Pascal  [Select][+][-]

1. function TTestClass.DoSomeThing(var AText: string): integer;
2. var
3.    profiling: TFireflyProfilerMethod;
4. begin
5.    profiling := StartProfiling(Self, [AText]);
6.    try
7.       Result := Length(AText);
8.    finally
9.       EndProfiling(profiling, [Result]);
10.      // or profiling.EndProfiling([Result]);
11.    end;
12. end;
13.  

or

Code: Pascal  [Select][+][-]

1. function TTestClass.DoSomeThing(var AText: string): integer;
2. begin
3.    with StartProfiling(Self, [AText]) do
4.    try
5.       Result := Length(AText);
6.    finally
7.       EndProfiling([Result]);
8.    end;
9. end;
10.  

Here's the code I use to locate the code position:

Code: Pascal  [Select][+][-]

1.  
2. {
3.    Used to find the calling function that called this units code,
4.    e.g. the one that uses the profiler.
5.  
6.    @param(AFunction will receive the calling function name.)
7.    @param(ASource will receive the name of the unit calling.)
8.    @param(ALine will receive the line of code where the profiler was triggered.)
9.  
10.    @author(Patrick Kolla-ten Venne)
11. }
12. procedure LocateCallingPosition(out AFunction, ASource: string; out ALine: longint); overload;
13. var
14.    sFunction: shortstring = '';
15.    sSource: shortstring = '';
16.    sThisSource: shortstring = '';
17.    iLine: longint = 0;
18.    pCurrentFrame: Pointer;
19.    pCurrentAddress: CodePointer;
20. begin
21.    // current address is inside this unit.
22.    pCurrentFrame := get_frame;
23.    pCurrentAddress := get_pc_addr;
24.    // get the parent, which is inside this unit...
25.    get_caller_stackinfo(pCurrentFrame, pCurrentAddress);
26.    GetLineInfo(PtrUInt(pCurrentAddress), sFunction, sThisSource, iLine);
27.    // go up in hierarchy until first code line outside of this unit is found.
28.    repeat
29.       get_caller_stackinfo(pCurrentFrame, pCurrentAddress);
30.       GetLineInfo(PtrUInt(pCurrentAddress), sFunction, sSource, iLine);
31.       // In last lines of calling method, this returns:
32.       // sFunction @$0179FA29 = '$fin$0000002A'
33.    until (sSource <> sThisSource);
34.    AFunction := sFunction;
35.    ASource := sSource;
36.    ALine := iLine;
37. end;  
38.  

Here I'm a bit confused, since the debugger of Lazarus shows me a correct callstack, and I picked up the GetLineInfo hint from looking into Dump_Stack and what it uses back to the Dwarf implementation of the display of callstack information.

[Martin_fr]

First of all, for profiling, I suggest to write addresses only, and then have a tool that runs the data, and resolves the addresses.
This may be a good bit faster than doing them during the run.

Here I'm a bit confused, since the debugger of Lazarus shows me a correct callstack, and I picked up the GetLineInfo hint from looking into Dump_Stack and what it uses back to the Dwarf implementation of the display of callstack information.

The finally (SEH) runs in a function of it's own, hence the name....

But in order to behave like it was the same function as the "try" block is in, the finally uses the "RBP" (base pointer used as  stackframe) of the actual function.

Since the RBP is used to find the parent frame, the $fin looks like it has been called by the function that called the "pascal function containing it". So it hides all other callers. In reality it is either called by the OS (some unwind code) or by the "pascal function containing it".

The debug info does not have any link....

--------------
FpDebug does a bit of a trick here.

- The finally must have line numbers in the range of the "pascal function containing it"
- FpDebug finds the first line number of the finally (that may not be on the first address, which could be "begin" being mapped to the "end" line)e
- It then looks up the address of the line right before that (not sure there may be more than one)
- And that address can be used to find the "pascal function containing it"

If that is an other "finally" then recurse.


Mind, you can probably screw that up, if you put to much code on one line....
Not tested with anonymous functions....

------------------
It may be possible to get some info by parsing SEH records... But that is on the TODO list... So no info on it.


Because it has the same "RBP" (base pointer / stackframe)...

In your StartProfiling you could get the frame of the caller (of the function for which you log).
You could store that in a look up list
And in the finally you got look it up.

Of course that may be time consuming