Get Unit Name from InitTable - hack System.pas

Question

For debugging our slow-starting Delphi XE3 application, we would like to log the initialization-phase of all used units in our system.

To complete this task, we need the Unit Name for each initialization call.

Analyzing the Data, when stepping through InitNames, we find the first Unit Name inside:

InitContext.InitTable^.TypeInfo.UnitNames

but we do not know how to fetch the appropriate Name from the Unit ID I before calling the Initialization procedure. Code Documentation says, TypeInfo.UnitNames contains the concatenated Unit Names of all Units.. But how do i travel between them? It is not an array nor a long string with seperators.

The code, where i would like to insert the log routine.

procedure InitUnits;
var
  Count, I: Integer;
  Table: PUnitEntryTable;
  P: Pointer;
begin
  if InitContext.InitTable = nil then
    exit;
  Count := InitContext.InitTable^.UnitCount;
  I := 0;
  Table := InitContext.InitTable^.UnitInfo;
{$IFDEF LINUX}
  Inc(PByte(Table), InitContext.Module^.GOT);
{$ENDIF}
  try
    while I < Count do
    begin

      /////////////////////////////////////
      MyLogCode( 'Unit: ' + Get UnitName here )  
      /////////////////////////////////////

      P := Table^[I].Init;
      Inc(I);
      InitContext.InitCount := I;
      if Assigned(P) and Assigned(Pointer(P^)) then
  begin
{$IF defined(MSWINDOWS)}
    TProc(P)();
{$ELSEIF (defined(POSIX) and defined(CPUX86))}
        CallProc(P, InitContext.Module^.GOT);
{$ELSE}
        TProc(P)();
{$ENDIF}
      end;
    end;
  except
    FinalizeUnits;
    raise;
  end;
end;

Recompiling the System.pas will be done via Arnaud Bouchez suggested solution.

Are you quite sure that you wish to do this? You really wish to modify System.pas? — David Heffernan, Apr 11 '14 at 10:03
I know it may become a bit tedious with tons of units, but using CodeSite (the contained Express Edition will do) with EnterMethod/ExitMethod looks straight forward and much less intrusive to me. — Uwe Raabe, Apr 11 '14 at 10:29
I would suggest using a profiler to find the bottleneck in your application which does not involve changing any code. I just used the NQS LineTimer and it shows that I have some long running code in my initialization part of some unit (I just simply counted to MaxInt). — Stefan Glienke, Apr 11 '14 at 11:05
I wrote for our application a simple thread sensitive logger which i am already using throughout the app and would also like to use for this. It has a nice visual representation of runtime and call times as a graphical time line. The downside is, i need to insert the log code manualy. I will look into your suggested applications. Thanks. — Hugie, Apr 11 '14 at 11:46
I would love to have a thread-sensitive logger which visualizes the logs like a thread-profiler of a game engine. For example: [ImageOfProfilerVis](http://zaynar.co.uk/0ad-pub/profiler1.png) — Hugie, Apr 11 '14 at 12:22

David Heffernan · Accepted Answer · 2014-04-11T12:41:19.850

3

UnitNames contains multiple unit names. They are Pascal short strings, concatenated. However, as we shall see, they are not the names that you need.

Break in the debugger in InitUnits and evaluate:

PAnsiChar(InitContext.InitTable.TypeInfo.UnitNames)

In my simple test project, a console app that just uses SysUtils, you see the following:

#$F'System.SysUtils'#6'System'#$18'System.Internal.ExcUtils'#$F'System.SysConst'
#7'SysInit'#$10'System.Character'#$E'Winapi.Windows'#$E'System.UITypes'
#$C'System.Types'#$10'System.RTLConsts'#$C'Winapi.PsAPI'#$F'Winapi.SHFolder'
#$F'Winapi.ImageHlp‹À'

The first character is the length of the string. They are concatenates one after the other, with a total of InitContext.InitTable.TypeInfo.UnitCount names. For my simple project InitContext.InitTable.TypeInfo.UnitCount evaluates to 13.

However, these names do not correspond to the units that are initialised. In my test project InitContext.InitTable^.UnitCount has value 18, and the units are initialized in a quite different order from that listed above. As I'm sure you know, SysInit always comes first. As you can see from the above, it is in the middle of the list. So, whilst InitContext.InitTable.TypeInfo.UnitNames gives you a list of certain units, it bears no relation to the units that require initialization, nor the order of initialization.

So as I read it, UnitNames cannot help you here. My belief is that you will need to use the detailed map file to decode this. You need to look up the name of the function Table^[I].Init. If you were using, for instance, madExcept, that would be easy to do.

Of course, you might not be able to perform the lookup inside InitUnits. You are faced with a chicken and egg situation. You may need for at least some units to be initialized before you get started with your logging.

For instance, it looks like you are attempting to allocate a string variable. That will fail because the RTL heap allocator has not been initialized. Your logging code cannot perform any dynamic allocation using the RTL heap if you expect to call it before the RTL has been initialized.

This does all seem over the top to me. If I were you I would:

Identify the units by index when logging. That is log the value of I.
Use the results of your profiling to work out which indexes are the problematic ones.
Under the debugger, use a conditional break point to break at the call to TProc(P)() associated with the index you identified in the previous step.
Step into P to find out which unit it is attached to.

edited Apr 11 '14 at 12:41

answered Apr 11 '14 at 09:54

David Heffernan

601,492
42
1,072
1,490

Yes, we use madExcept, i forgot about it. I will give it a try with storing the pointer and mapping it later while starting our analyzer form. Your final solution is what i also thought of but can not be used on a non-dev machine on a live environment, for instance a customer pc. – Hugie Apr 11 '14 at 12:02
The init order will be the same on customer machine as dev machine. If you know which index identifies the unit then you have what you need. – David Heffernan Apr 11 '14 at 12:03
You are right. But to avoid to manualy identify the most important IDs for every build or after bigger code changes, i would prefer a automatic solution like madExcept. – Hugie Apr 11 '14 at 12:08
Perhaps a bigger problem for you is that you must avoid RTL heap allocations until the RTL has been initialized. Do you understand that issue? – David Heffernan Apr 11 '14 at 12:42
Do you have some links to dig deeper into that? I know the difference between stack&heap and (afaik) that Delphi or FastMM4 manages the heap allocation to speed up the process. What you try to tell me is: If Fastmm4 ist not initialized and does not know about my prior Heap Allocation, i will run into problems like MemoryLeaks or Memory Allocation Overlaps? – Hugie Apr 11 '14 at 14:11
@Hugie Well there is no official documentation that tells you how to hack the RTL. But you can work it out by looking at the source. In the init proc for the System unit you find a call to `InitializeMemoryManager`. Before that call is made then the RTL heap is not available for use. And the code in your question which performs string concat happens before `InitializeMemoryManager` is called. What's more, if you replace the memory manager with another (e.g. full FastMM), then you need to take care to free off the same heap that you allocated on. – David Heffernan Apr 11 '14 at 14:45
You will find that it's a little way into the initialization of the RTL before the first RTL heap memory is allocated. By my reckoning three units are initialized before the RTL heap is used. And I would be astounded if your logging class did not perform RTL heap allocation. So that call to `MyLogCode` is going to bomb. – David Heffernan Apr 11 '14 at 14:46
That makes sense. Ok, my current theoretical "hack" would be to introduce a new "pre-Inititialization" callback function. That function, if assigned, will be fired before initialization and be given the ID and the pointer of the Initialization function as parameter. So, in the initialization of my first project unit, i will set this callback function. At that point, the critical units should be initialized and the slow-down units should'nt be. By that, i have the feedback of a new Initialization call, have the necessary data for the later madExcept questions and do not provoke heap errors. – Hugie Apr 11 '14 at 15:13

score 0 · Answer 2 · answered Jan 01 '16 at 23:21

In general it is best to NOT rely on the order of class constructors, initialization sections, class destructors, and finalization sections.

In a large (1.2M LOC) project one will not be able to deduce which is the order that Delphi will use.

It is best to refactor your code to avoid such dependencies or use Singleton pattern side effect (initialize when first needed).

Yet if you really have to output the order you can manually log all

Initialization section entries
Finalization section entries
class constructors
class destructors

One safe way to do it is by using the Windows API - OutputDebugString()

You can use the following unit to help you with the logging

unit unt_Debug;
{$SCOPEDENUMS ON}

interface

uses
  // System
  System.SysUtils
  {$IFDEF MACOS}
  ,FMX.Types
  {$ELSE}
  ,Winapi.Windows
  {$ENDIF};

{$WARN SYMBOL_PLATFORM OFF}
/// <remarks>
/// Output debug string. Output debug string can be seen in Delphi
/// View|Debug Windows|Event Log or with 3-rd party programs such as
/// dbgview.exe from SysInternals (www.sysinternals.com)
/// </remarks>
procedure ODS(const Text: string);

procedure ReportClassConstructorCall(const C: TClass);

procedure ReportClassDestructorCall(const C: TClass);

procedure ReportInitializationSection(const UnitName: string);

procedure ReportFinalizationSection(const UnitName: string);

implementation

procedure ReportClassConstructorCall(const C: TClass);
begin
  ODS(Format('%0:s class constructor invoked.', [C.ClassName]));
end;

procedure ReportClassDestructorCall(const C: TClass);
begin
  ODS(Format('%0:s class destructor invoked.', [C.ClassName]));
end;

procedure ReportInitializationSection(const UnitName: string);
begin
  ODS(Format('Unit %0:s - entering Initialization section.', [UnitName]));
end;

procedure ReportFinalizationSection(const UnitName: string);
begin
  ODS(Format('Unit %0:s - entering Finalization section.', [UnitName]));
end;

procedure ODS(const Text: string);
begin
  {$IFDEF DEBUG}
  {$IFDEF MACOS}
  // http://stackoverflow.com/questions/12405447/outputdebugstring-with-delphi-for-macosunit unt_Debug;
   Log.d(Text);
  {$ENDIF}
  {$IFDEF LINUX}
  __write(stderr, AText, Length(AText));
  __write(stderr, EOL, Length(EOL));
  {$ENDIF}
  {$IFDEF MSWINDOWS}
  OutputDebugString(PWideChar(Text));
  {$ENDIF}
  {$ENDIF}
end;

{$WARN SYMBOL_PLATFORM ON}

end.

It can be used for example this way:

unit Sample;

interface

type
  TSample = class
  public
    class constructor Create;
    class destructor Destroy;
  end;

implementation

uses
  unt_Debug;

class constructor TSample.Create;
begin
  ReportClassConstructorCall(TSample);
  // Do stuff
end;

class destructor TSample.Destroy;
begin
  ReportClassDestructorCall(TSample);
  // Do stuff
end;

initialization

  ReportInitializationSection(TSample.UnitName);
  // do stuff

finalization

  ReportFinalizationSection(TSample.UnitName);
  // do stuff

end.

Get Unit Name from InitTable - hack System.pas

2 Answers2