In the up-to-come 1.13 version, there is also a new logging mechanism with stack trace exception and such, just like MadExcept, using a .map file content as source. It's now used by the unit testing classes, so that any failure will create an entry in the log with the source line, and stack trace:
C:\Dev\lib\SQLite3\exe\TestSQL3.exe 0.0.0.0 (2011-04-13)
Host=Laptop User=MyName CPU=2*0-15-1027 OS=2.3=5.1.2600 Wow64=0 Freq=3579545
TSynLogTest 1.13 2011-04-13 05:40:25

20110413 05402559 fail TTestLowLevelCommon(00B31D70) Low level common: TDynArray "" stack trace 0002FE0B SynCommons.TDynArray.Init (15148) 00036736 SynCommons.Test64K (18206) 0003682F SynCommons.TTestLowLevelCommon._TDynArray (18214) 000E9C94 TestSQL3 (163)
The difference between a test suit without logging (TSynTests) and a test suit with logging (TSynTestsLogged) is only this:
procedure TSynTestsLogged.Failed(const msg: string; aTest: TSynTestCase);
begin
  inherited;
  with TestCase[fCurrentMethod] do
    fLogFile.Log(sllFail,'%: % "%"',
      [Ident,TestName[fCurrentMethodIndex],msg],aTest);
end;

The logging mechanism can be used to trace recursive calls. It can use an interface-based mechanism to log when you enter and leave any method:

procedure TMyDB.SQLExecute(const SQL: RawUTF8);
var ILog: ISynLog;
begin
  ILog := TSynLogDB.Enter(self,'SQLExecute');
  // do some stuff
  ILog.Log(sllInfo,'SQL=%',[SQL]);
end; // when you leave the method, it will write the corresponding event to the log

It will be logged as such:

20110325 19325801  +    MyDBUnit.TMyDB(004E11F4).SQLExecute
20110325 19325801 info   SQL=SELECT * FROM Table;
20110325 19325801  -    MyDBUnit.TMyDB(004E11F4).SQLExecute

Here the method name is set in the code ('SQLExecute'). But if you have an associated .map file, the logging mechanism is able to read this symbol information, and write the exact line number of the event.

Note that by default you have time and date written to the log, but it's also possible to replace this timing with high-resolution timestamps. With this, you'll be able to profile your application with data coming from the customer side, on its real computer. Via the Enter method (and its auto-Leave feature), you have all information needed for this.

In this log entries, you'll see both high-resolution time stamp, and the entering and leaving of the TTestCompression.TestLog method traced with no additional code (with accurate line numbers):

0000000000000B56  +    TTestCompression(00AB3570).000E6C79 SynSelfTests.TTestCompression.TestLog (376)
0000000000001785  -    TTestCompression(00AB3570).000E6D09 SynSelfTests.TTestCompression.TestLog (385)

I still need to write some tool to compute the profiling, but there is already a dedicated TSynLogFile class able to read the .log file, and recognize its content.

The first time the .map file is read, a .mab file is created, and will contain all symbol information needed. You can send the .mab file with the .exe to your client, or even embed its content to the .exe. This .mab file is optimized: a .map of 927,984 bytes compresses into a 71,943 .mab file.

You have several debugging levels available. And even 4 custom types. It's worth saying that the logging level is a SET, and not an enumerate: that is, you can select several kind of logging information to be logged at once, on request:

/// the available logging events, as handled by TSynLog
// - sllError will log errors
// - sllInfo will log general information events
// - sllDebug will log detailed debugging information
// - sllEnter will log every method start
// - sllLeave will log every method quit
// - sllLastError will log the GetLastError OS message
// - sllException will log all exception raised - available since Windows XP
// - sllExceptionOS will log all OS low-level exceptions (EDivByZero,
// ERangeError, EAccessViolation...) - available since Windows XP
// - sllMemory will log memory statistics
// - sllStackTrace will log caller's stack trace (it's by default part of
// TSynLogFamily.LevelStackTrace)
// - sllFail was defined fo TSynTestsLogged.Failed method
// - sllSQL is dedicated to trace the SQL statements
// - sllResult could trace the SQL results, JSON encoded
// - sllDB is dedicated to trace low-level database engine features
// - sllHTTP could be used to trace HTTP process
// - sllClient/sllServer could be used to trace some Client or Server process
// - sllCustom* items can be used for any purpose
TSynLogInfo = (
    sllNone, sllError, sllInfo, sllDebug, sllEnter, sllLeave,
    sllLastError, sllException, sllExceptionOS, sllMemory, sllStackTrace,
    sllFail, sllSQL, sllResult, sllDB, sllHTTP, sllClient, sllServer,
    sllCustom1, sllCustom2, sllCustom3, sllCustom4);
/// used to define a logging level
// - i.e. a combination of none or several logging event
// - e.g. use LOG_VERBOSE constant to log all events
TSynLogInfos = set of TSynLogInfo;

Of course, this logging mechanism is able to intercept the raise of exceptions, including the worse (e.g. EAccessViolation), to be logged automatically in the log file:

000000000000090B EXCOS EAccessViolation (C0000005) at 000E9C7A SynSelfTests.Proc1 (785)  stack trace 000E9D51 SynSelfTests.Proc2 (801) 000E9CC1 SynSelfTests.Proc1 (790) 000E9D51 SynSelfTests.Proc2 (801) 000E9CC1 SynSelfTests.Proc1 (790) 000E9D51 SynSelfTests.Proc2 (801) 000E9CC1 SynSelfTests.Proc1 (790) 000E9D51 SynSelfTests.Proc2 (801) 000E9CC1 SynSelfTests.Proc1 (790) 000E9D51 SynSelfTests.Proc2 (801) 000E9CC1 SynSelfTests.Proc1 (790) 000E9E2E SynSelfTests.TestsLog (818) 000EA0FB SynSelfTests (853) 00003BF4 System.InitUnits 00003C5B System.@StartExe 000064AB SysInit.@InitExe 000EA3EC TestSQL3 (153)

Objects, TList, and dynamic arrays can also be serialized as JSON in the log on request.
TSQLRecords can also be serialized as JSON in the log.

For instance, the following code:

procedure TestPeopleProc;
var People: TSQLRecordPeople;
    Log: ISynLog;
begin
  Log := TSQLLog.Enter;
  People := TSQLRecordPeople.Create;
  try
    People.ID := 16;
    People.FirstName := 'Louis';
    People.LastName := 'Croivébaton';
    People.YearOfBirth := 1754;
    People.YearOfDeath := 1793;
    Log.Log(sllInfo,People);
  finally
    People.Free;
  end;
end;

will result in the following log content:

0000000000001172  +    000E9F67 SynSelfTests.TestPeopleProc (784)
000000000000171B info      {"TSQLRecordPeople(00AB92E0)":{"ID":16,"FirstName":"Louis","LastName":"Croivébaton","Data":"","YearOfBirth":1754,"YearOfDeath":1793}}
0000000000001731  -    000EA005 SynSelfTests.TestPeopleProc (794)

You can have several log files per process, and even a per-thread log file, if needed (it could be sometimes handy, for instance on a server running the same logic in parallel in several threads).

Works with Delphi 6 up to XE.

Feedback and questions are welcome in our forum.

Blog post edit