Log filtering not working for one module

I’m filtering out error messages and they are correctly filtered in the console shell but are still being sent to Golioth logs.

In the serial console there are no messages between loop 53 and 54

[08:41:33.419,647] <dbg> sm_iot: main: Waiting 558/600 seconds until next read using seed 5
[08:50:51.550,048] <inf> sm_iot: 03-25-24 13:10:06 loop:53 sen:25 deb:16 state:7 pwr:1 rd:600 err:1 sync:5 sstat:3 inst:0 led:0 net:1 gol:1 ota:0 41409ms 3.696v 98.00% -81db
[08:51:33.606,140] <dbg> sm_iot: main: Waiting 557/600 seconds until next read using seed 5
[09:00:51.550,903] <inf> sm_iot: 03-25-24 13:20:06 loop:54 sen:25 deb:16 state:7 pwr:1 rd:600 err:1 sync:5 sstat:3 inst:0 led:0 net:1 gol:1 ota:0 41378ms 3.694v 99.33% -82db

but in the Golioth logs there are

|Today at 8:20:08 AM|INFO|sm_iot|03-25-24 13:20:06 loop:54 sen:25 deb:16 state:7 pwr:1 rd:600 err:1 sync:5 sstat:3 inst:0 led:0 net:1 gol:1 ota:0 41378ms 3.694v 99.33% -82db||
|Today at 8:10:50 AM|DEBUG|sm_iot|main: Waiting 557/600 seconds until next read using seed 5||
|Today at 8:10:10 AM|WARN|ds28e18|Write GPIO Config error ffffffff at line 192||
|Today at 8:10:10 AM|WARN|ds28e18|Send CRC does not match||
|Today at 8:10:08 AM|INFO|sm_iot|03-25-24 13:10:06 loop:53 sen:25 deb:16 state:7 pwr:1 rd:600 err:1 sync:5 sstat:3 inst:0 led:0 net:1 gol:1 ota:0 41409ms 3.696v 98.00% -81db|

They were in both places before I added the line:
log_filter_set(NULL, 0, log_source_id_get("ds28e18"), LOG_LEVEL_ERR);

Most of the other log modules correctly filtered in both places but this one isn’t. Any ideas why?

I’m using [golioth-firmware-sdk] v0.11.1 with nRF Connect SDK v2.5.2 and zephyr-sdk-0.16.5-1

Hey John,

can you try using log_backend_golioth as the backend instance in log_filter_set() instead of NULL?

The code should be as follows:

const char *log_backend_golioth_name = "log_backend_golioth";

const struct log_backend *log_backend_golioth = log_backend_get_by_name(log_backend_golioth_name);

log_filter_set(log_backend_golioth, 0, log_source_id_get("ds28e18"), LOG_LEVEL_ERR);

It seems very inconsistent. Most of the time “log_filter_set(NULL, 0,” filters both the console and Golioth but sometimes it doesn’t.
What should NULL filter out? It’s not clear but all the examples show NULL in the first parameter.
If I want to filter it out in both the console and to Golioth do I need to call log_filter_set twice?

@john.stuewe, using NULL will filter out all logging backends, in this case, the serial console and Golioth. A caveat to this statement is that the log backend instance must be active. The filtering won’t affect the Golioth log backend instance if it is not active (before the connection to the Cloud is established or if the log backend is disabled altogether).

Example:
calling log_filter_set(NULL, 0, log_source_id_get("ds28e18"), LOG_LEVEL_ERR); when the Golioth log instance isn’t active will filter the serial console messages but not the Golioth ones. In the serial console you would see only ERR messages, but in the Golioth Cloud you would see ERR, WRN, INF and DBG messages.

Can you check if you are applying the filter for ds28e18 module when the Golioth log instance isn’t active? This would explain the inconsistencies you’re experiencing.

I start Golioth before filtering the logs but it may not be completely connected so this may be it. Is it safe to filter all the logs in the on_client_event() function? Are all log backends guaranteed to be active on GOLIOTH_CLIENT_EVENT_CONNECTED?

Yes, it is safe to filter all logs in the on_client_event() function because we guarantee that the golioth_log_backend is active on the GOLIOTH_CLIENT_EVENT_CONNECTED event.