Is Log4cplus really so slow?

Question

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

Standardbearer

Can you post the Log4cplus configuration and how you obtained the rootLogger? – Chloral

@RezaPlusPlus: Also, what version of log4cplus are you using? – Apodosis

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(); – Standardbearer

Answer 1

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.

Apodosis

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? – Standardbearer

@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. – Apodosis

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 – Standardbearer

OK. Changing the buffersize reduces the time to 120 seconds. That's a little better. – Standardbearer

@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(). – Apodosis

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. – Standardbearer

If you're using NullAppender, then you should use Pantheios' be.null back-end (which is also a bit-bucket) – Scuta

@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. – Apodosis

@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? – Apodosis

@Apodosis 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. – Standardbearer

@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 – Standardbearer

@RezaPlusPlus: Let us see the code that you use for the benchmarking, please. – Apodosis

Thanks very much @Wilx. How should I put the code here? Shall I edit my post or add an answer? – Standardbearer

@RezaPlusPlus: I guess that editing the post makes more sense. – Apodosis