Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging - strange behaviour with RTT on nRF53 #21514

Closed
koffes opened this issue Dec 19, 2019 · 5 comments · Fixed by #21517
Closed

Logging - strange behaviour with RTT on nRF53 #21514

koffes opened this issue Dec 19, 2019 · 5 comments · Fixed by #21517
Assignees
Labels
area: Logging bug The issue is a bug, or the PR is fixing a bug platform: nRF Nordic nRFx

Comments

@koffes
Copy link
Collaborator

koffes commented Dec 19, 2019

Currently using the logger with mostly default settings on the nRF53.
Whilst using LOG_WRN in a high frequency loop, I would expect to see something like:
--- 71 messages dropped ---
This usually happens. Though, sometimes the logger skips a series of prints without the "messages dropped" warning.

If I set CONFIG_LOG_BLOCK_IN_THREAD=y the same thing happens. I would expect this to block the thread and output all messages from the for-loop.

If CONFIG_LOG_IMMEDIATE=y is set, I would expect to get all logs, but there is a gap in the prints from the for loop, and no error message.

@nordic-krch

@koffes koffes added the bug The issue is a bug, or the PR is fixing a bug label Dec 19, 2019
@nordic-krch
Copy link
Contributor

@koffes will take a look.

@nordic-krch
Copy link
Contributor

If CONFIG_LOG_IMMEDIATE=y is set, I would expect to get all logs, but there is a gap in the prints from the for loop, and no error message.

I've been looking into that a bit and i think that it is host related. When there is a debugging session opened (e.g. Ozone) and RTT viewer then actually both are trying to read RTT data. Most is read by RTT viewer but some is read by debug session.

I've been successfully reading all logs (on nrf52 and nrf53) when i was running Ozone debug session and use PuTTY to connect to telnet 127.0.0.1:19021.

However, I've found one issue that was causing RTT performance degradation in immediate mode (#21644).

@koffes
Copy link
Collaborator Author

koffes commented Jan 2, 2020

Interesting. AFAIK, the debug session should read from a different channel than RTT. I am quite certain that I did not have a debug session running whilst reading RTT. Is this something that can be described and sent to Segger?

@nordic-krch
Copy link
Contributor

Without debug session, RTT viewer only i see some occasional bytes loss (1 per 1000 entries). I don't see them when using Ozone+PuTTY. When I use Ozone+RTT viewer i see multiple losses on RTT viewer (that's competing for RTT data that i've described above).

So it seems that there are 2 issues that could be reported to segger:

  • debug session + rtt viewer
  • occasional losses on rtt viewer

@XavierChapron
Copy link
Contributor

As @koffes , I am still having issues with #21517
I have created a PR that resolves it (at least in my situation): #24647
Please have a look.

nashif pushed a commit to XavierChapron/zephyr that referenced this issue Jul 7, 2020
Fix data_out_block_mode() to return the data correctly sent to RTT.
Before this fixes, it was always returning `lenght`, even in situation
where data have been dropped. This was leading to not having the dropped
messages warning displayed.

Fixes zephyrproject-rtos#21514

Signed-off-by: Xavier Chapron <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area: Logging bug The issue is a bug, or the PR is fixing a bug platform: nRF Nordic nRFx
Projects
None yet
4 participants