esp_log_level_set() with tag provided as variable has no effect

meowsqueak
Posts: 151
Joined: Thu Jun 15, 2017 4:54 am
Location: New Zealand

esp_log_level_set() with tag provided as variable has no effect

Postby meowsqueak » Mon Jan 28, 2019 10:17 am

For many months I have used code such as:

Code: Select all

esp_log_level_set("mytag", ESP_LOG_DEBUG);
However I'd like to programmatically enable debugging for certain tags in response to certain events. The tag I wish to set is stored in a char *, such that I wish to call:

Code: Select all

void set_debug(char * tag) {
    esp_log_level_set(tag, ESP_LOG_DEBUG);
}
However I've noticed that this does not work, for both stack-allocated and heap-allocated char arrays. It seems that unless the tag is a literal string, the log level is not set for the specified tag. However a string variable with the contents "*" does enable logging for all tags.

Is this a limitation in the way the logging mechanism works?

I'm using ESP-IDF 3.0.6+ (7e0ea6b05db8ad5d1a8dc183414ca8cd456ec934).

EDIT: After inspecting components/log/log.c it seems like a complete mystery to me. There is no macro magic, and the tag parameter is simply compared or copied, so any null-terminated char pointer should work fine.

EDIT2: I've printf-traced through esp_log_level_set() with both a literal tag and a variable tag, and the behaviour seems to be identical. In both cases, it->level is set to the specified level.

meowsqueak
Posts: 151
Joined: Thu Jun 15, 2017 4:54 am
Location: New Zealand

Re: esp_log_level_set() with tag provided as variable has no effect

Postby meowsqueak » Mon Jan 28, 2019 10:38 am

I think I've found the problem - around line 168 in components/log/log.c (in my head of ESP-IDF) there's the following code:

Code: Select all

    //search in the cache and update it if exist         
    for (int i = 0; i < s_log_cache_entry_count; ++i) {
#ifdef LOG_BUILTIN_CHECKS
        assert(i == 0 || s_log_cache[(i - 1) / 2].generation < s_log_cache[i].generation);
#endif
        if (s_log_cache[i].tag == tag) {
            s_log_cache[i].level = level;
            break;
        }
    }
This comparison between s_log_cache[\i].tag and tag doesn't seem right to me, since this tag is previously set by strcpy. For a string literal, the comparison will succeed because the compiler will compare the pointers, which will be the same for literals. I believe this should probably be a strcmp instead.

meowsqueak
Posts: 151
Joined: Thu Jun 15, 2017 4:54 am
Location: New Zealand

Re: esp_log_level_set() with tag provided as variable has no effect

Postby meowsqueak » Mon Jan 28, 2019 10:54 am

I'm not 100% sure why it works with literal tags (new_entry->tag is not set to tag anywhere I can see) however I've tested my fix and posted it as a pull request here: https://github.com/espressif/esp-idf/pull/2996

meowsqueak
Posts: 151
Joined: Thu Jun 15, 2017 4:54 am
Location: New Zealand

Re: esp_log_level_set() with tag provided as variable has no effect

Postby meowsqueak » Mon Jan 28, 2019 11:02 am

Looks like this was fixed a little over a year ago on the master branch, but the fix has not made its way into 3.0.7. It is in 3.1 though.

Who is online

Users browsing this forum: ESP_Sprite and 203 guests