logging formatting and rollover

[pjwhite]

Hi, I am really hoping to use the Poco::Logger framework in my application instead of log4cpp. However, there are two features that I am missing, that are "really nice to haves". I am willing to work on them myself, however would love some guidance to see if it would be picked up, and the best way to do it.

Feature 1: Rollover on start.


Basically if the file already exists, but the application is just starting I would love a way to force a rollover.

I was thinking this could be added as a new property of FileChannel called "rollonstart". Initially I was thinking it would ( unfortunately ) a simple bool check in RotateStrategy that would be done as well in mustRotate() which would then be turned off. Alternatively I could do it in FileChannel when doing a 'new LogFile()', which wouldn't affect performance at all, by calling the RotateStrategy with a new method.

Thoughts?

Feature 2: Message Formatting padding

If I have two logger names "main" and "window.dialog.blart", I would really love them to be formatted like this, rather than only the number of characters in each line.

Code: Select all

10-35-43.335 I main                : DoALog
10-35-43.335 I window.dialog.blart : Another log statement!


Almost everyone I work with much prefers this format because we find it easier to read.

Looking at PatternFormatter, I see the large switch statement that actually generates the log message. I would only really need to do this for a few of the format patterns ( ones that have length changes ), like: %s message-source, and %p message-priority ( though %q would work too ). In log4cpp I believe they simply use sprintf type logics, which supports padding, but it will also "crop" so if you set %15s and you log with a catagory name 'window.dialog.blart' the log would look like:

Code: Select all

10-35-43.335 I main            : Do A Log
10-35-43.335 I ...dialog.blart : Another log statement!


Again, any direction and thoughts?

[pjwhite]

Anyone able to give some direction?

[guenter]

These things are not too hard to do. Regarding log file rotation on open, this requires a change to the open() method:

Code: Select all

void FileChannel::open()
{
   FastMutex::ScopedLock lock(_mutex);
   
   if (!_pFile)
   {
      _pFile = new LogFile(_path);
      if (_rotateOnOpen && _pFile->size() > 0)
      {
         try
         {
            _pFile = _pArchiveStrategy->archive(_pFile);
            purge();
         }
         catch (...)
         {
            _pFile = new LogFile(_path);
         }
      }
   }
}


I've left the code handling the rotateOnOpen property as an exercise for the reader.
Regarding the PatternFormatter change, this should not be too hard either. Read the width field and truncate the string accordingly.

[pjwhite]

Ya, the first one is quite simple. I added the property and implemented as you suggested and it works well.

Regarding the PatternFormatter change, this should not be too hard either. Read the width field and truncate the string accordingly.

This is theoretically simple too, but I don't know the best way to find the length because the formatter seems almost hard-coded to read 2 values in the format of %X at a time, with exception of %[prop] fields, which is how I was thinking of doing it:

%x[22] -> Similar to the property method I read out that number and then append/crop the field appropriately.

However, it seems inefficient to parse the string parameter every time, plus if more patterns want fixed widths there is a lot of code duplication. I was trying to think of a way to parse the format string once, and then loop through a vector of 'action structs' that would have the key, the max width, and property name pre-parsed.

Code: Select all

struct FormatAction
{
char key;        // the right side of %s
int   width;     // if applicable to the key
std::string property; // if key == 'x' then this is the property in %[prop]
}

....

for (std::vector<FormatAction> ait = mActions.begin(); ait != mActions.end(); ++ait)
{
     switch (ait->key)
     {
           // similar case statements go here
     }
}


I don't know the overhead of looping over such a vector of structs, and I don't know which way Poco would prefer ( if interested in this ).

Thoughts?

[pjwhite]

So I have implemented my suggested method and it simplifies some code nicely, and actually speeds up logging in certain circumstances (Up to 4x in my tests). As an aside, comparing the performance of logging in poco vs log4cpp it is about twice as fast for the exact same message format, which is great! ( I logged 1000000 lines with poco in 9 seconds, and 18 seconds with log4cpp ).

I have 2 patches for logging ( and 2 patches for compiling on os-x with clang ), but source-forge is acting funny and when I log in I can't see the patches module anymore. I saw there is talk of moving to github, and that things are kinda on hold until after 1.5 release. Anyways, I'll check back in a bit and get them contributed somehow.

Thanks Guenter!