Disabling Logging breaks ant_enable() (Softdevice S212)

[Yandrik]

Hello there!

I am working on an ANT+ project, and - as I have taken a fairly unexplored development approach, namely integrating nRF5-SDK Code into a main application written in Rust, I am running into a roadblock.

I need to disable logging, as logging is completely taken care of by the Rust side, and Callbacks into the Rust side are used for logging using the `defmt` logging framework. That part works just fine, but because of that, if logging is enabled on the nRF5-SDK side, a stack overflow happens in the logging code, breaking the program.

I tried disabling logging by setting

#define NRF_SDH_ANT_LOG_LEVEL 0
#define NRF_SDH_ANT_LOG_ENABLED 0
#define NRF_LOG_DEFAULT_LEVEL 0
#define NRF_LOG_ENABLED 0

in various orders (some set to 0, all set to 0, ...). This did exactly what I wanted and disabled logging, but broke the Softdevice Startup Procedure:

void ant_start() {
    info("Starting ANT");
    ant_channel_config_t conf = {
            ...
    };

    info("Enabling Softdevice...");
    ret_code_t ret = nrf_sdh_enable_request();
    APP_ERROR_CHECK(ret);


    ASSERT(nrf_sdh_is_enabled());

    info("Enabling ANT...");

    ret = nrf_sdh_ant_enable();  // works with logging enabled, but returns 0x7 without it
    log_nrf_ret_t("ant enable ret", ret);
    APP_ERROR_CHECK(ret);

    info("Initializing Channel...");
    ret = ant_channel_init(&conf);
    log_nrf_ret_t("Channel initialized.", ret);
    APP_ERROR_CHECK(ret);
}

0x7 seems to be the error code for `Invalid Parameter`, but this line works just fine with logging enabled. However, no matter which way, if `NRF_SDH_ANT_LOG_ENABLED` or any "higher-level" logging configuration value is 0, this breaks.

I have to admit, I'm kind of lost on how to solve this. My two current ideas are to either write a custom logging driver for my Rust-based logging implementation, but as I have never done this, I don't know if this would work. Does that sound like a possible solution? Or is there something I'm overlooking?

Any help would be much appreciated. If you need more information, I'd be happy to supply that too.

Best wishes,

Yannik

[Kenneth]

Not heard of such issue before, sounds like a memory issue/conflict of some kind. 

Even though you have disabled logging, you should be able to single step the code from a debugger during init. Can you just double check the parameters passed to sd_ant_enable() in nrf_sdh_ant_enable() are the same with/without logging?

Kenneth

[Yandrik]

I've stepped through the code, and the results are fairly interesting I believe.

Here's the ant_enable_cfg with NRF_LOG_DEFAULT_LEVEL 0

And here with NRF_LOG_DEFAULT_LEVEL 5

They seem basically the same, ignoring some minor differences. What I found wierd was that NRF_LOG_DEFAULT_LEVEL was 3 in both cases according to my debugger, even tho it is clearly set to a different value in the sdk_config.h.

The even more confusing part however was that the version of the code that is run in the debugger didn't even return an error, but 0, exactly as the version without logs. In other words, it works while debugging, but not while executing without attached debugger. I'm currently checking why that could be, but I haven't found a solution yet.

[Yandrik]

void ant_start() {
    info("Starting ANT");
    ant_channel_config_t conf = {
            ...
    };

    info("Enabling Softdevice...");
    ret_code_t ret = nrf_sdh_enable_request();
    APP_ERROR_CHECK(ret);


    ASSERT(nrf_sdh_is_enabled());

    info("Enabling ANT...");

    for (int i = 0; i < 100000; i++) {  // waste some time
        if (i % 1000 == 0) log_nrf_ret_t("looping", i);
    }
    
    ret = nrf_sdh_ant_enable();
    error("starting...");
    log_nrf_ret_t("ant enable ret", ret);
    APP_ERROR_CHECK(ret);

    info("Initializing Channel...");
    ret = ant_channel_init(&conf);
    log_nrf_ret_t("Channel initialized.", ret);
    APP_ERROR_CHECK(ret);
}

So, wierdly, this works (log_nrf_ret_t ist just to waste more time and give some semblance of the duration).

Seems like the softdevice needs some time to startup or something like that. As I find that rather wierd, I wanted to ask whether I just forgot a step in the startup procedure, or something similar, as this seems to be a somewhat confusing solution, especially considering that the return code is 0x7 (INVALID_PARAM)?

[Yandrik]

I just got a debug run where the error reoccurred by placing a breakpoint only at ANT_ENABLE and nowhere else.

The ant_enable_cfg values seem very messed up, especially considering that they are set nowhere else than in the sdk_config, where NRF_SDH_ANT_TOTAL_CHANNELS_ALLOCATED is 1, and NRF_SDH_ANT_ENCRYPTED_CHANNELS is 0.

Those values seem very off indeed, which explains the 0x7 invalid parameter return code. Any idea why this could be happening? Even with the loop from above it doesn't work reliably while logs are disabled. When they are enabled, the values still seem wierd (see below), but are more reasonable, and therefore the program doesn't blow up.

I find that very confusing, as the values really shouldn't change between runs. You said you believed that to be a memory problem before, and I do agree. How do I find out what exactly the problem is?

[Kenneth]

If you are able to replicate this using one of the supported development IDE (e.g. SES, Keil og IAR) I can look into it, but as it looks now you have an issue with a third party development IDE that is not supported.
https://infocenter.nordicsemi.com/topic/ug_gsg_ses/UG/gsg/intro.html 

Kenneth