mORMot Open Source

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Logging 1 Line sllError takes 15 Seconds

Hi Arnaud,

Logging on a Standard Windows 11 Computer took a long time (much longer than on my develop maschine)
After looking in the Log i found the sllError Line takes 15 second.

The only Reason i found could be the StackTrace - Routines
I set StackTraceLevel to 0 an the delay disappeared (It disabled the StackTrace Option)
as i do not need the StackTrace at this log its not important for me.

But do you have an Idea what i have to do to avoid the delay on active StackTrace ? Is there a Windows - Option ? Does the Windows User afford som special rights ?

---

Rad Studio 12.1 Santorini

ab

Administrator

From: France

Registered: 2010-06-21

Posts: 14,659

Website

Re: Logging 1 Line sllError takes 15 Seconds

With Win32 or Win64 executable?

Does changing StackTraceUse to stOnlyAPI or stOnlyManual change something?

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Re: Logging 1 Line sllError takes 15 Seconds

win32 Executable (mORMot2)

I'll try

---

Rad Studio 12.1 Santorini

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Re: Logging 1 Line sllError takes 15 Seconds

Here my Results, made 4 Tests

1. Default Settings

15.03.2022 20:04:57.688	Trace	1	 Program wurde gestartet
15.03.2022 20:04:57.688	Error	1	 Error1  
15.03.2022 20:04:59.608	Error	1	 Error2  
15.03.2022 20:05:00.976	Error	1	 Error3  
15.03.2022 20:05:03.656	Enter	1	 After Error3

2. OnlyApi

15.03.2022 20:05:45.944	Trace	1	 Program wurde gestartet
15.03.2022 20:05:45.944	Error	1	 Error1  
15.03.2022 20:05:47.784	Error	1	 Error2  
15.03.2022 20:05:48.992	Error	1	 Error3  
15.03.2022 20:05:51.240	Enter	1	 After Error3

3. OnlyManual

15.03.2022 20:06:18.304	Trace	1	 Program wurde gestartet
15.03.2022 20:06:18.304	Error	1	 Error1  
15.03.2022 20:06:19.784	Error	1	 Error2  
15.03.2022 20:06:21.112	Error	1	 Error3  
15.03.2022 20:06:23.288	Enter	1	 After Error3

4. StackTraceLevel=0

15.03.2022 20:09:37.144	Trace	1	 Program wurde gestartet
15.03.2022 20:09:37.144	Error	1	 Error1
15.03.2022 20:09:37.144	Error	1	 Error2
15.03.2022 20:09:37.144	Error	1	 Error3
15.03.2022 20:09:38.592	Enter	1	 After Error3

Example Code

TSynLog.Family.Level := LOG_VERBOSE;
  if AppHasParam('StackTraceLevel0') then
TSynLog.Family.StackTraceLevel := 0;
  if SameText(GetAppParamValue('StackTraceUse'), 'OnlyApi') then
TSynLog.Family.StackTraceUse := stOnlyApi;
  if SameText(GetAppParamValue('StackTraceUse'), 'OnlyManual') then
TSynLog.Family.StackTraceUse := stOnlyManual;
TSynLog.Family.HighResolutionTimeStamp := true;
TSynLog.Family.LocalTimeStamp := true;
TSynLog.Family.FileExistsAction := acAppend;
TSynLog.Family.PerThreadLog := ptIdentifiedInOnFile;
TSynLog.Family.RotateFileCount := 100;    // ca. 3 Monate
TSynLog.Family.RotateFileSizeKB := 5000 * 1024;
TSynLog.Family.RotateFileDailyAtHour := 23;
TSynLog.Family.IncludeComputerNameInFileName := true;
TSynLog.Family.DestinationPath := TPath.Combine(ExtractFilePath(Application.ExeName), 'Logs');
TDirectory.CreateDirectory(TSynLog.Family.DestinationPath);
TSynLog.Add.Log(sllTrace, 'Program wurde gestartet');
TSynLog.Add.Log(sllError, 'Error1');
TSynLog.Add.Log(sllError, 'Error2');
TSynLog.Add.Log(sllError, 'Error3');
---
After Error 3 - Later in code

Last edited by itSDS (2022-03-15 19:20:29)

---

Rad Studio 12.1 Santorini

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Re: Logging 1 Line sllError takes 15 Seconds

As you can see Trace=0 works as expected. The Other have Delays.
The 15s Delay is at another Place in the Program where the Stack / Memory Usage is much bigger

Last edited by itSDS (2022-03-15 19:22:51)

---

Rad Studio 12.1 Santorini

ab

Administrator

From: France

Registered: 2010-06-21

Posts: 14,659

Website

Re: Logging 1 Line sllError takes 15 Seconds

Perhaps the problem is that the .map file is recreated each time.

Is the .map file generated by Delphi for your project?
Is the .mab file properly generated by TDebugFile ?

Could you check if it is not TDebugFile.Create which is called by TDebugFile.Log on line 5670 of mormot.core.log which makes the delay.

Edit: Please try https://github.com/synopse/mORMot2/commit/99c7db03

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Re: Logging 1 Line sllError takes 15 Seconds

Hi Arnaud,

i testet the latest commit.
Now OnlyApi is as fast as expected
OnlyManual does take the same time as before.

Last edited by itSDS (2022-03-17 09:20:10)

---

Rad Studio 12.1 Santorini

itSDS

Member

From: Germany

Registered: 2014-04-24

Posts: 516

Re: Logging 1 Line sllError takes 15 Seconds

Perhaps the problem is that the .map file is recreated each time.

Is the .map file generated by Delphi for your project?
Is the .mab file properly generated by TDebugFile ?

Could you check if it is not TDebugFile.Create which is called by TDebugFile.Log on line 5670 of mormot.core.log which makes the delay.

Edit: Please try https://github.com/synopse/mORMot2/commit/99c7db03

Hi Arnaud, i only have the EXE on the Test Machine, no map / mab file.
After starting the App i can not find a mab/map file in the folder.

---

Rad Studio 12.1 Santorini

ab

Administrator

From: France

Registered: 2010-06-21

Posts: 14,659

Website

Re: Logging 1 Line sllError takes 15 Seconds

I have made stOnlyApi the default settings.

Even after some fixes and refactoring, the manual parsing is sometimes incorrect.