LazLogger: added basic profiling

git-svn-id: trunk@42860 -
This commit is contained in:
martin 2013-09-18 14:43:41 +00:00
parent 0e785800e1
commit 71ce8192f2
7 changed files with 352 additions and 14 deletions

1
.gitattributes vendored
View File

@ -2373,6 +2373,7 @@ components/lazutils/lazfreetypefontcollection.pas svneol=native#text/plain
components/lazutils/lazlogger.pas svneol=native#text/pascal
components/lazutils/lazloggerbase.pas svneol=native#text/pascal
components/lazutils/lazloggerdummy.pas svneol=native#text/pascal
components/lazutils/lazloggerprofiling.pas svneol=native#text/pascal
components/lazutils/lazmethodlist.pas svneol=native#text/pascal
components/lazutils/lazutf16.pas svneol=native#text/pascal
components/lazutils/lazutf8.pas svneol=native#text/pascal

View File

@ -63,6 +63,7 @@ type
FFileHandle: TLazLoggerFileHandle;
FOnDbgOut: TLazLoggerWriteEvent;
FOnDebugLn: TLazLoggerWriteEvent;
FBlockHandler: TList;
FEnvironmentForLogFileName: String;
@ -98,6 +99,9 @@ type
procedure DecreaseIndent(LogGroup: PLazLoggerLogGroup); overload; override;
procedure IndentChanged; override;
procedure CreateIndent; virtual;
function GetBlockHandler(AIndex: Integer): TLazLoggerBlockHandler; override;
procedure ClearAllBlockHandler;
procedure DoDbgOut(const s: string); override;
procedure DoDebugLn(const s: string); override;
@ -119,6 +123,10 @@ type
property OnDebugLn: TLazLoggerWriteEvent read FOnDebugLn write FOnDebugLn;
property OnDbgOut: TLazLoggerWriteEvent read FOnDbgOut write FOnDbgOut;
procedure AddBlockHandler(AHandler: TLazLoggerBlockHandler); override;
procedure RemoveBlockHandler(AHandler: TLazLoggerBlockHandler); override;
function BlockHandlerCount: Integer; override;
// forward to TLazLoggerFileHandle
property LogName: String read GetLogName write SetLogName;
property UseStdOut: Boolean read GetUseStdOut write SetUseStdOut;
@ -389,17 +397,26 @@ begin
end;
procedure TLazLoggerFile.IncreaseIndent;
var
i: Integer;
begin
inc(FDebugNestLvl);
CreateIndent;
for i := 0 to BlockHandlerCount - 1 do
BlockHandler[i].EnterBlock(Self, FDebugNestLvl);
end;
procedure TLazLoggerFile.DecreaseIndent;
var
i: Integer;
begin
if not FDebugNestAtBOL then DebugLn;
if FDebugNestLvl > 0 then
if FDebugNestLvl > 0 then begin
for i := 0 to BlockHandlerCount - 1 do
BlockHandler[i].ExitBlock(Self, FDebugNestLvl);
dec(FDebugNestLvl);
end;
CreateIndent;
end;
@ -451,6 +468,16 @@ begin
FDebugIndent := s + StringOfChar(' ', NewLen);
end;
function TLazLoggerFile.GetBlockHandler(AIndex: Integer): TLazLoggerBlockHandler;
begin
Result := TLazLoggerBlockHandler(FBlockHandler[AIndex]);
end;
procedure TLazLoggerFile.ClearAllBlockHandler;
begin
while BlockHandlerCount > 0 do RemoveBlockHandler(BlockHandler[0]);
end;
procedure TLazLoggerFile.DoDbgOut(const s: string);
var
Handled: Boolean;
@ -539,6 +566,7 @@ constructor TLazLoggerFile.Create;
begin
inherited;
FDebugNestLvl := 0;
FBlockHandler := TList.Create;
{$ifdef WinCE}
FParamForLogFileName := '';
@ -551,8 +579,10 @@ end;
destructor TLazLoggerFile.Destroy;
begin
ClearAllBlockHandler;
inherited Destroy;
FreeAndNil(FFileHandle);
FreeAndNil(FBlockHandler);
end;
procedure TLazLoggerFile.Assign(Src: TLazLogger);
@ -572,6 +602,23 @@ begin
end;
end;
procedure TLazLoggerFile.AddBlockHandler(AHandler: TLazLoggerBlockHandler);
begin
FBlockHandler.Add(AHandler);
AHandler.AddReference;
end;
procedure TLazLoggerFile.RemoveBlockHandler(AHandler: TLazLoggerBlockHandler);
begin
FBlockHandler.Remove(AHandler);
AHandler.ReleaseReference;
end;
function TLazLoggerFile.BlockHandlerCount: Integer;
begin
Result := FBlockHandler.Count;
end;
function TLazLoggerFile.GetLogFileName: string;
var
EnvVarName: string;

View File

@ -45,6 +45,18 @@ type
type
TLazLogger = class;
{ TLazLoggerBlockHandler
called for DebuglnEnter / Exit
}
TLazLoggerBlockHandler = class(TRefCountedObject)
public
procedure EnterBlock(Sender: TLazLogger; Level: Integer); virtual; abstract;
procedure ExitBlock(Sender: TLazLogger; Level: Integer); virtual; abstract;
end;
{ TLazLoggerLogGroupList }
TLazLoggerLogGroupList = class(TRefCountedObject)
@ -95,6 +107,7 @@ type
procedure IncreaseIndent({%H-}LogGroup: PLazLoggerLogGroup); overload; virtual;
procedure DecreaseIndent({%H-}LogGroup: PLazLoggerLogGroup); overload; virtual;
procedure IndentChanged; virtual;
function GetBlockHandler(AIndex: Integer): TLazLoggerBlockHandler; virtual;
procedure DoDbgOut(const {%H-}s: string); virtual;
procedure DoDebugLn(const {%H-}s: string); virtual;
@ -119,6 +132,11 @@ type
function FindOrRegisterLogGroup(const AConfigName: String) : PLazLoggerLogGroup; virtual;
property LogGroupList: TLazLoggerLogGroupList read GetLogGroupList;
property UseGlobalLogGroupList: Boolean read FUseGlobalLogGroupList write SetUseGlobalLogGroupList;
procedure AddBlockHandler(AHandler: TLazLoggerBlockHandler); virtual;
procedure RemoveBlockHandler(AHandler: TLazLoggerBlockHandler); virtual;
function BlockHandlerCount: Integer; virtual;
property BlockHandler[AIndex: Integer]: TLazLoggerBlockHandler read GetBlockHandler;
public
procedure DebuglnStack(const s: string = '');
@ -509,6 +527,11 @@ begin
IndentChanged;
end;
function TLazLogger.GetBlockHandler(AIndex: Integer): TLazLoggerBlockHandler;
begin
Result := nil;;
end;
procedure TLazLogger.SetNestLvlIndent(AValue: Integer);
begin
if FNestLvlIndent = AValue then Exit;
@ -671,6 +694,21 @@ begin
Result^.Flags := Result^.Flags + [lgfNoDefaultEnabledSpecified];
end;
procedure TLazLogger.AddBlockHandler(AHandler: TLazLoggerBlockHandler);
begin
//
end;
procedure TLazLogger.RemoveBlockHandler(AHandler: TLazLoggerBlockHandler);
begin
//
end;
function TLazLogger.BlockHandlerCount: Integer;
begin
Result := 0;
end;
procedure TLazLogger.DebuglnStack(const s: string);
begin
DoDebuglnStack(s);
@ -992,12 +1030,18 @@ begin
end;
procedure TLazLoggerWithGroupParam.Assign(Src: TLazLogger);
var
i: Integer;
begin
inherited Assign(Src);
if (Src <> nil) and (Src is TLazLoggerWithGroupParam) then begin
FLogParamParsed := False;
FParamForEnabledLogGroups := TLazLoggerWithGroupParam(Src).FParamForEnabledLogGroups;
end;
if (Src <> nil) then
for i := 0 to Src.BlockHandlerCount - 1 do
AddBlockHandler(BlockHandler[i]);
end;
function TLazLoggerWithGroupParam.RegisterLogGroup(const AConfigName: String): PLazLoggerLogGroup;

View File

@ -45,6 +45,16 @@ type
type
(* All empty methods *)
{ TLazLoggerBlockHandler
called for DebuglnEnter / Exit
}
TLazLoggerBlockHandler = class
public
procedure IncreaseIndent; virtual; abstract;
procedure DecreaseIndent; virtual; abstract;
end;
{ TLazLoggerLogGroupList }
TLazLoggerLogGroupList = class(TRefCountedObject)

View File

@ -0,0 +1,233 @@
unit LazLoggerProfiling;
{$mode objfpc}{$H+}
interface
uses
Classes, SysUtils, LazLoggerBase, lazutf8sysutils;
type
{ TLazLoggerBlockTimer }
TLazLoggerBlockTimer = class(TLazLoggerBlockHandler)
private
FMaxDepth: Integer;
FTimes: Array of QWord;
FNested: Array of QWord;
function GetNested(ALevel: Integer): QWord;
function GetTimeDiff(ALevel: Integer): QWord;
procedure SetMaxDepth(AValue: Integer);
public
constructor Create;
procedure EnterBlock(Sender: TLazLogger; Level: Integer); override;
procedure ExitBlock(Sender: TLazLogger; Level: Integer); override;
property MaxDepth: Integer read FMaxDepth write SetMaxDepth;
property TimeDiff[ALevel: Integer]: QWord read GetTimeDiff;
property Nested[ALevel: Integer]: QWord read GetNested;
end;
{ TLazLoggerBlockMemWatch }
TLazLoggerBlockMemWatch = class(TLazLoggerBlockHandler)
private
FMaxDepth: Integer;
FMem: Array of Int64;
FNested: Array of Int64;
function GetMemDiff(ALevel: Integer): Int64;
function GetNested(ALevel: Integer): Int64;
procedure SetMaxDepth(AValue: Integer);
public
constructor Create;
procedure EnterBlock(Sender: TLazLogger; Level: Integer); override;
procedure ExitBlock(Sender: TLazLogger; Level: Integer); override;
property MaxDepth: Integer read FMaxDepth write SetMaxDepth;
property MemDiff[ALevel: Integer]: Int64 read GetMemDiff;
property Nested[ALevel: Integer]: Int64 read GetNested;
end;
// %0:s Current block, since enter
// %1:s Sum of Nested blocks frame
// %2:s Paren block, since enter
// %4:s Sum of Nested blocks in parent frame
function DbgsMemUsed(AFormat: String = '%0:d'): string;
function DbgsTimeUsed(AFormat: String = '%0:n'): string;
implementation
function GetMemWatch: TLazLoggerBlockMemWatch;
var
i: Integer;
begin
Result := nil;
i := DebugLogger.BlockHandlerCount - 1;
while (i >= 0) and (Result = nil) do
if DebugLogger.BlockHandler[i] is TLazLoggerBlockMemWatch then
Result := DebugLogger.BlockHandler[i] as TLazLoggerBlockMemWatch
else
dec(i);
end;
function GetTimer: TLazLoggerBlockTimer;
var
i: Integer;
begin
Result := nil;
i := DebugLogger.BlockHandlerCount - 1;
while (i >= 0) and (Result = nil) do
if DebugLogger.BlockHandler[i] is TLazLoggerBlockTimer then
Result := DebugLogger.BlockHandler[i] as TLazLoggerBlockTimer
else
dec(i);
end;
function DbgsMemUsed(AFormat: String): string;
var
l: TLazLoggerBlockMemWatch;
i: Integer;
begin
Result := '';
i := DebugLogger.NestLvlIndent;
l := GetMemWatch;
if l = nil then exit;
try
Result := Format(AFormat, [l.MemDiff[i], l.Nested[i], l.MemDiff[i-1], l.Nested[i-1]]);
except
Result := Format('%0:d %1:d', [l.MemDiff[i], l.Nested[i], l.MemDiff[i-1], l.Nested[i-1]]);
end;
end;
function DbgsTimeUsed(AFormat: String): string;
var
l: TLazLoggerBlockTimer;
i: Integer;
begin
Result := '';
i := DebugLogger.NestLvlIndent;
l := GetTimer;
if l = nil then exit;
try
Result := Format(AFormat, [l.TimeDiff[i]/1000, l.Nested[i]/1000, l.TimeDiff[i-1]/1000, l.Nested[i-1]/1000]);
except
Result := Format('%0:n %1:n', [l.TimeDiff[i]/1000, l.Nested[i]/1000, l.TimeDiff[i-1]/1000, l.Nested[i-1]/1000]);
end;
end;
{ TLazLoggerBlockMemWatch }
procedure TLazLoggerBlockMemWatch.SetMaxDepth(AValue: Integer);
begin
if FMaxDepth = AValue then Exit;
SetLength(FMem, AValue+1);
SetLength(FNested, AValue);
if (FMaxDepth = 0) and (AValue > 0) then begin
FMem[0] := GetHeapStatus.TotalAllocated;
FNested[0] := 0;
end;
FMaxDepth := AValue;
end;
function TLazLoggerBlockMemWatch.GetMemDiff(ALevel: Integer): Int64;
var
t: Int64;
begin
Result := 0;
if (ALevel < 0) or (ALevel >= FMaxDepth + 1) then exit;
t := GetHeapStatus.TotalAllocated;
Result := t - FMem[ALevel];
end;
function TLazLoggerBlockMemWatch.GetNested(ALevel: Integer): Int64;
begin
Result := 0;
if (ALevel < 0) or (ALevel >= FMaxDepth) then exit;
Result := FNested[ALevel];
end;
constructor TLazLoggerBlockMemWatch.Create;
begin
MaxDepth := 100;
FMem[0] := GetHeapStatus.TotalAllocated;
FNested[0] := 0;
end;
procedure TLazLoggerBlockMemWatch.EnterBlock(Sender: TLazLogger; Level: Integer);
begin
if (Level < 0) or (Level >= FMaxDepth + 1) then exit;
FMem[Level] := GetHeapStatus.TotalAllocated;
if (Level >= FMaxDepth) then exit;
FNested[Level] := 0;
end;
procedure TLazLoggerBlockMemWatch.ExitBlock(Sender: TLazLogger; Level: Integer);
begin
if (Level < 1) or (Level >= FMaxDepth + 1) then exit;
FMem[Level - 1] := FNested[Level - 1] + GetMemDiff(Level);
end;
{ TLazLoggerBlockTimer }
procedure TLazLoggerBlockTimer.SetMaxDepth(AValue: Integer);
begin
if FMaxDepth = AValue then Exit;
SetLength(FTimes, AValue+1);
SetLength(FNested, AValue);
if (FMaxDepth = 0) and (AValue > 0) then begin
FTimes[0] := GetTickCount64;
FNested[0] := 0;
end;
FMaxDepth := AValue;
end;
function TLazLoggerBlockTimer.GetTimeDiff(ALevel: Integer): QWord;
var
t: QWord;
begin
Result := 0;
if (ALevel < 0) or (ALevel >= FMaxDepth + 1) then exit;
t := GetTickCount64;
if t >= FTimes[ALevel] then
Result := t - FTimes[ALevel]
else // timer overflow
Result := high(t) - FTimes[ALevel] + t;
end;
function TLazLoggerBlockTimer.GetNested(ALevel: Integer): QWord;
begin
Result := 0;
if (ALevel < 0) or (ALevel >= FMaxDepth) then exit;
Result := FNested[ALevel];
end;
constructor TLazLoggerBlockTimer.Create;
begin
MaxDepth := 100;
FTimes[0] := GetTickCount64;
FNested[0] := 0;
end;
procedure TLazLoggerBlockTimer.EnterBlock(Sender: TLazLogger; Level: Integer);
begin
if (Level < 0) or (Level >= FMaxDepth + 1) then exit;
FTimes[Level] := GetTickCount64;
if (Level >= FMaxDepth) then exit;
FNested[Level] := 0;
end;
procedure TLazLoggerBlockTimer.ExitBlock(Sender: TLazLogger; Level: Integer);
begin
if (Level < 1) or (Level >= FMaxDepth + 1) then exit;
FNested[Level - 1] := FNested[Level - 1] + GetTimeDiff(Level);
end;
initialization
DebugLogger.AddBlockHandler(TLazLoggerBlockTimer.Create);
DebugLogger.AddBlockHandler(TLazLoggerBlockMemWatch.Create);
end.

View File

@ -1,4 +1,4 @@
<?xml version="1.0"?>
<?xml version="1.0" encoding="UTF-8"?>
<CONFIG>
<Package Version="4">
<Name Value="LazUtils"/>
@ -19,10 +19,10 @@
<Description Value="Useful units for Lazarus packages."/>
<License Value="Modified LGPL-2"/>
<Version Major="1"/>
<Files Count="72">
<Files Count="73">
<Item1>
<Filename Value="laz2_dom.pas"/>
<UnitName Value="laz2_DOM"/>
<UnitName Value="Laz2_DOM"/>
</Item1>
<Item2>
<Filename Value="laz2_names.inc"/>
@ -102,7 +102,7 @@
</Item20>
<Item21>
<Filename Value="lazutf8classes.pas"/>
<UnitName Value="lazutf8classes"/>
<UnitName Value="LazUTF8Classes"/>
</Item21>
<Item22>
<Filename Value="masks.pas"/>
@ -309,6 +309,10 @@
<Filename Value="winlazutf8.inc"/>
<Type Value="Include"/>
</Item72>
<Item73>
<Filename Value="lazloggerprofiling.pas"/>
<UnitName Value="LazLoggerProfiling"/>
</Item73>
</Files>
<LazDoc Paths="../../docs/xml/lazutils"/>
<i18n>

View File

@ -7,15 +7,14 @@ unit LazUtils;
interface
uses
Laz2_DOM, Laz2_XMLCfg, laz2_XMLRead, laz2_xmlutils, laz2_XMLWrite, Laz_DOM,
Laz_XMLCfg, Laz_XMLRead, Laz_XMLStreaming, Laz_XMLWrite, LazFileUtils,
LazFileCache, LazUTF8, LazDbgLog, paswstring, FileUtil, LazUTF8Classes,
Masks, LazUtilsStrConsts, LConvEncoding, lazutf16, lazutf8sysutils,
LazMethodList, AvgLvlTree, LazLogger, LazFreeType, TTCache, TTCalc, TTCMap,
TTDebug, TTError, TTFile, TTGLoad, TTInterp, TTLoad, TTMemory, TTObjs,
TTProfile, TTRASTER, TTTables, TTTypes, EasyLazFreeType, LazLoggerBase,
LazLoggerDummy, LazClasses, LazFreeTypeFontCollection, LazConfigStorage,
UTF8Process, laz2_xpath, DictionaryStringList, LazarusPackageIntf;
Laz2_DOM, Laz2_XMLCfg, laz2_XMLRead, laz2_xmlutils, laz2_XMLWrite, Laz_DOM, Laz_XMLCfg,
Laz_XMLRead, Laz_XMLStreaming, Laz_XMLWrite, LazFileUtils, LazFileCache, LazUTF8,
LazDbgLog, paswstring, FileUtil, LazUTF8Classes, Masks, LazUtilsStrConsts, LConvEncoding,
lazutf16, lazutf8sysutils, LazMethodList, AvgLvlTree, LazLogger, LazFreeType, TTCache,
TTCalc, TTCMap, TTDebug, TTError, TTFile, TTGLoad, TTInterp, TTLoad, TTMemory, TTObjs,
TTProfile, TTRASTER, TTTables, TTTypes, EasyLazFreeType, LazLoggerBase, LazLoggerDummy,
LazClasses, LazFreeTypeFontCollection, LazConfigStorage, UTF8Process, laz2_xpath,
DictionaryStringList, LazLoggerProfiling, LazarusPackageIntf;
implementation