Post

Thread Logging Macro

I was working on a project recently for a client where I suspected a race condition between threads accessing the same section of code. I came across this very simple logging macro which allows you to wrap the standard logging output with some extra information about the thread it is called from. I put it in a header file of it’s own that I can include anywhere.

1
2
3
4
5
6
7
8
9
10
#pragma once

#include <esp_log.h>

#define THREAD_LOG(tag, format, ...) \
    ESP_LOGI(tag, "[%s:%d][Core:%d] " format, \
    pcTaskGetName(NULL), \
    (int)xTaskGetTickCount(), \
    xPortGetCoreID(), \
    ##__VA_ARGS__);

And here is an example usage.

1
2
3
4
5
6
7
8
#include "thread_logger.h"

RTC_DATA_ATTR int boot_count = 0;
// ...
// Other code here
// ...

THREAD_LOG("main", "The boot count is %d", boot_count);

And here is the output you will see:

1
I (623) main: [main:1][Core:0] The boot count is 4

You still get the classic TAG info which is the first main followed by added formatting of the thread name(in this case also “main”), how many ticks the thread has been active, and the core it’s running on.

Yes, step debugging is always the gold standard but sometimes a simple log output with the right information will do the trick.

© Kevin Sidwar