The Design of Software (CLOSED)

A public forum for discussing the design of software, from the user interface to the code architecture. Now closed.

The "Design of Software" discussion group has been merged with the main Joel on Software discussion group.

The archives will remain online indefinitely.

Non-intrusive logging

I'm working on a C/C++ application that is extremely sensitive; performance is absolutely critical, multiple processes/threads, timing is GPS/NTP synchronized, etc.

We're running into some difficulties with some of the debugging, and I suspect that the state logging is partly to blame. Currently there is a logging framework, but there are also multiple printf's to stdout/stderr. This logging is used partly because tools like Valgrind affect performance far too much.

I'd really like to minimize this, as well as establish a more robust system for tracking state messages. My thoughts are running towards having a seperate application/process that takes all of these messages in a queue, and sockets them over to a seperate queue located on a separate workstation. At that point I'd likely have a Java app that would be used for displaying and filtering these log messages.

The socket layer would be written in C++ since we have the libaries for this. Does anyone else have some experience in this? Can the stdout/stderr streams be easily redirected to a queue/stream that can be sent out by a low-priority process?

Open to all suggestions.
Sunday, October 03, 2004
One time-saver is to minimize the amount of logging ... perhaps by having different levels (the most detailed level being more for debugging than for performance tuning), and being able to selectively enable logging for different modules.

Storing real-time log events on a RAM queue sounds like a good idea (I couldn't think of a better); as a C++ programmer you probably know how to do that efficiently: minimizing the associated locks and heap allocations, for example.

When I did it I didn't bother writing the log to a separate process: I just buffered everything in RAM for the duration of the (short) test, and dumped the RAM to disk as a post-test stage.

I don't know enough about Linux to answer your question about stdout/stderr ... if you can redirect them to file, perhaps you can redirect them to a memory mapped file that's shared with another process ... it's possible that would be more intrusive than writing to private RAM within your own process, though.

You might also consider hacking the printf statements, to make them use your less-intrusive looging framework, either by using global search-and-replace or by using a "#define printf" macro.
Christopher Wells Send private email
Sunday, October 03, 2004
Good ideas, Christopher. We do actually try to minimize the logging output: there are a number of run-time settings for just this purpose.

The issue in this case is not so much the 'regular' logging output, but the debugging output that has been put in. It's impossible to run the app in a debugger (gdb/ddd), so that seemed to be the quickest route.

The shared memory is an option, but I've had mixed experiences with that in the past. Seemed to be rather fickle.

I suspect that the printf's are messing with the kernel scheduling as well, so I'm looking for a nice/neat way of cleaning that up, with as little change to the code as possible. I don't know enough about this subject to say exactly what my needs are, so feel free to speak your mind...
Sunday, October 03, 2004
Apart from adding a "#define printf something" to a top-level header file, might it also work to implement your own printf function? Perhaps then the linker would link in your version of printf, and subsequently not also try to link in the regular printf from wherever it normally finds it (i.e. the run library or the O/S).
Christopher Wells Send private email
Sunday, October 03, 2004
Some ideas:

- Consider having one log per thread.  (E.g. one buffer/socket/file per thread).  All your locking disappears.  This may be trickier if you create threads on the fly, but will be fine if you know you always have N threads.

- Consider using a circular buffer for logging output, and have another thread read that circular buffer and output it.  When the buffer is full, don't block, just lose some log messages (perhaps with a message that you need to make the buffer bigger next time!).  If you read and set the write pointer atomically (and frankly on most modern systems it's hard _not_ to do that), and you have one buffer per writer thread (see previous point), then you can get away without any locking.

You only need one reader thread for all your log buffers, that reads the buffers and writes to a socket/file/whatever.  You'll have to set that thread to fairly low priority so it doesn't interfere with the rest of the system but it still gets run.  If you can throw lots of RAM at the problem then you don't have to run the thread very often.

Sunday, October 03, 2004
Thanks for the ideas, Jon. This isn't going to be released, so adjusting buffer sizes to suit is fine. Can't allocate new memory on the fly anyways, so that fits well.

Agreed on the reader priority. Viewing logs in real-time is not a requirement.
Sunday, October 03, 2004
printf is unbelievably slow. At one point we reimplemented it, including only the formats we needed (int, string, 0-padded hex for pointer, fixed precision float), exactly for the same purposes - logging got too slow. The replacement function, thrown together in a couple of hours, was over 10x faster than stock printf for our logs!
Ivan-Assen Ivanov Send private email
Monday, October 04, 2004
Take a look at CodeTest (a Metroworks product). Its tools (requires a modified compile step) will instrument the functions within modules, and write to dual ported memory for each function call. You can extract all kinds of interesting data.

I do not work for Metroworks. We happen to use the product, and its pretty cool.
hoser Send private email
Monday, October 04, 2004
> printf is unbelievably slow

For maximum speed consider implementing multiple functions that just log strings, or string plus one int -- things like that. You are trading complexity (multiple functions) for speed.

Example: Instead of

  printf("%s: %d\n", "The frobnitz has an error code: ",

  LogStringAndInt("The frobnitz has an error code",

where the LogXXX has a built in call to something along the lines if itoa().
frustrated Send private email
Monday, October 04, 2004
Hi There. Why can't you run your app in gdb? Because of threads? Gdb is very powerful and worthwhile to learn. I had to write a basic client/server program(s) once and at first it was very hard to learn how to use gdb, but after a while it was very useful.

Could you explain more on how your app is structured and why you need so many debugging message?

Chris Bruyere Send private email
Tuesday, October 05, 2004
It's a real-time system, and can't be slowed down or paused in any way at all.

I do use gdb very often, but not in this case.
William Send private email
Tuesday, October 05, 2004
I like frustrated's idea- except couldn't you just overload printf so the call would be identical.  I guess that depends on whether the compiler will automatically select




Anyone know if this works?
Ken Send private email
Wednesday, October 06, 2004
My guess is that you're not allowed to overload functions that are declared as extern "C".
Christopher Wells Send private email
Wednesday, October 06, 2004

This topic is archived. No further replies will be accepted.

Other recent topics Other recent topics
Powered by FogBugz