A simple logger

Hi there –

Recently in our project we had the need for a simple logger system. I did not want to use mbed_trace for several reasons:

  • We find it unnecessarily cumbersome, but that’s some personal preference
  • We did not want to be tightly coupled with mbed for that
  • We wanted to customize the output format with a timestamp, file location, function name, etc.
  • mbed_trace is not interrupt safe

The last point is important: we wanted something interrupt safe and something that would not impact the normal flow of the program.

To achieve this, we use a dedicated low priority thread, an event queue and a circular buffer. The circular buffer is filed with fully formatted and timestamped messages. Printing is deferred with the event queue and the low priority thread only runs when nothing else is happening.

The output looks like this:

008:15:12:345 [DBUG] [LogKit_test_log.cpp:99] FunctionName > Hello, World. 42 FTW!

The library is designed for our needs, so it’s not really usable as is, but it’s can be easily modified to work for other projects.

You can find it here:

CMakeLists.txt and unit tests are available here: LekaOS/libs/LogKit at develop · leka/LekaOS · GitHub

The circular buffer is a rework of mbed’s, that you can find here: LekaOS/CircularQueue.h at develop · leka/LekaOS · GitHub

We also compared the use of printf vs serial.write. As expected serial.write is much faster.

Here is the test program: LekaOS/spikes/lk_log_kit at develop · leka/LekaOS · GitHub

On our system, using the STM32F769, results are as follow:

  • LogKit with full output formatting (timestamp, filename, function name, etc.) - 3942 characters in 2ms
  • printf for the same message but without the full output formatting (no timestamp, no filename, no function name, etc.) - 1261 characters in 119ms

This means that LogKit is 186 times faster / character than printf. This allows us to use it to debug stuff such as getting the frame rate in jpeg video decoding with no impact on the performance.

I hope this can be helpful to others.

Feel free to ask any questions if something’s not clear.

Happy Holidays!
– Ladislas

2 Likes

Nice work, very interesting. I will give it a try. As far as I saw in your example, it should be easy to migrate from mbed_trace to this.

Have you thought about making a PR in mbed-os?

migration in terms of find and replace will be easy, but having LogKit compiling in your setup might take a little more time.

To replace/improve mbed_trace you mean?

I think they serve different purposes: mbed_trace is the internal logger for mbed, which is good as long as it stays there. I’m not sure it’s a good idea to sprinkle your own code base which such things as they create a tight coupling with mbed.

LogKit is a logger for (our) user code. It’s very opinionated, easily customizable but you need to modify the source code. It could be made customizable with macros/defines but as we don’t need it, I haven’t implemented it.

It can be turned on/off, but for the moment your can’t define a minimum log level (say only display error messages). We might add the feature in the future, not sure yet.

Our philosophy is that errors/info logs should only be present in the main code, not in libs/drivers. debug can be used to debug code being written anywhere but must be removed once everything is working as expected.

Have time to test it