zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.34k stars 6.33k forks source link

Logging - strange behaviour with RTT on nRF53 #21514

Closed koffes closed 4 years ago

koffes commented 4 years ago

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

nordic-krch commented 4 years ago

@koffes will take a look.

nordic-krch commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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:

XavierChapron commented 4 years ago

As @koffes , I am still having issues with #21517 I have created a PR that resolves it (at least in my situation): https://github.com/zephyrproject-rtos/zephyr/pull/24647 Please have a look.