8

I've been testing three options for my logging subsystem in C++. One is Log4cplus, one is Pantheios and the last one is a simple logging library that we have written ourselves.

Log4cplus has been much slower than the other two. Here are the results for logging 1,000,000 log entries:

  • log4cplus: 200 seconds EDIT: setting the buffer size reduced it to 120 seconds
  • mylogger: 55 seconds
  • Pantheios: 35 seconds

I'm wondering if I'm missing any performance tuning.

I should add that I'm always using the root logger, I'm logging to file and logging: LOG4CPLUS_INFO(rootLogger, "Replace me with the text!");

thanks, Reza

ДМИТРИЙ МАЛИКОВ
  • 21,474
  • 11
  • 78
  • 131
RezaPlusPlus
  • 545
  • 1
  • 8
  • 18
  • 1
    Can you post the Log4cplus configuration and how you obtained the rootLogger? – Andrew T Finnell Sep 07 '11 at 18:07
  • @RezaPlusPlus: Also, what version of log4cplus are you using? – wilx Sep 07 '11 at 18:13
  • Here's the configuration: `log4cplus.rootLogger=INFO, R log4cplus.appender.R=log4cplus::FileAppender log4cplus.appender.R.File=c:\logs\log4cplusLog.log` and I get the root logger as: rootLogger = log4cplus::Logger::getRoot(); – RezaPlusPlus Sep 07 '11 at 18:18

1 Answers1

12

Using log4cplus::NullAppender in the performance_test gives me Logging 1000000 took: 4sec 343709usec on semi-loaded FreeBSD server. IOW, the pure logging overhead is rather small. Your logging timings seem to depend on the target logger. If you are using log4cplus::FileAppender, the timings will be significantly different.

EDIT:

You need to tune the FileAppender a little bit. Make sure that you set the ImmediateFlush property to false. You could also set up BufferSize to something bigger, like 1000000 bytes.

wilx
  • 17,697
  • 6
  • 59
  • 114
  • Well at the end, I'm going to use the FileAppender. Does it mean that I should write my own fileappender to make it faster? – RezaPlusPlus Sep 07 '11 at 18:22
  • 1
    @RezaPlusPlus: Speed is always not the most important thing. Some people prefer reliable logs in case of crash, hence the default for `ImmediateFlush` is `true`. – wilx Sep 07 '11 at 18:29
  • Good point. But I guess my other two libraries will do the same. They also write to the file and flush the buffer to file. Can it be because of this line `return (stream << log4cplus::helpers::towstring(str)); ` that log4cplus tries to convert every string to wide characters? I'm just guessing :p I was hoping to find some tuning like this one – RezaPlusPlus Sep 07 '11 at 18:33
  • OK. Changing the buffersize reduces the time to 120 seconds. That's a little better. – RezaPlusPlus Sep 07 '11 at 18:41
  • 1
    @RezaPlusPlus: Where do you see that line? File `stringhelper.cxx`? That line is effective only if you use UNICODE builds and do output of plain char strings. If you do use UNICODE builds of log4cplus and of your application, use `L"text"` string literals or wrap the string literals into `_T()` (on Windows) or `LOG4CPLUS_TEXT()`. – wilx Sep 07 '11 at 20:16
  • Yeap! correct. But at the end, it seems to me that the real difference is because of the FileAppender logger. Pantheios seems to be able to write to files way faster than the streams that log4cplus uses. If I want to confirm this, I should use the NullAppender instead of FileAppender, right? And I should expect it not to take too much time. If so, I may end up writing my own appender for log4cplus. – RezaPlusPlus Sep 07 '11 at 23:37
  • If you're using NullAppender, then you should use Pantheios' be.null back-end (which is also a bit-bucket) – dcw Sep 08 '11 at 00:31
  • @rezaPlusPlus: My point of using `NullAppender` to get the timing was to show that the formatting overhead is not that big and that the main overhead is in the logger that you have used. – wilx Sep 08 '11 at 04:52
  • @RezaPlusPlus: You have mentioned that you have changed the buffer size. Have you also changed the `ImmediateFlush` to `false` or is the 120 seconds for both `ImmediateFlush=false` and changed buffer size? – wilx Sep 08 '11 at 04:54
  • @wilx I didn't want to set the immediateflush to false, as I also prefer having more reliable logs. Again, I think log4cplus is slower as it uses streams for writing the logs (correct me please if I'm wrong) and Pantheios uses the FastFormat library. My simple logging library also uses fprintf which seems to be faster than C++ streams. – RezaPlusPlus Sep 08 '11 at 06:15
  • @dcw: I used the nullAppender for log4cplus and it again took relatively long time. I'm starting to doubt that I have a bug in my simple performance testing code – RezaPlusPlus Sep 08 '11 at 06:16
  • @RezaPlusPlus: Let us see the code that you use for the benchmarking, please. – wilx Sep 08 '11 at 07:23
  • Thanks very much @Wilx. How should I put the code here? Shall I edit my post or add an answer? – RezaPlusPlus Sep 08 '11 at 18:42
  • @RezaPlusPlus: I guess that editing the post makes more sense. – wilx Sep 10 '11 at 09:22