Overview
Examples
Screenshots
Comparisons
Applications
Download
Documentation
Tutorials
Bazaar
Status & Roadmap
FAQ
Authors & License
Forums
Funding Ultimate++
Search on this site
Search in forums












SourceForge.net Logo
Home » Community » U++ community news and announcements » U++ logging refactored
U++ logging refactored [message #36754] Mon, 02 July 2012 17:34 Go to next message
mirek is currently offline  mirek
Messages: 13975
Registered: November 2005
Ultimate Member
While finishing Skylark, I have found certain features of U++ logging inadequate.

First of all, output from multiple threads depended on locks in LOGing macros, which was fine for macros, but e.g. Sql is not using these macros (and thus MT logging was basically broken in Sql). Fixed by complete refactoring of LogStream, which is now handling locking internally (serializes issuing completed lines to the output).

The I have removed secondary logs UsrLog and BugLog and integrated them to the main log output.

I have added new standard log options:

LOG_SYS - in Posix, log is outputed to syslog too.
LOG_ROTATE(n) - when .log file is about to be replaced, up to 'n' older logs are preserved (using file extensions '.1', '.2', ... '.n').
LOG_ROTATE_GZIP - preserved logs '.2' and higher are gzipped.

I have also introduced a new concept, 'modular' logging, which usually should be bound to program config (e.g. .ini file) and immediately used it to replace UsrLog concept (two lines of code better than 300 words :):

#define LOG_(flag, x) do { if(flag) RLOG(x); } while(false)

namespace Ini {
extern Bool user_log;
};

#define USRLOG(x) LOG_(Ini::user_log, x)

Last but not least, logging is now documented Smile

UPDATE: Config->Ini

[Updated on: Tue, 03 July 2012 09:57]

Report message to a moderator

Re: U++ logging refactored [message #36760 is a reply to message #36754] Tue, 03 July 2012 08:38 Go to previous messageGo to next message
Zbych is currently offline  Zbych
Messages: 325
Registered: July 2009
Senior Member
If it is not a problem, can you add UTC timestamp (LOG_TIMESTAMP_UTC)?
Re: U++ logging refactored [message #36762 is a reply to message #36760] Tue, 03 July 2012 09:47 Go to previous messageGo to next message
mirek is currently offline  mirek
Messages: 13975
Registered: November 2005
Ultimate Member
Done.
Re: U++ logging refactored [message #36764 is a reply to message #36762] Tue, 03 July 2012 10:24 Go to previous messageGo to next message
Zbych is currently offline  Zbych
Messages: 325
Registered: July 2009
Senior Member
Thanks.
Re: U++ logging refactored [message #36801 is a reply to message #36754] Fri, 06 July 2012 19:19 Go to previous messageGo to next message
dolik.rce is currently offline  dolik.rce
Messages: 1789
Registered: August 2008
Location: Czech Republic
Ultimate Contributor

Hi Mirek,

I think there is a bug in the refactored logging - or maybe it is a feature Smile The logging is now not "atomic", e.g.:
bool fn(){
	LOG("fn called");
	return true;
}

GUI_APP_MAIN{
	DUMP(fn());
};

produces
fn() = fn called
true

That is IMHO wrong behavior.

Best regards,
Honza
Re: U++ logging refactored [message #36806 is a reply to message #36801] Sat, 07 July 2012 11:54 Go to previous messageGo to next message
mirek is currently offline  mirek
Messages: 13975
Registered: November 2005
Ultimate Member
This is nothing new, it was always working this way.

It is possible to fix it, but with somewhat lowered performance (because we would need to create String first, then output to stream, now everything goes directly to stream).

Not sure it is worth it...

(Note that MT behaviour is fine, it is "non-atomic" only in single thread).
Re: U++ logging refactored [message #36807 is a reply to message #36806] Sat, 07 July 2012 12:22 Go to previous messageGo to next message
dolik.rce is currently offline  dolik.rce
Messages: 1789
Registered: August 2008
Location: Czech Republic
Ultimate Contributor

mirek wrote on Sat, 07 July 2012 11:54

This is nothing new, it was always working this way.

It is possible to fix it, but with somewhat lowered performance (because we would need to create String first, then output to stream, now everything goes directly to stream).

Not sure it is worth it...

(Note that MT behaviour is fine, it is "non-atomic" only in single thread).


Hm, interesting, I never noticed before... I think that when using logging for debug purposes, the performance is not important. Would it be possible to add some mechanism that would allow to differentiate between debug logging and other cases?

The simple way that comes to my mind is to make it work fast in release mode and correct in debug, but that might lead to confusion in the non-debug usage. What about a flag/macro, that would let me say "now I want to use the 'atomic' logging"? It could even work on per file basis...

Honza
Re: U++ logging refactored [message #36808 is a reply to message #36807] Sat, 07 July 2012 13:01 Go to previous messageGo to next message
mirek is currently offline  mirek
Messages: 13975
Registered: November 2005
Ultimate Member
dolik.rce wrote on Sat, 07 July 2012 06:22

mirek wrote on Sat, 07 July 2012 11:54

This is nothing new, it was always working this way.

It is possible to fix it, but with somewhat lowered performance (because we would need to create String first, then output to stream, now everything goes directly to stream).

Not sure it is worth it...

(Note that MT behaviour is fine, it is "non-atomic" only in single thread).


Hm, interesting, I never noticed before... I think that when using logging for debug purposes



But the changes in logging are intended for logging even for production purposes...

Mirek
Re: U++ logging refactored [message #36810 is a reply to message #36808] Sat, 07 July 2012 13:54 Go to previous messageGo to next message
dolik.rce is currently offline  dolik.rce
Messages: 1789
Registered: August 2008
Location: Czech Republic
Ultimate Contributor

mirek wrote on Sat, 07 July 2012 13:01

But the changes in logging are intended for logging even for production purposes...

Mirek

I'm aware of that, that is why I was thinking about doing it settable - to allow the current, high performance version where needed.

Honza
Re: U++ logging refactored [message #38210 is a reply to message #36754] Thu, 06 December 2012 12:41 Go to previous messageGo to next message
NilaT is currently offline  NilaT
Messages: 70
Registered: November 2011
Location: Austria
Member
Hello,

and sorry for digging out this old thread again but I have a question to the new logging feature.

A few days ago I went from 2010 source to 2012 and saw, that UsrLog and BugLog etc. isn't available anymore.
I searched and luckily found this thread.

In my program I added "StdLogSetup(LOG_FILE | LOG_TIMESTAMP, sFile);" as suggested in here:
http://www.ultimatepp.org/src$Core$Logging$en-us.html

BUT, how do I create two different logfiles?
I want files with the .log extension and another with .buglog or something.
In 2010 source I used a USRLOG or BUGLOG Macro which get me UsrLog() in Debug.cpp

But now it's a bit more complicated with struct IniBool and stuff... (don't know exactly what the user_log flag is for, but as it seems LOG_ calls RLOG calls UPP::VppLog calls UppLog calls StdLog calls StdLogStream)

Seems like I have to add a new Stream Method oder something?
Any help appreciated.

Thanks.

[Updated on: Thu, 06 December 2012 12:47]

Report message to a moderator

Re: U++ logging refactored [message #38211 is a reply to message #38210] Thu, 06 December 2012 12:45 Go to previous messageGo to next message
mirek is currently offline  mirek
Messages: 13975
Registered: November 2005
Ultimate Member
I am sorry, but UsrLog and BugLog were removed.

I think you can easily bring them back for your code even with USRLOG and BUGLOG macros. Even copying from 2010 sources might work.

Maybe we should this BW support to bazaar?

Mirek
Re: U++ logging refactored [message #38390 is a reply to message #36754] Thu, 13 December 2012 13:37 Go to previous message
NilaT is currently offline  NilaT
Messages: 70
Registered: November 2011
Location: Austria
Member
Hello,

well I tried it, but I gave up.
Now I'm doing the following:

Mutex LogFileMutex;

void WriteLogfile(String text) {
 LogFileMutex.Enter();
 Time zeit = GetSysTime();
 String zt = Format("[%i/%i/%i/ %i:%i:%i]", zeit.day, zeit.month, zeit.year, zeit.hour, zeit.minute, zeit.second);
 FileAppend file(m_LogFilename);
 file.PutLine(Format("%s %s", zt, text));
 file.Close();
 LogFileMutex.Leave();
}

[Updated on: Thu, 13 December 2012 13:41]

Report message to a moderator

Previous Topic: SQL refactored, adding per-thread option, added second SQLR
Next Topic: MySql now supports reconnection features
Goto Forum:
  


Current Time: Fri Apr 19 01:31:07 CEST 2024

Total time taken to generate the page: 1.07019 seconds