1 // SPDX-License-Identifier: GPL-2.0-only
3 // Copyright(c) 2022 Intel Corporation. All rights reserved.
5 #include <linux/debugfs.h>
6 #include <linux/sched/signal.h>
7 #include <sound/sof/ipc4/header.h>
12 * debug info window is organized in 16 (equal sized) pages:
14 * ------------------------
15 * | Page0 - descriptors |
16 * ------------------------
18 * ------------------------
20 * ------------------------
22 * ------------------------
24 * ------------------------
26 * ------------------------
28 * The slot size == page size
30 * The first page contains descriptors for the remaining 15 cores
31 * The slot descriptor is:
36 * Log buffer slots have the following layout:
41 * The two pointers are offsets within the buffer.
44 #define FW_EPOCH_DELTA 11644473600LL
46 #define MAX_ALLOWED_LIBRARIES 16
48 #define SOF_IPC4_INVALID_SLOT_OFFSET 0xffffffff
50 /* for debug and critical types */
51 #define SOF_MTRACE_SLOT_CORE_MASK GENMASK(7, 0)
52 #define SOF_MTRACE_SLOT_TYPE_MASK GENMASK(31, 8)
54 #define DEFAULT_AGING_TIMER_PERIOD_MS 0x100
55 #define DEFAULT_FIFO_FULL_TIMER_PERIOD_MS 0x1000
57 /* ipc4 log level and source definitions for logs_priorities_mask */
58 #define SOF_MTRACE_LOG_LEVEL_CRITICAL BIT(0)
59 #define SOF_MTRACE_LOG_LEVEL_ERROR BIT(1)
60 #define SOF_MTRACE_LOG_LEVEL_WARNING BIT(2)
61 #define SOF_MTRACE_LOG_LEVEL_INFO BIT(3)
62 #define SOF_MTRACE_LOG_LEVEL_VERBOSE BIT(4)
63 #define SOF_MTRACE_LOG_SOURCE_INFRA BIT(5) /* log source 0 */
64 #define SOF_MTRACE_LOG_SOURCE_HAL BIT(6)
65 #define SOF_MTRACE_LOG_SOURCE_MODULE BIT(7)
66 #define SOF_MTRACE_LOG_SOURCE_AUDIO BIT(8)
67 #define SOF_MTRACE_LOG_SOURCE_SCHEDULER BIT(9)
68 #define SOF_MTRACE_LOG_SOURCE_ULP_INFRA BIT(10)
69 #define SOF_MTRACE_LOG_SOURCE_ULP_MODULE BIT(11)
70 #define SOF_MTRACE_LOG_SOURCE_VISION BIT(12) /* log source 7 */
71 #define DEFAULT_LOGS_PRIORITIES_MASK (SOF_MTRACE_LOG_LEVEL_CRITICAL | \
72 SOF_MTRACE_LOG_LEVEL_ERROR | \
73 SOF_MTRACE_LOG_LEVEL_WARNING | \
74 SOF_MTRACE_LOG_LEVEL_INFO | \
75 SOF_MTRACE_LOG_SOURCE_INFRA | \
76 SOF_MTRACE_LOG_SOURCE_HAL | \
77 SOF_MTRACE_LOG_SOURCE_MODULE | \
78 SOF_MTRACE_LOG_SOURCE_AUDIO)
80 struct sof_log_state_info {
81 u32 aging_timer_period;
82 u32 fifo_full_timer_period;
84 u32 logs_priorities_mask[MAX_ALLOWED_LIBRARIES];
87 enum sof_mtrace_state {
89 SOF_MTRACE_INITIALIZING,
93 struct sof_mtrace_core_data {
94 struct snd_sof_dev *sdev;
99 struct mutex buffer_lock; /* for log_buffer alloc/free */
102 /* pos update IPC arrived before the slot offset is known, queried */
103 bool delayed_pos_update;
104 wait_queue_head_t trace_sleep;
107 struct sof_mtrace_priv {
108 struct snd_sof_dev *sdev;
109 enum sof_mtrace_state mtrace_state;
110 struct sof_log_state_info state_info;
112 struct sof_mtrace_core_data cores[];
115 static int sof_ipc4_mtrace_dfs_open(struct inode *inode, struct file *file)
117 struct sof_mtrace_core_data *core_data = inode->i_private;
120 mutex_lock(&core_data->buffer_lock);
122 if (core_data->log_buffer) {
127 ret = debugfs_file_get(file->f_path.dentry);
131 core_data->log_buffer = kmalloc(SOF_IPC4_DEBUG_SLOT_SIZE, GFP_KERNEL);
132 if (!core_data->log_buffer) {
133 debugfs_file_put(file->f_path.dentry);
138 ret = simple_open(inode, file);
140 kfree(core_data->log_buffer);
141 debugfs_file_put(file->f_path.dentry);
145 mutex_unlock(&core_data->buffer_lock);
150 static bool sof_wait_mtrace_avail(struct sof_mtrace_core_data *core_data)
152 wait_queue_entry_t wait;
154 /* data immediately available */
155 if (core_data->host_read_ptr != core_data->dsp_write_ptr)
158 /* wait for available trace data from FW */
159 init_waitqueue_entry(&wait, current);
160 set_current_state(TASK_INTERRUPTIBLE);
161 add_wait_queue(&core_data->trace_sleep, &wait);
163 if (!signal_pending(current)) {
164 /* set timeout to max value, no error code */
165 schedule_timeout(MAX_SCHEDULE_TIMEOUT);
167 remove_wait_queue(&core_data->trace_sleep, &wait);
169 if (core_data->host_read_ptr != core_data->dsp_write_ptr)
175 static ssize_t sof_ipc4_mtrace_dfs_read(struct file *file, char __user *buffer,
176 size_t count, loff_t *ppos)
178 struct sof_mtrace_core_data *core_data = file->private_data;
179 u32 log_buffer_offset, log_buffer_size, read_ptr, write_ptr;
180 struct snd_sof_dev *sdev = core_data->sdev;
181 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
182 void *log_buffer = core_data->log_buffer;
187 /* check pos and count */
190 if (!count || count < sizeof(avail))
193 /* get available count based on current host offset */
194 if (!sof_wait_mtrace_avail(core_data)) {
195 /* No data available */
197 if (copy_to_user(buffer, &avail, sizeof(avail)))
203 if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET)
206 /* The log data buffer starts after the two pointer in the slot */
207 log_buffer_offset = core_data->slot_offset + (sizeof(u32) * 2);
208 /* The log data size excludes the pointers */
209 log_buffer_size = SOF_IPC4_DEBUG_SLOT_SIZE - (sizeof(u32) * 2);
211 read_ptr = core_data->host_read_ptr;
212 write_ptr = core_data->dsp_write_ptr;
214 if (read_ptr < write_ptr)
215 avail = write_ptr - read_ptr;
217 avail = log_buffer_size - read_ptr + write_ptr;
222 if (avail > log_buffer_size)
223 avail = log_buffer_size;
225 /* Need space for the initial u32 of the avail */
226 if (avail > count - sizeof(avail))
227 avail = count - sizeof(avail);
229 if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))
231 "core%d, host read: %#x, dsp write: %#x, avail: %#x\n",
232 core_data->id, read_ptr, write_ptr, avail);
234 if (read_ptr < write_ptr) {
235 /* Read data between read pointer and write pointer */
236 sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer, avail);
238 /* read from read pointer to end of the slot */
239 sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer,
241 /* read from slot start to write pointer */
243 sof_mailbox_read(sdev, log_buffer_offset,
244 (u8 *)(log_buffer) + avail - write_ptr,
248 /* first write the number of bytes we have gathered */
249 ret = copy_to_user(buffer, &avail, sizeof(avail));
253 /* Followed by the data itself */
254 ret = copy_to_user(buffer + sizeof(avail), log_buffer, avail);
258 /* Update the host_read_ptr in the slot for this core */
260 if (read_ptr >= log_buffer_size)
261 read_ptr -= log_buffer_size;
262 sof_mailbox_write(sdev, core_data->slot_offset, &read_ptr, sizeof(read_ptr));
264 /* Only update the host_read_ptr if mtrace is enabled */
265 if (priv->mtrace_state != SOF_MTRACE_DISABLED)
266 core_data->host_read_ptr = read_ptr;
269 * Ask for a new buffer from user space for the next chunk, not
270 * streaming due to the heading number of bytes value.
277 static int sof_ipc4_mtrace_dfs_release(struct inode *inode, struct file *file)
279 struct sof_mtrace_core_data *core_data = inode->i_private;
281 debugfs_file_put(file->f_path.dentry);
283 mutex_lock(&core_data->buffer_lock);
284 kfree(core_data->log_buffer);
285 core_data->log_buffer = NULL;
286 mutex_unlock(&core_data->buffer_lock);
291 static const struct file_operations sof_dfs_mtrace_fops = {
292 .open = sof_ipc4_mtrace_dfs_open,
293 .read = sof_ipc4_mtrace_dfs_read,
294 .llseek = default_llseek,
295 .release = sof_ipc4_mtrace_dfs_release,
297 .owner = THIS_MODULE,
300 static ssize_t sof_ipc4_priority_mask_dfs_read(struct file *file, char __user *to,
301 size_t count, loff_t *ppos)
303 struct sof_mtrace_priv *priv = file->private_data;
304 int i, ret, offset, remaining;
308 * one entry (14 char + new line = 15):
313 buf = kzalloc(241, GFP_KERNEL);
317 for (i = 0; i < MAX_ALLOWED_LIBRARIES; i++) {
318 offset = strlen(buf);
319 remaining = 241 - offset;
320 snprintf(buf + offset, remaining, "%2d: 0x%08x\n", i,
321 priv->state_info.logs_priorities_mask[i]);
324 ret = simple_read_from_buffer(to, count, ppos, buf, strlen(buf));
330 static ssize_t sof_ipc4_priority_mask_dfs_write(struct file *file,
331 const char __user *from,
332 size_t count, loff_t *ppos)
334 struct sof_mtrace_priv *priv = file->private_data;
341 * To update Nth mask entry, write:
342 * "N,0x1234" or "N,1234" to the debugfs file
343 * The mask will be interpreted as hexadecimal number
345 buf = memdup_user_nul(from, count);
349 ret = sscanf(buf, "%u,0x%x", &id, &mask);
351 ret = sscanf(buf, "%u,%x", &id, &mask);
358 if (id >= MAX_ALLOWED_LIBRARIES) {
363 priv->state_info.logs_priorities_mask[id] = mask;
371 static const struct file_operations sof_dfs_priority_mask_fops = {
373 .read = sof_ipc4_priority_mask_dfs_read,
374 .write = sof_ipc4_priority_mask_dfs_write,
375 .llseek = default_llseek,
377 .owner = THIS_MODULE,
380 static int mtrace_debugfs_create(struct snd_sof_dev *sdev)
382 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
383 struct dentry *dfs_root;
387 dfs_root = debugfs_create_dir("mtrace", sdev->debugfs_root);
388 if (IS_ERR_OR_NULL(dfs_root))
391 /* Create files for the logging parameters */
392 debugfs_create_u32("aging_timer_period", 0644, dfs_root,
393 &priv->state_info.aging_timer_period);
394 debugfs_create_u32("fifo_full_timer_period", 0644, dfs_root,
395 &priv->state_info.fifo_full_timer_period);
396 debugfs_create_file("logs_priorities_mask", 0644, dfs_root, priv,
397 &sof_dfs_priority_mask_fops);
399 /* Separate log files per core */
400 for (i = 0; i < sdev->num_cores; i++) {
401 snprintf(dfs_name, sizeof(dfs_name), "core%d", i);
402 debugfs_create_file(dfs_name, 0444, dfs_root, &priv->cores[i],
403 &sof_dfs_mtrace_fops);
409 static int ipc4_mtrace_enable(struct snd_sof_dev *sdev)
411 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
412 const struct sof_ipc_ops *iops = sdev->ipc->ops;
413 struct sof_ipc4_msg msg;
418 if (priv->mtrace_state != SOF_MTRACE_DISABLED)
421 msg.primary = SOF_IPC4_MSG_TARGET(SOF_IPC4_MODULE_MSG);
422 msg.primary |= SOF_IPC4_MSG_DIR(SOF_IPC4_MSG_REQUEST);
423 msg.primary |= SOF_IPC4_MOD_ID(SOF_IPC4_MOD_INIT_BASEFW_MOD_ID);
424 msg.primary |= SOF_IPC4_MOD_INSTANCE(SOF_IPC4_MOD_INIT_BASEFW_INSTANCE_ID);
425 msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_SYSTEM_TIME);
427 /* The system time is in usec, UTC, epoch is 1601-01-01 00:00:00 */
428 kt = ktime_add_us(ktime_get_real(), FW_EPOCH_DELTA * USEC_PER_SEC);
429 system_time = ktime_to_us(kt);
430 msg.data_size = sizeof(system_time);
431 msg.data_ptr = &system_time;
432 ret = iops->set_get_data(sdev, &msg, msg.data_size, true);
436 msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);
438 priv->state_info.enable = 1;
440 msg.data_size = sizeof(priv->state_info);
441 msg.data_ptr = &priv->state_info;
443 priv->mtrace_state = SOF_MTRACE_INITIALIZING;
444 ret = iops->set_get_data(sdev, &msg, msg.data_size, true);
446 priv->mtrace_state = SOF_MTRACE_DISABLED;
450 priv->mtrace_state = SOF_MTRACE_ENABLED;
455 static void ipc4_mtrace_disable(struct snd_sof_dev *sdev)
457 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
458 const struct sof_ipc_ops *iops = sdev->ipc->ops;
459 struct sof_ipc4_msg msg;
462 if (priv->mtrace_state == SOF_MTRACE_DISABLED)
465 msg.primary = SOF_IPC4_MSG_TARGET(SOF_IPC4_MODULE_MSG);
466 msg.primary |= SOF_IPC4_MSG_DIR(SOF_IPC4_MSG_REQUEST);
467 msg.primary |= SOF_IPC4_MOD_ID(SOF_IPC4_MOD_INIT_BASEFW_MOD_ID);
468 msg.primary |= SOF_IPC4_MOD_INSTANCE(SOF_IPC4_MOD_INIT_BASEFW_INSTANCE_ID);
469 msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);
471 priv->state_info.enable = 0;
473 msg.data_size = sizeof(priv->state_info);
474 msg.data_ptr = &priv->state_info;
475 iops->set_get_data(sdev, &msg, msg.data_size, true);
477 priv->mtrace_state = SOF_MTRACE_DISABLED;
479 for (i = 0; i < sdev->num_cores; i++) {
480 struct sof_mtrace_core_data *core_data = &priv->cores[i];
482 core_data->host_read_ptr = 0;
483 core_data->dsp_write_ptr = 0;
484 wake_up(&core_data->trace_sleep);
489 * Each DSP core logs to a dedicated slot.
490 * Parse the slot descriptors at debug_box offset to find the debug log slots
491 * and map them to cores.
492 * There are 15 slots and therefore 15 descriptors to check (MAX_MTRACE_SLOTS)
494 static void sof_mtrace_find_core_slots(struct snd_sof_dev *sdev)
496 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
497 struct sof_mtrace_core_data *core_data;
498 u32 slot_desc_type_offset, type, core;
501 for (i = 0; i < SOF_IPC4_MAX_DEBUG_SLOTS; i++) {
502 /* The type is the second u32 in the slot descriptor */
503 slot_desc_type_offset = sdev->debug_box.offset;
504 slot_desc_type_offset += SOF_IPC4_DEBUG_DESCRIPTOR_SIZE * i + sizeof(u32);
505 sof_mailbox_read(sdev, slot_desc_type_offset, &type, sizeof(type));
507 if ((type & SOF_MTRACE_SLOT_TYPE_MASK) == SOF_IPC4_DEBUG_SLOT_DEBUG_LOG) {
508 core = type & SOF_MTRACE_SLOT_CORE_MASK;
510 if (core >= sdev->num_cores) {
511 dev_dbg(sdev->dev, "core%u is invalid for slot%d\n",
516 core_data = &priv->cores[core];
518 * The area reserved for descriptors have the same size
520 * In other words: slot0 starts at
521 * debug_box + SOF_MTRACE_SLOT_SIZE offset
523 core_data->slot_offset = sdev->debug_box.offset;
524 core_data->slot_offset += SOF_IPC4_DEBUG_SLOT_SIZE * (i + 1);
525 dev_dbg(sdev->dev, "slot%d is used for core%u\n", i, core);
526 if (core_data->delayed_pos_update) {
527 sof_ipc4_mtrace_update_pos(sdev, core);
528 core_data->delayed_pos_update = false;
531 dev_dbg(sdev->dev, "slot%d is not a log slot (%#x)\n", i, type);
536 static int ipc4_mtrace_init(struct snd_sof_dev *sdev)
538 struct sof_ipc4_fw_data *ipc4_data = sdev->private;
539 struct sof_mtrace_priv *priv;
542 if (sdev->fw_trace_data) {
543 dev_err(sdev->dev, "fw_trace_data has been already allocated\n");
547 if (!ipc4_data->mtrace_log_bytes ||
548 ipc4_data->mtrace_type != SOF_IPC4_MTRACE_INTEL_CAVS_2) {
549 sdev->fw_trace_is_supported = false;
553 priv = devm_kzalloc(sdev->dev, struct_size(priv, cores, sdev->num_cores),
558 sdev->fw_trace_data = priv;
560 /* Set initial values for mtrace parameters */
561 priv->state_info.aging_timer_period = DEFAULT_AGING_TIMER_PERIOD_MS;
562 priv->state_info.fifo_full_timer_period = DEFAULT_FIFO_FULL_TIMER_PERIOD_MS;
563 /* Only enable basefw logs initially (index 0 is always basefw) */
564 priv->state_info.logs_priorities_mask[0] = DEFAULT_LOGS_PRIORITIES_MASK;
566 for (i = 0; i < sdev->num_cores; i++) {
567 struct sof_mtrace_core_data *core_data = &priv->cores[i];
569 init_waitqueue_head(&core_data->trace_sleep);
570 mutex_init(&core_data->buffer_lock);
571 core_data->sdev = sdev;
575 ret = ipc4_mtrace_enable(sdev);
578 * Mark firmware tracing as not supported and return 0 to not
579 * block the whole audio stack
581 sdev->fw_trace_is_supported = false;
582 dev_dbg(sdev->dev, "initialization failed, fw tracing is disabled\n");
586 sof_mtrace_find_core_slots(sdev);
588 ret = mtrace_debugfs_create(sdev);
590 ipc4_mtrace_disable(sdev);
595 static void ipc4_mtrace_free(struct snd_sof_dev *sdev)
597 ipc4_mtrace_disable(sdev);
600 static int sof_ipc4_mtrace_update_pos_all_cores(struct snd_sof_dev *sdev)
604 for (i = 0; i < sdev->num_cores; i++)
605 sof_ipc4_mtrace_update_pos(sdev, i);
610 int sof_ipc4_mtrace_update_pos(struct snd_sof_dev *sdev, int core)
612 struct sof_mtrace_priv *priv = sdev->fw_trace_data;
613 struct sof_mtrace_core_data *core_data;
615 if (!sdev->fw_trace_is_supported ||
616 priv->mtrace_state == SOF_MTRACE_DISABLED)
619 if (core >= sdev->num_cores)
622 core_data = &priv->cores[core];
624 if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET) {
625 core_data->delayed_pos_update = true;
629 /* Read out the dsp_write_ptr from the slot for this core */
630 sof_mailbox_read(sdev, core_data->slot_offset + sizeof(u32),
631 &core_data->dsp_write_ptr, 4);
632 core_data->dsp_write_ptr -= core_data->dsp_write_ptr % 4;
634 if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))
635 dev_dbg(sdev->dev, "core%d, host read: %#x, dsp write: %#x",
636 core, core_data->host_read_ptr, core_data->dsp_write_ptr);
638 wake_up(&core_data->trace_sleep);
643 static void ipc4_mtrace_fw_crashed(struct snd_sof_dev *sdev)
646 * The DSP might not be able to send SOF_IPC4_NOTIFY_LOG_BUFFER_STATUS
647 * messages anymore, so check the log buffer status on all
648 * cores and process any pending messages.
650 sof_ipc4_mtrace_update_pos_all_cores(sdev);
653 static int ipc4_mtrace_resume(struct snd_sof_dev *sdev)
655 return ipc4_mtrace_enable(sdev);
658 static void ipc4_mtrace_suspend(struct snd_sof_dev *sdev, pm_message_t pm_state)
660 ipc4_mtrace_disable(sdev);
663 const struct sof_ipc_fw_tracing_ops ipc4_mtrace_ops = {
664 .init = ipc4_mtrace_init,
665 .free = ipc4_mtrace_free,
666 .fw_crashed = ipc4_mtrace_fw_crashed,
667 .suspend = ipc4_mtrace_suspend,
668 .resume = ipc4_mtrace_resume,