Skip to content

ASoC: SOF: ipc4-mtrace: resync host_read_ptr on debugfs open and release #5690

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.

Sign up for GitHub

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

Open
majunkier wants to merge 1 commit into
base: topic/sof-dev
Choose a base branch
from
Open

ASoC: SOF: ipc4-mtrace: resync host_read_ptr on debugfs open and release #5690

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 28 additions & 0 deletions sound/soc/sof/ipc4-mtrace.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,26 @@ static int sof_ipc4_mtrace_dfs_open(struct inode *inode, struct file *file)
return -ENOMEM;
}

/*
* Re-sync dsp_write_ptr from SRAM and align host_read_ptr to it so
* this reader starts from current write position and only sees
* data written after this open(). Without this prior reader (e.g.
* one-shot dd) may have advanced host_read_ptr to equal
* dsp_write_ptr, causing next reader to block indefinitely on
* platforms with low DSP activity.Resetting to current dsp_write_ptr
* (not to 0) avoids re-reading stale data from wrapped circular buffer.
*/
if (core_data->slot_offset != SOF_IPC4_INVALID_SLOT_OFFSET) {
struct snd_sof_dev *sdev = core_data->sdev;
u32 write_ptr;

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;
core_data->host_read_ptr = write_ptr;
Copy link
Collaborator

@ujfalusi ujfalusi Mar 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

but you will loose debug data between two opens?
open / read / close
fw still prints # this information might be lost?
open / read /close

Copy link
Collaborator

@kv2019i kv2019i Mar 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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!

Copy link
Collaborator

@ujfalusi ujfalusi Mar 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

}

ret = simple_open(inode, file);
if (ret) {
kfree(core_data->log_buffer);
Expand Down Expand Up @@ -254,6 +274,14 @@ static int sof_ipc4_mtrace_dfs_release(struct inode *inode, struct file *file)
scoped_guard(mutex, &core_data->buffer_lock) {
kfree(core_data->log_buffer);
core_data->log_buffer = NULL;
/*
* Align host_read_ptr to current dsp_write_ptr so that
* subsequent open() starts from fresh data and isnt
* blocked by stale pointer left by this reader. Using
* dsp_write_ptr (not 0) avoids re-reading stale data from
* wrapped circular buffer.
*/
core_data->host_read_ptr = core_data->dsp_write_ptr;
Copy link
Collaborator

@ujfalusi ujfalusi Mar 9, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.

}

return 0;
Expand Down
Loading