nRF Cloud Log backend doesn't filter unwanted messages generated as a side effect of sending other log messages

[ragruslan]

Hi!

We use nRF Cloud Log backend in our project. And during my research I found that it actually doesn't filter (despite the filtering code is there) messages generated by underlying libs when application log messages are sent to the cloud. This creates an endless stream of messages being sent to the cloud, even if the application is no longer logging messages.

It seems, I see a confirmation for this issue in the code. Here logger_init() is called, it sets up filtering by calling log_filter_set(..., 0) for every source that needs to be filtered out, and then log_backend_enable() is called which actually resets filtering by calling log_filter_set(..., level) for all sources registered in the logger.

My SDK version is 2.9.0. But I see that this code hasn't been changed since that version.

My configuration contains:

CONFIG_LOG_RUNTIME_FILTERING=y

CONFIG_NRF_CLOUD_LOG_BACKEND=y

# This option leads to sending endless messages like this "Sent lines:516, bytes:70952"

CONFIG_NRF_CLOUD_LOG_LOG_LEVEL_INF=y

 

This issue is currently not critical for our project.

Thank you!

[dejans]

Hi,

You have set quite high level for log messages. You can refer to logging configuration. You can try to reduce the level of logging for messages that are sent to nRF Cloud using CONFIG_NRF_CLOUD_LOG_OUTPUT_LEVEL. You can read more about nRF Cloud Logging in the documentation.

Best regards,
Dejan

[ragruslan]

The root of the issue is not in the high log level (this is actually the default log level). Please, look a bit deeper: there is a list of log sources which must be filtered out - regardless of their log levels. But they are not filtered out if CONFIG_LOG_RUNTIME_FILTERING=y.

Regards,
Ruslan

[dejans]

Hi Ruslan,

We are investigating this issue. I will get back to you with status update by the end of the week.

Best regards,
Dejan

[dejans]

Hi Ruslan,

I have discussed your reported issue with our developers. 
We have checked internally that nRF Cloud Multi Service sample using CoAP does allow to filter the information. However, it is not very responsive (as it takes around 120 seconds to change the filter value). The filtering happens on the device through device shadow. The cloud sends the filter state to the device (c2d) and the device aligns the cloud logging to that. You need to look at how this is implemented in multi_service sample and implement it in your project.

Best regards,
Dejan

[ragruslan]

Hi Dejan,

There seems to be a misunderstanding...

Did you open the links I provided in my messages? Can you please explain what this array/list is for?

Regards,
Ruslan

[dejans]

Hi Ruslan,

CONFIG_LOG_RUNTIME_FILTERING is used for fine run-time control of log levels for each logging source. You can get more information in configuration documentation.

# This option leads to sending endless messages like this "Sent lines:516, bytes:70952"

CONFIG_NRF_CLOUD_LOG_LOG_LEVEL_INF=y

Is it correct that this endless stream of messages is sent from device and observed on nRF Cloud? Do you see these messages in the Logs tab for your device in nRF Cloud?

Can you provide more information about your application?

Is it correct that you want to filter the messages that you can see on nRF Cloud? 

Which logging settings in your device shadow are there on the nRF Cloud?

You could try to set log level on nRF Cloud (see using device logs in nRF Cloud) and that should change current shadow, but you also need to have some logic on the device side to update its state based on existing shadow when the device connects to nRF Cloud next time. 

Best regards,
Dejan

[Alexey Kos]

Hi Dejan,

Ruslan is talking about a possible bug in the code - in the nrf_cloud_log_backend.c file.
And in my opinion, he well described the issue in the very first message in this thread.
Briefly:
- There is some code to prevent an endless sending of log messages.
- It uses filtering of logs from some sources. The filtered_modules array defines these sources.
- But there seems an issue in the code - in the logs_backend_enable() function - logger_init() sets the mentioned filtering, but right after that log_backend_enable() resets it. So, the needed filtering does not work.
Did your developers review this piece of code?
Can they confirm there is the issue or explain if there no issue?

Again, the question is about the code (nrf_cloud_log_backend.c and related files). Pls return to the first message in this thread.
The question is not about using/configuring the logging, configuration settings, etc.

Thanks,
-Alexey

[dejans]

Hi Alexey,

Alexey Kos said:

Did your developers review this piece of code?
Can they confirm there is the issue or explain if there no issue?

Our developers have tested nrf_cloud_multi_service sample and confirmed that this feature works in the sample as expected. You can look at relevant implementation in the nrf_cloud_multi_service sample.

Best regards,
Dejan

[Alexey Kos]

Unfortunately, it does not answer our question ;(

Is there a bug tracking system where we can submit a bug?

And/or is there a way to discuss the question directly with developer(s)?

Regards,
-Alexey

[dejans]

Hi Alexey,

It is still not quite clear why you think there might be a bug. Is this issue reproducible?
In order to confirm that this is a bug, can you provide a minimal sample (or use one of existing NCS samples such as multi_service sample) which demonstrates this issue and additional description of what is expected to happen and what actually happens?

Best regards,
Dejan