How can I log which thread called which function from which class and at what time throughout my whole project?

Question

Hello,

I am working on a fairly large project that runs on embedded systems. I would like to add the capability of logging which thread called which function from which class and at what time. E.g., here's what a typical line of the log file would look like:

Time - Thread Name - Function Name - Class Name

I know that I can do this by using the _penter hook function, which would execute at the beginning of every function called within my project (Source: http://msdn.microsoft.com/en-us/library/c63a9b7h%28VS.80%29.aspx). I could then find a library that would help me find the function, class, and thread from which _penter was called. However, I cannot use this solution since it is VC++ specific.

Is there a different way of doing this that would be supported by non-VC++ implementations? I am using the ARM/Thumb C/C++ Compiler, RVCT3.1. Additionally, is there a better way of tracking problems that may arise from multithreading?

Thank you,

Borys

Answer 1

I've worked with a system that had similar requirements (ARM embedded device). We had to build much of it from scratch, but we used some CodeWarrior stuff to do it, and then the map file for the function name lookup.

With CodeWarrior, you can get some code inserted into the start and end of each function, and using that, you can track when you enter each function, and when you switch threads. We used assembly, and you might have to as well, but it's easier than you think. One of your registers will be your return value, which is a hex value. If you compile with a map file, you can then use that hex value to look up the (mangled) name of that function. You can find the class name in the function name.

But, basically, get yourself a stream to somewhere (ideally to a desktop), and yell to the stream:

Entered Function #####

Left Function #####

Switched to Thread #

(PS - Actual encoding should be more like 1 21361987236, 2 1238721312, since you don't actually want to send characters)

If you're only ever processing one thread at a time, this should give you an accurate record of where you went, in the order you went there. Attach clock tick info for function profiling, add a message for allocations (and deallocations) and you get memory tracking.

If you're actually running multiple threads, it could get substantially harder, or be more of the same - I don't know. I'd put timing information on everything, and then have a separate stream for each thread. Although you might just be able to detect which processor you're running on, and report that, for which thread.... I don't, however, know if any of that will work.

Still, the basic idea was: Report on each step (function entry/exit, thread switching, and allocation), and then re-assemble the information you care about on the desktop side, where you have processing to spare.

Answer 2

gcc has PRETTY_FUNCTION define. With regard to thread, you can always call gettid or similar.

Answer 3

I've written a few log systems that just increment a thread # and store in in thread-local-data. That helps with giving thread of log statements. (time is easy to print out)

For tracing all function calls automatically, I'm not so sure. If it's just a few, you can easily write an object & macro that logs entry/exit using the __FUNCNAME__ #define (or something sim ilar for your compiler).