• State Not Answered
  • Replies 15 replies
  • Subscribers 77 subscribers
  • Views 746 views
  • Users 0 members are here
Attachments (0)
Nordic Case Info
  • Case ID: 346186
Options

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!

Parents
  • 0

    Hello Alexey,

    I sent you an email early this week, let me know if this is still an issue.

    Regards,

    Pascal.

  • 0 in reply to Pascal Hdz

    Hi Pascal,
    Thanks for your email. We (Ruslan) has found it ;)
    - The question is not critical for our current project but we would like to clarify it anyway.
    - It is not related to the cloud logging configuration/filtering/etc. It is related to the source code.
    - We use the SDK code (including the nrf_cloud_log_backend.c file) in our project, so we looked at that source code and have this question.
    - It is formulated in the original post in this thread. Pls have a look at it.
    - Just to repeat it 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.
    - Can you please review that source code and either confirm there is the issue, or explain how it works if the code is correct.
    - We will try to reproduce the issue on practice, but will need to find time for that.
    Thank you!
    -Alexey

  • 0 in reply to Alexey Kos

    Hello Alexey,

    This is a feature that leverage Zephyr's Logging subsystem. nRF Cloud received the logging and displays it in the Logs Card. This is also available for binary logging for a smaller memory footprint.

    The Logs card's UI allows you to select which is the desired level of logging you would like to visualize in the cards but this is not something that is being filtered in the front end neither in the back end of nRF Cloud. When you select the desired log level, this will be changed in AWS shadow and wait for the device to connect to nRF Cloud to catch this new desired value (which is considered a delta) and execute in the application the desired configuration changes. Once this is done, the device reports back the current state, this is then visualized on the left side of the options to select in the Logs card. If you pass your mouse on top of it, it will describe what I'm mentioning.



    As you can see in the picture above, I remarked on blue the "reported" by the device and in orange the "desired".

    If you look at the Multi Service sample, you will notice there are a few files that controls the Shadow control on the device. There are some specific for CoAP and MQTT. If your project lacks of shadow support and has nRF Cloud logging enabled, the device will send the log to nRF Cloud but you will not be able to control the device.


    My recommendation would be to compile the Multi Service sample with the overlay_nrfcloud_logging.conf and see how this changes.

    So you are aware, this feature is not responsive. It takes ~120 seconds to be able to visualize the change on the reported sections I mentioned before.

    Pascal.

  • 0 in reply to Pascal Hdz

    Hello Pascal,

    Thanks for your message. But it seems we still don't understand each other. We talk about a possible issue in the code, not about the shadow and configuration. And it's important to carefully look at the code by the links I provided in the previous messages. There were questions about the code.. But no answers so far.

    I've run the Multi Service sample and the behavior I see confirms the issue described in this ticket.

    To reproduce the issue I made the following steps:

    1. I modified the overlay_nrfcloud_logging.conf to disable all "periodic business logic". This is the diff:

    @@ -28,3 +28,7 @@ CONFIG_LOG_BACKEND_NRF_CLOUD_OUTPUT_TEXT=y
 CONFIG_LOG_PROCESS_THREAD_STACK_SIZE=4096
 CONFIG_LOG_PROCESS_THREAD_SLEEP_MS=30000
 CONFIG_TEMP_ALERT_LIMIT=24
+
+CONFIG_LOCATION_TRACKING=n
+CONFIG_TEMP_TRACKING=n
+

    2. Ran the sample for 15 mins. Got the following logs in nRF Cloud:

    No actions - no logs. This is the expected behavior. Right?

    3. I made one more modification in the overlay_nrfcloud_logging.conf. Set CONFIG_LOG_RUNTIME_FILTERING=y (as I've written above - this option breaks the log filtering). This is the diff:

    @@ -11,7 +11,7 @@ CONFIG_NRF_CLOUD_LOG_INCLUDE_LEVEL_0=y
 
 # If enabled, log levels for each log source can be set per log backend, and
 # can be changed dynamically.
-CONFIG_LOG_RUNTIME_FILTERING=n
+CONFIG_LOG_RUNTIME_FILTERING=y
 
 CONFIG_LOG_BUFFER_SIZE=4096
 
@@ -28,3 +28,7 @@ CONFIG_LOG_BACKEND_NRF_CLOUD_OUTPUT_TEXT=y
 CONFIG_LOG_PROCESS_THREAD_STACK_SIZE=4096
 CONFIG_LOG_PROCESS_THREAD_SLEEP_MS=30000
 CONFIG_TEMP_ALERT_LIMIT=24
+
+CONFIG_LOCATION_TRACKING=n
+CONFIG_TEMP_TRACKING=n
+

    4. Ran the sample for 15 mins. Got the following logs in nRF Cloud:

    Still no actions - but much logs (and they never end). Is this the expected behavior? I believe - not. And I see the code in nrf_cloud_log_backend.c that should prevent this behavior. But it actually doesn't work (see our explanations in the previous messages).

    Thanks,
    -Ruslan

  • 0 in reply to ragruslan

    Hello Ruslan,

    Sorry for my misunderstanding, I can see now the problem that you are pointing. This is indeed an issue and we will need to follow up internally. Unfortunately, I can't offer you a hot fix for now but should be fix on the next NCS releases.

    Pascal.

Reply Children
No Data
Related
Terms of service