ASoC: SOF: ipc4-mtrace: resync host_read_ptr on debugfs open#5690
ASoC: SOF: ipc4-mtrace: resync host_read_ptr on debugfs open#5690majunkier wants to merge 1 commit intothesofproject:topic/sof-devfrom
Conversation
majunkier
requested review from
bardliao,
dbaluta,
kv2019i,
lgirdwood,
plbossart,
ranj063 and
ujfalusi
as code owners
sound/soc/sof/ipc4-mtrace.c
Outdated
| &write_ptr, sizeof(write_ptr)); | ||
| write_ptr -= write_ptr % 4; | ||
| core_data->dsp_write_ptr = write_ptr; | ||
| core_data->host_read_ptr = write_ptr; |
There was a problem hiding this comment.
but you will loose debug data between two opens?
open / read / close
fw still prints # this information might be lost?
open / read /close
There was a problem hiding this comment.
Ack @ujfalusi , I asked @majunkier to push this for review. THis is genuine problem, but not sure which way to go about. The current implementation is intentional in the sense that you cannot run mtrace-reader.py before the driver is loaded, and as the driver loads and boots the DSP, it is not possible to get first boot logs if the read pointer is reset at boot. IOW, ability to get old logs is a feature. But as Mateusz has rootcaused, this creates non-deterministic behaviour is the mtrace-reader is restarted, and this is showing up as problems in some scenarios we have in CI. It's also true mtrace-reader.py needs to be stopped before the driver can be unloaded.
Not sure how to best solve this. I don't think we sync at open. Sync at close is a possibility, but this is still not deterministic. I guess one option is to just document this behaviour and the test case (that checks whether logging is working) needs to create some DSP activity that ensures there is new logs after mtrace-reader is restarted. Ideas are welcome!
There was a problem hiding this comment.
I'm not sure, but have we tried to read the pointers directly from the slot?
I guess the issue shows up when the DSP is suspended and the the write counter got reset (also the read ptr in slot).
If we read the write/read ptr from slot on open then we will have up-to date info, or we just always read them on every time in sof_ipc4_mtrace_dfs_read(), first I would try the sync at open only. There is a reason why we only update the write ptr when fw tells that it has moved.
There was a problem hiding this comment.
so i will remove core_data->host_read_ptr = write_ptr and re-sync only dsp_write_ptr from SRAM in open().
I hope this avoid losing inter session data.
i need to validate if this will be enough
UPDATE
i have tested current changes, seems working
sound/soc/sof/ipc4-mtrace.c
Outdated
| * dsp_write_ptr (not 0) avoids re-reading stale data from | ||
| * wrapped circular buffer. | ||
| */ | ||
| core_data->host_read_ptr = core_data->dsp_write_ptr; |
There was a problem hiding this comment.
either of the two change is redundant? If you reset the pointers in open then this is not needed, but resetting might be a problem as well.
There was a problem hiding this comment.
Dropping this change as well.
majunkier
force-pushed
the
check_sof_logger
branch
from
4c09f20 to
98832db
Compare
| sof_mailbox_read(sdev, core_data->slot_offset + sizeof(u32), | ||
| &write_ptr, sizeof(write_ptr)); | ||
| write_ptr -= write_ptr % 4; | ||
| core_data->dsp_write_ptr = write_ptr; |
There was a problem hiding this comment.
The commit message also needs update.
But something is not quite right in the description. The dsp_write_ptr is updated for the NOTIFY_LOG_BUFFER_STATUS in sof_ipc4_mtrace_update_pos(), it is done regardless if reader is active or not, but if there is one active then it is woken up to read out the data.
There was a problem hiding this comment.
out of curiosity, can you debug this a bit further?
read the write and read ptr from the slot and then compare it with the ptr value tracked in core_data and if they differ print them out.
Something is not adding up here.
core_data->dsp_write_ptr is updated on each aging timer IPC, but there is 256ms window between DSP write and IPC. If reader opens in this window and DSP goes idle before next IPC,there wont be further writes and sof_wait_mtrace_avail() blocks until timeout. Fix by reading dsp_write_ptr directly from SRAM in open() to get current write position without waiting for the next IPC. host_read_ptr is left unchanged to preserve inter-session data. Signed-off-by: Mateusz Junkier <mateusz.junkier@intel.com>
majunkier
force-pushed
the
check_sof_logger
branch
from
98832db to
4b9d08c
Compare
majunkier
changed the title
3 participants
core_data->dsp_write_ptr is updated on each aging timer IPC, but there
is 256ms window between DSP write and IPC. If reader opens in this window
and DSP goes idle before next IPC,there wont be further writes
and sof_wait_mtrace_avail() blocks until timeout.
Fix by reading dsp_write_ptr directly from SRAM in open() to get
current write position without waiting for the next IPC. host_read_ptr
is left unchanged to preserve inter-session data.