Start und Stop jeder Methode Tracen an nur einer stelle Implementieren

[gibb]

Hallo zusammen,

Gibt es eine möglichkeit die zeit die in einer Methode verbracht wird zu tracen?

Klar ich könnte bei jedem methodenstart und ende eine Zeile einfügen, das ist jedoch nicht die Lösung die ich suche. Ich möchte an einem ort etwas machen das jeder Methodenstart und stop getracet wird und zwar mit Classenname und Methodenname nach möglichkeit.

geht das irgendwie? Ein simples Nein würde auch reichen wenns dann stimmt. Weil ich selber hätte keine ahnung wo das Delphi das anbieten sollte und wo die Logik dafür untergebracht währe.


gruss Severin

[haentschman]

Hallo...

welche Delphi Version hast du ? Ab DXE ist AQtime dabei (Standard). Damit kann man sowas einfach realisieren.

PS: Passe in deinem Profil einfach die Delphi Version an :zwinker:

[Bernhard Geyer]

AQTime ist super. Die größere Kaufversion kann auch Zeiten auf Quellcode-Zeilen profilen.
Damit haben wir schon einige Flaschenhälse behoben ...

[gibb]

Delphi 2006 sorry das habe ich vergessen zu schreiben. AQ time habe ich jedoch auch als Software zur verfügung. Ich möchte das jedoch nicht über AQ time lösen da ich es für weitere Analysen benötige die AQ Time mir nicht liefern kann da es Produktspezifisch ist.

Ausserdem läuft bei gewissen usecases AQ time nicht sauber und schmeisst exceptions weil wohl gewisse Programmierer etwas "verbotenes" gemacht haben.

[himitsu]

Tja, einen allgemeinen und vorallem einfachen Weg gibt es nunmal nicht.

Entweger man sucht sich nachträglich (nach dem Kompilieren) aus den erweiterten Debuginfos die Methoden-Anfänge (erste Codezeile) und deren Ende (letzte Codezeile)
und patcht sich dann überall einen Funktionsaufruf (Logfunktion) rein, bzw. erstellt überall dort Haltepunkte, auf die ein eigener Debugger hört.

Oder man baut sich einen Precompiler, welcher vor dem compilieren die Quellcodes parst und überall diese Log-Funktionsufrufe reinmacht (nur für's Compilieren),
bzw. man läßt den Parser so drüberlaufen und läßt sich direkt in seine Quellcodes die Aufrufe reinbauen.
Oder man geht selber durch und macht die manuell rein. :stupid:

[schlecki]

eine recht billige Variante ist mit einem Interface implementierbar - allerdings muss dann jede Methode, die gemessen werden soll, mit einer Zeile instrumentiert werden. Ich zeige hier mal ein kurzes Beispiel (aus dem Kopf runtergetippelt)

Delphi-Quellcode:

type
  IAutoDestroy = interface(IInterface)
  end;

  TMeasure = class(TInterfacedObject, IAutoDestroy)
  protected
    FMessage: string;
    procedure Log(const msg: string);
  public
    class function MeasureThis(const msg: string): IAutoDestroy
    constructor Create(const msg: string); reintroduce;
    destructor Destroy; override;
  end;

// ...

class function TMeasure.MeasureThis(const msg: string): IAutoDestroy
begin
  Result := TMeasure.Create(msg);
end;

constructor TMeasure.Create(const msg: string);
begin
  inherited Create;
  // Log msg
  FMessage := msg;
  Log('Beginn: ' + FMessage);  
end;

destructor TMeasure.Destroy();
  Log('Ende: ' + FMessage);
end;

procedure TMeasure.Log(const msg: string);
begin
  Writeln(FormatDateTime('HH:MM:SS', Now), ' [', GetCurrentThreadId(), '] ', msg);
end;

Die Verwendung ist dann so:

Delphi-Quellcode:

procedure TForm.ButtonClick(...) 
begin
  TMeasure.MeasureThis('TForm.ButtonClick');
  Writeln('Muuh');
  Sleep(1000);
end;

die Ausgabe ist dann etwa so:

Code:

11:12:00 [123] Beginn: TForm.ButtonClick
Muuh
11:12:01 [123] Ende: TForm.ButtonClick

Das lässt sich natürlich noch beliebig verfeinern :)

[stahli]

Für eine zeilenweise Analyse habe ich mir mal notdürftig etwas zusammengestrickt: http://www.delphipraxis.net/165749-r...hleunigen.html

[Bernhard Geyer]

Zitat:

Zitat von gibb (Beitrag 1152469)

Delphi 2006 sorry das habe ich vergessen zu schreiben. AQ time habe ich jedoch auch als Software zur verfügung. Ich möchte das jedoch nicht über AQ time lösen da ich es für weitere Analysen benötige die AQ Time mir nicht liefern kann da es Produktspezifisch ist.

???

Zitat:

Zitat von gibb (Beitrag 1152469)

Ausserdem läuft bei gewissen usecases AQ time nicht sauber und schmeisst exceptions weil wohl gewisse Programmierer etwas "verbotenes" gemacht haben.

Welche Version? Diverse Versionen haben so ihre Problem unter Win7. AQTime4 konnte ich unter Vista (32-Bit) einsetzen aber nicht mehr unter Win7 (64 Bit). Komischerweise läuft aber AQTime3 damit ganz gut. Die "verbotenen" Sachen macht hier eher AQTime als eure Entwickler.

[gibb]

danke für die Zahlreichen Antworten

Mit der die wir hier haben und der Trial der neusten weil ich auch herausgefunden habe das unter win7 alte AQ time versionen Probleme machen ;)

um deine Fragezeichen zu beantworten. Wir haben noch eine eigene Scriptingsprache integeriert und messen diese ebenso messen wir SQL statements aus dem Script und aus dem Delphi sourcecode. Die Scriptingsprache selber und die Methodenaufrufe tracen wir auch und können dann Informationen herausfiltern. Selbst der Java teil welcher delphi Code integriert können wir messen. Bis jetzt fehlt halt nur der Delphi Teil der bis jetzt als unbekante Zeitaufwand angegeben wird.Aber um herauszufinden wo das dann der Flaschenhals liegt müsste man die Methodenaufrüfe selber Tracen können ;)

Gruss gibb

[himitsu]

Die VAriante mit dem Interface ist eigentlich genial. :thumb:
Das darf ich mir doch mopsen? :angle2:

Bastle mir grade eine kleine rudimentäre Log-Klasse, welche ich in meinen Klassen/Komponenten verbauen will, wo unter Anderem auch ein EnterMethode-/ExitMethod-LogAufruf implementiert ist, allerdings muß ich bis jetzt das Exit noch selber aufrufen (OK, da wo man das Result mitloggen will, da kommt man um den händischen Aufruf nicht drumrum)
Die soll dann mal als Weiterleitung zu irgendeinem beliebigen Logsystem genutzt werden können.

Aber ich hab auch grade eine Idee, wie man in dem automatischen "Ende:" mitbekommt, ob dieses durch einen regulären Ausstieg (Methodenende oder Exit), oder durch DAS vERLASSEN über eine Exception, eingetreten ist. :angle:

[schlecki]

Zitat:

Zitat von himitsu (Beitrag 1152538)

Die VAriante mit dem Interface ist eigentlich genial. :thumb:
Das darf ich mir doch mopsen? :angle2:

dafür hab ichs gepostet :)

[Bernhard Geyer]

Zitat:

Zitat von schlecki (Beitrag 1152476)

Die Verwendung ist dann so:

Delphi-Quellcode:

procedure TForm.ButtonClick(...) 
begin
  TMeasure.MeasureThis('TForm.ButtonClick');
  Writeln('Muuh');
  Sleep(1000);
end;

Wenn man die Hilfsroutinen der JEDI zur verfügung hat könnte man sich den Text-Parameter bei "MeasureThis" sparen.
Einfach im Callstack den passenden Methodennamen rausholen und als Text ausgeben.
Dann könnte man mit einer einfachen Methode das komplett erschlagen

Delphi-Quellcode:

procedure StartMeasure: IAutoDestroy;
begin
  result := TMeasure.MeasureThis(_STACK...._);
end;

Verwendung:

Delphi-Quellcode:

procedure TForm.ButtonClick(...)
begin
  StartMeasure;
  Writeln('Muuh');
  Sleep(1000);
end;

[gibb]

Okay das klingt schonmal nicht schlecht...

Interface + JEDI klasse ergibt immerhin einen einzeiler der dynamisch klassen+methodenname ausliest... jetzt nur noch an einer stelle implementieren + einen schalter einbauen ob das tracing stattfinden soll. Aber diese stelle gibt es wohl nicht oder? es gibt ja nichts was die methodenaufrufe sozusagen verarbeitet und man noch einfluss darauf nehmen kann...

[Bummi]

{$ifdef debug} ... {$endif}

??

[schlecki]

oder ein boolean als class var in TMeasure - wenn der false ist, einfach im Log nichts schreiben.

edit: @bernhard geyer das mit der jcl muß ich mir nochmal anschauen, haben wir sowieso im projekt :) Danke ^^

[Luckie]

Darf man mal fragen wozu du das brauchst?

[himitsu]

Zitat:

Zitat von Luckie (Beitrag 1152590)

Darf man mal fragen wozu du das brauchst?

Wenn man absolut keine Ahnung hat, was das eigene Programm macht und man das nun endlich mal wissen will? :stupid:

Bei 'ner Multithreadanwendung, mit "ausreichend" (tausenden/millionen) Funktionen, da möchte ich dan die "kleinen" Logdateien sehn und vorallem den, welcher damit dann auch wirklich noch was anfangen kann (den, der in dieser Masse dann noch das Wichtige findet).

[Furtbichler]

Zitat:

Zitat von himitsu (Beitrag 1152595)

...da möchte ich dann die "kleinen" Logdateien sehn und vorallem den, welcher damit dann auch wirklich noch was anfangen kann (den, der in dieser Masse dann noch das Wichtige findet).

Es soll doch glatt Leute geben, die sich eine Auswertesoftware schreiben oder die Ergebnisse in einen SQL-Server schaufeln und dann damit rumspielen.

[Stevie]

Zitat:

Zitat von himitsu (Beitrag 1152538)

Die VAriante mit dem Interface ist eigentlich genial. :thumb:
Das darf ich mir doch mopsen? :angle2:

Dieses Pattern nennt sich RAII.

[Daniel]

Zitat:

Zitat von Luckie (Beitrag 1152590)

Darf man mal fragen wozu du das brauchst?

Damit ließe sich quantitativ erfassen, welche Programmteile wie oft aufgerufen werden und dabei allein und in Summe wie viel Ausführungszeit benötigen. Danach hat man (im Idealfall) eine Vorstellung, welches die maßgeblichen Flaschenhälse sind und wo man am effizientesten zur Optimierung ansetzen kann.

[Luckie]

Hm, gibt es da nicht schon Software für? Profiler oder wie die sich nennt?

[neo4a]

Zitat:

Zitat von Daniel (Beitrag 1152617)

Zitat:

Zitat von Luckie (Beitrag 1152590)

Darf man mal fragen wozu du das brauchst?

Damit ließe sich quantitativ erfassen, welche Programmteile wie oft aufgerufen werden und dabei allein und in Summe wie viel Ausführungszeit benötigen.

Das oder auch die Testabdeckung der Schnittstellen eines Moduls...

[Stevie]

Zitat:

Zitat von Luckie (Beitrag 1152618)

Hm, gibt es da nicht schon Software für? Profiler oder wie die sich nennt?

Hast du den Thread überhaupt gelesen?

[gibb]

:-D das mit dem Flag war keine Frage sondern eine Feststellung ;) das krieg ich noch gerade so hin...

Die frage ist nur wie schiebe ich das stückchien code allen Methoden unter die im Programm sind und das nur bei bedarf. Ansonsten möchte man ja diesen Code nicht unbedingt in jeder funktion finden ;)

daher müsste das irgendwie automatisch gehen. oder halt wie bereits gesagt eine stelle ganz weit hinten versteckt.


Gruss Gibb

[himitsu]

Zitat:

Zitat von gibb (Beitrag 1152662)

daher müsste das irgendwie automatisch gehen. oder halt wie bereits gesagt eine stelle ganz weit hinten versteckt.

Mehrere Die Wege hatte ich doch schonmal aufgezählt?

[gibb]

ja aber ich habe die hoffnung nicht aufgegeben das es einen einfacheren weg gibt ;)

Zitat:

Entweger man sucht sich nachträglich (nach dem Kompilieren) aus den erweiterten Debuginfos die Methoden-Anfänge (erste Codezeile) und deren Ende (letzte Codezeile)
und patcht sich dann überall einen Funktionsaufruf (Logfunktion) rein, bzw. erstellt überall dort Haltepunkte, auf die ein eigener Debugger hört.

Oder man baut sich einen Precompiler, welcher vor dem compilieren die Quellcodes parst und überall diese Log-Funktionsufrufe reinmacht (nur für's Compilieren),
bzw. man läßt den Parser so drüberlaufen und läßt sich direkt in seine Quellcodes die Aufrufe reinbauen.
Oder man geht selber durch und macht die manuell rein.

[himitsu]

Ein einfacher Weg wäre, wenn es ein Event gäbe, welches schon eingebaut ist (zu Beginn und am ende jeder Prozedur), aber sowas gibt es in Delphi nicht.

Bei Scriptsprachen, wie JavaScript und auch teilweise bei gemanagten Sprachen (vielleicht .NET) sähe die Sache anders aus. Also vorwiegend dort, wo ein Programm den Code interpretiert und wo man sich in den Interpretierer reinhängen kann.

Du willst ja überall einen Funktionsaufruf reinhaben und der muß ja auch erstmal überall rein.
Wäre halt zu schön, wenn man ganz einfach im Delphi einen Precompiler registrieren könnte. (den vermisse ich ganz doll)

In neueren Delphis gäbe es die PreCompile- und AfterCompile-Events, wo man sowas gewisser Maßen unterbringen könnte. (auch wenn kein echter PreCompiler möglich wäre, welcher die QuellCodes unverändert läßt)

[neo4a]

Zitat:

Zitat von himitsu (Beitrag 1152667)

Zitat:

Zitat von gibb (Beitrag 1152662)

daher müsste das irgendwie automatisch gehen. oder halt wie bereits gesagt eine stelle ganz weit hinten versteckt.

Mehrere Die Wege hatte ich doch schonmal aufgezählt?

Ich würde einmal vermuten, er möchte eine Lösung z.B. basierend auf TVirtualMethodInterceptor - er weiß es nur nicht.

Wie auch immer: Ohne Konfigurationsaufwand (sei es per Attribute, xml-File oder hardcodierte Funktionsaufrufe) wird es wohl nicht, zumindest aber nicht vernünftig gehen.

[Stevie]

Zitat:

Zitat von neo4a (Beitrag 1152671)

Zitat:

Zitat von himitsu (Beitrag 1152667)

Zitat:

Zitat von gibb (Beitrag 1152662)

daher müsste das irgendwie automatisch gehen. oder halt wie bereits gesagt eine stelle ganz weit hinten versteckt.

Mehrere Die Wege hatte ich doch schonmal aufgezählt?

Ich würde einmal vermuten, er möchte eine Lösung z.B. basierend auf TVirtualMethodInterceptor - er weiß es nur nicht.

Zum Profilen würd ich diesen Weg aber nicht gerade empfehlen, der ganze RTTI und Invoke Overhead ist ein Performance Albtraum (ich gehe jetzt mal davon aus, dass der TE hier performancekritische Stellen untersuchen möchte).

Ich konnte bisher nicht herauslesen, ob das Tracen Teil der Entwicklung ist, oder ob das auch irgendwie beim Kunden aktivierbar sein muss. Speziell für Debugging/Profiling Zwecke ist auch der Sampling Profiler sehr nützlich.

[Daniel]

Zitat:

Zitat von neo4a (Beitrag 1152671)

Ich würde einmal vermuten, er möchte eine Lösung z.B. basierend auf TVirtualMethodInterceptor - er weiß es nur nicht.

Ich wage es, dies in Zweifel zu ziehen. An den TVirtualMethodInterceptor hatte ich zwar auch geacht, dieser ist jedoch Teil der neuen RTTI und damit nicht in Delphi 2006 verfügbar.

[himitsu]

Und das ginge dann wohl auch nur für virtuelle Methoden und nicht für "alle" Methoden/Prozeduren.

Aufrufe der WinAPI und anderer DLL-Funktionen könnte man auch leicht umbiegen, aber Methoden/Prozeduren, welche direkt angesprungen werden, sind da schon schwerer, da es dort keine "zentrale" Stelle für die Eintrittsadresse gibt, außer man überschreibt den Methoden-Code und quetsch so seinen Log-Methodenaufruf dazwischen.

[Stevie]

Zitat:

Zitat von Daniel (Beitrag 1152680)

Zitat:

Zitat von neo4a (Beitrag 1152671)

Ich würde einmal vermuten, er möchte eine Lösung z.B. basierend auf TVirtualMethodInterceptor - er weiß es nur nicht.

Ich wage es, dies in Zweifel zu ziehen. An den TVirtualMethodInterceptor hatte ich zwar auch geacht, dieser ist jedoch Teil der neuen RTTI und damit nicht in Delphi 2006 verfügbar.

Das stimmt so nicht ganz. Die TVirtualMethodInterceptor Klasse an sich ist zwar Teil der neuen RTTI, aber die Technik dahinter war schon in Delphi 7 oder eher möglich (siehe auch diesen und andere Artikel) - diese wurde vor allem für SOAP benutzt (siehe z.B. Rio.pas)

[neo4a]

Zitat:

Zitat von Stevie (Beitrag 1152695)

Zitat:

Zitat von Daniel (Beitrag 1152680)

Zitat:

Zitat von neo4a (Beitrag 1152671)

TVirtualMethodInterceptor - er weiß es nur nicht.

und damit nicht in Delphi 2006 verfügbar.

schon in Delphi 7 oder eher möglich

Der TE gibt D5 als Zielplattform an, wobei ich gerade Schwierigkeiten habe mich zu erinnern, was eher auf den Markt war: D5 oder Farb-TV ;)

Da auch eine Info fehlt, wie viele Prozeduren überhaupt gemonitort oder getracet (S..-Denglisch) werden sollen, würde ich unserem Eid-Delphi-Genossen etwas Stärkung und den gezeigten Weg mit dem Interface-Einzeiler empfehlen, denn das funktioniert sicher und hat wenig Nebenwirkungen. Macht halt Arbeit, aber irgendetwas ist eben immer.

[himitsu]

Oder der TE hat vergessen es anzugeben. D5 ist die Standardeinstellung.
http://www.delphipraxis.net/issue-344/

Zitat:

Zitat von neo4a (Beitrag 1152717)

Da auch eine Info fehlt, wie viele Prozeduren überhaupt gemonitort oder getracet (S..-Denglisch) werden sollen,

Zitat:

Start und Stop jeder Methode Tracen an nur einer stelle Implementieren

Für mich klingt das wie "Alle".

[himitsu]

*doppelpost*

[neo4a]

Zitat:

Zitat von himitsu (Beitrag 1152736)

Zitat:

Start und Stop jeder Methode Tracen an nur einer stelle Implementieren

Für mich klingt das wie "Alle".

Ja, stimmt genau: alle 3! Da lohnt sich jeder Aufwand ;)

[gibb]

haha witzbold ;)

ich würde nicht nach einer solchen Lösung fragen wenn ich nur 3 methoden hätte...

ich werde mir dann halt die anderen wege genauer anschauen und versuchen den flexibelsten weg zu nehmen.

danke jedenfalls,

gruss Gibb

EDIT: nach dem wieder überfliegen stelle ich fest das es nur der PreCompiler für mich nen gangbaren weg währe. Aber ich habe jetzt dazu ne frage... Soll ich mir etwa hierzu ein Programm schreiben das die Pas file anpasst und anschliessend Compiliert und wieder die änderungen rückgängig macht?

Oder wie macht man das normalerweise?

[Namenloser]

Hatte jbg nicht mal einen Precompiler für Generics (bevor es sie von Haus aus gab)? Finde ich leider nicht mehr... aber du könntest mal danach suchen oder ihn fragen.

[neo4a]

Zitat:

Zitat von gibb (Beitrag 1153129)

ich würde nicht nach einer solchen Lösung fragen wenn ich nur 3 methoden hätte...

"Patienten lügen!" (Dr. House)

[Stevie]

Zitat:

Zitat von neo4a (Beitrag 1152717)

Der TE gibt D5 als Zielplattform an, wobei ich gerade Schwierigkeiten habe mich zu erinnern, was eher auf den Markt war: D5 oder Farb-TV ;)

Nicht nur ersten Post lesen, Andreas ;)

Zitat:

Zitat von gibb (Beitrag 1152469)

Delphi 2006 sorry das habe ich vergessen zu schreiben.