How to do Better Logging

When you're working on Embedded firmware or low level development, it's important to have a proper logging system in place. Logging helps with debugging, tracking values and monitoring the system for the health. But there are situations where we need to disable all logs; let's say for a release or for performance benchmarking.

What easily comes to mind is to comment out all the printf statements and recompiling. But, imagine a codebase with hundreds of thousands of logs. It will get quite tedious to get rid of all the logs, and it's also easy to miss some.

Another option would be to wrap all printf statements with an ifdef. For example:

#include <stdio.h>

#define DEBUG

int main() {
#ifdef DEBUG
    printf("Hello...");
#endif
}

If DEBUG is defined, printf will be there and when it's not, the printf will not be there in the final compiled binary.

But this is also quite inefficient. Imagine having to write three lines instead of one for a simple print statement, not to mention the complication of a trivial task like printing a message. The reason that I'm telling this is that there's a better option.

What if instead of directly using printf, we create a macro to transform it into some other form, but then we use another macro to select which form that we're using? This is exactly where the optimum way to do logging lies. Here's a sample code:

#include <stdio.h>

#define DEBUG 1

#if DEBUG
    #define LOG(fmt, ...) printf(fmt "\n", ##__VA_ARGS__)
#else
    #define LOG(fmt, ...) 
#endif

int main() {
    int connection_count = 5;
    
    LOG("Server started successfully.");
    LOG("Current connections: %d", connection_count);

    return 0;
}

Notice how there's an if macro which chooses between two forms for a function we define as LOG(fmt, ...). In case DEBUG is 1, it automatically turns into printf(fmt "\n", ##__VA_ARGS__), the printf we know and love. But if it's 0, it turns into nothing. This creates a simple, efficient and clean way to enable and disable logs. You just have to write LOG(...) like you're used to and then define DEBUG as 1 or 0 to enable or disable the logging.

The keen eyed among you might worry if this might end up with unwanted instructions in your code. The thing is, modern compilers will happily compile this code without any overhead. Still don't believe me? Checkout this sample code in Compiler Explorer: https://godbolt.org/z/3c4qfvM3E.

The assembly for the case of DEBUG is 1 turns out to be:

.LC0:
        .string "Server started successfully."
.LC1:
        .string "Current connections: %d\n"
main:
        sub     rsp, 8
        mov     edi, OFFSET FLAT:.LC0
        call    puts
        mov     esi, 5
        mov     edi, OFFSET FLAT:.LC1
        xor     eax, eax
        call    printf
        xor     eax, eax
        add     rsp, 8
        ret

Try turning DEBUG to 0 and see the compilation. It will turn out to be:

main:
        xor     eax, eax
        ret

As you can see, the whole logging statements disappeared without any residual code.

Thus, we can see that this eliminates all the issues we had with the previous two methods. In fact most modern code uses this technique for logging. So make sure to use this in your next project.