673 lines · c
1// SPDX-License-Identifier: GPL-2.0-only2//3// Copyright(c) 2022 Intel Corporation4 5#include <linux/debugfs.h>6#include <linux/sched/signal.h>7#include <linux/sched/clock.h>8#include <sound/sof/ipc4/header.h>9#include "sof-priv.h"10#include "ipc4-priv.h"11 12/*13 * debug info window is organized in 16 (equal sized) pages:14 *15 * ------------------------16 * | Page0 - descriptors |17 * ------------------------18 * | Page1 - slot0 |19 * ------------------------20 * | Page2 - slot1 |21 * ------------------------22 * | ... |23 * ------------------------24 * | Page14 - slot13 |25 * ------------------------26 * | Page15 - slot14 |27 * ------------------------28 *29 * The slot size == page size30 *31 * The first page contains descriptors for the remaining 15 cores32 * The slot descriptor is:33 * u32 res_id;34 * u32 type;35 * u32 vma;36 *37 * Log buffer slots have the following layout:38 * u32 host_read_ptr;39 * u32 dsp_write_ptr;40 * u8 buffer[];41 *42 * The two pointers are offsets within the buffer.43 */44 45#define FW_EPOCH_DELTA 11644473600LL46 47#define MAX_ALLOWED_LIBRARIES 1648 49#define SOF_IPC4_INVALID_SLOT_OFFSET 0xffffffff50 51 /* for debug and critical types */52#define SOF_MTRACE_SLOT_CORE_MASK GENMASK(7, 0)53#define SOF_MTRACE_SLOT_TYPE_MASK GENMASK(31, 8)54 55#define DEFAULT_AGING_TIMER_PERIOD_MS 0x10056#define DEFAULT_FIFO_FULL_TIMER_PERIOD_MS 0x100057 58/* ipc4 log level and source definitions for logs_priorities_mask */59#define SOF_MTRACE_LOG_LEVEL_CRITICAL BIT(0)60#define SOF_MTRACE_LOG_LEVEL_ERROR BIT(1)61#define SOF_MTRACE_LOG_LEVEL_WARNING BIT(2)62#define SOF_MTRACE_LOG_LEVEL_INFO BIT(3)63#define SOF_MTRACE_LOG_LEVEL_VERBOSE BIT(4)64#define SOF_MTRACE_LOG_SOURCE_INFRA BIT(5) /* log source 0 */65#define SOF_MTRACE_LOG_SOURCE_HAL BIT(6)66#define SOF_MTRACE_LOG_SOURCE_MODULE BIT(7)67#define SOF_MTRACE_LOG_SOURCE_AUDIO BIT(8)68#define SOF_MTRACE_LOG_SOURCE_SCHEDULER BIT(9)69#define SOF_MTRACE_LOG_SOURCE_ULP_INFRA BIT(10)70#define SOF_MTRACE_LOG_SOURCE_ULP_MODULE BIT(11)71#define SOF_MTRACE_LOG_SOURCE_VISION BIT(12) /* log source 7 */72#define DEFAULT_LOGS_PRIORITIES_MASK (SOF_MTRACE_LOG_LEVEL_CRITICAL | \73 SOF_MTRACE_LOG_LEVEL_ERROR | \74 SOF_MTRACE_LOG_LEVEL_WARNING | \75 SOF_MTRACE_LOG_LEVEL_INFO | \76 SOF_MTRACE_LOG_SOURCE_INFRA | \77 SOF_MTRACE_LOG_SOURCE_HAL | \78 SOF_MTRACE_LOG_SOURCE_MODULE | \79 SOF_MTRACE_LOG_SOURCE_AUDIO)80 81struct sof_log_state_info {82 u32 aging_timer_period;83 u32 fifo_full_timer_period;84 u32 enable;85 u32 logs_priorities_mask[MAX_ALLOWED_LIBRARIES];86} __packed;87 88enum sof_mtrace_state {89 SOF_MTRACE_DISABLED,90 SOF_MTRACE_INITIALIZING,91 SOF_MTRACE_ENABLED,92};93 94struct sof_mtrace_core_data {95 struct snd_sof_dev *sdev;96 97 int id;98 u32 slot_offset;99 void *log_buffer;100 struct mutex buffer_lock; /* for log_buffer alloc/free */101 u32 host_read_ptr;102 u32 dsp_write_ptr;103 /* pos update IPC arrived before the slot offset is known, queried */104 bool delayed_pos_update;105 wait_queue_head_t trace_sleep;106};107 108struct sof_mtrace_priv {109 struct snd_sof_dev *sdev;110 enum sof_mtrace_state mtrace_state;111 struct sof_log_state_info state_info;112 113 struct sof_mtrace_core_data cores[];114};115 116static int sof_ipc4_mtrace_dfs_open(struct inode *inode, struct file *file)117{118 struct sof_mtrace_core_data *core_data = inode->i_private;119 int ret;120 121 mutex_lock(&core_data->buffer_lock);122 123 if (core_data->log_buffer) {124 ret = -EBUSY;125 goto out;126 }127 128 ret = debugfs_file_get(file->f_path.dentry);129 if (unlikely(ret))130 goto out;131 132 core_data->log_buffer = kmalloc(SOF_IPC4_DEBUG_SLOT_SIZE, GFP_KERNEL);133 if (!core_data->log_buffer) {134 debugfs_file_put(file->f_path.dentry);135 ret = -ENOMEM;136 goto out;137 }138 139 ret = simple_open(inode, file);140 if (ret) {141 kfree(core_data->log_buffer);142 debugfs_file_put(file->f_path.dentry);143 }144 145out:146 mutex_unlock(&core_data->buffer_lock);147 148 return ret;149}150 151static bool sof_wait_mtrace_avail(struct sof_mtrace_core_data *core_data)152{153 wait_queue_entry_t wait;154 155 /* data immediately available */156 if (core_data->host_read_ptr != core_data->dsp_write_ptr)157 return true;158 159 /* wait for available trace data from FW */160 init_waitqueue_entry(&wait, current);161 set_current_state(TASK_INTERRUPTIBLE);162 add_wait_queue(&core_data->trace_sleep, &wait);163 164 if (!signal_pending(current)) {165 /* set timeout to max value, no error code */166 schedule_timeout(MAX_SCHEDULE_TIMEOUT);167 }168 remove_wait_queue(&core_data->trace_sleep, &wait);169 170 if (core_data->host_read_ptr != core_data->dsp_write_ptr)171 return true;172 173 return false;174}175 176static ssize_t sof_ipc4_mtrace_dfs_read(struct file *file, char __user *buffer,177 size_t count, loff_t *ppos)178{179 struct sof_mtrace_core_data *core_data = file->private_data;180 u32 log_buffer_offset, log_buffer_size, read_ptr, write_ptr;181 struct snd_sof_dev *sdev = core_data->sdev;182 struct sof_mtrace_priv *priv = sdev->fw_trace_data;183 void *log_buffer = core_data->log_buffer;184 loff_t lpos = *ppos;185 u32 avail;186 int ret;187 188 /* check pos and count */189 if (lpos < 0)190 return -EINVAL;191 if (!count || count < sizeof(avail))192 return 0;193 194 /* get available count based on current host offset */195 if (!sof_wait_mtrace_avail(core_data)) {196 /* No data available */197 avail = 0;198 if (copy_to_user(buffer, &avail, sizeof(avail)))199 return -EFAULT;200 201 return 0;202 }203 204 if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET)205 return 0;206 207 /* The log data buffer starts after the two pointer in the slot */208 log_buffer_offset = core_data->slot_offset + (sizeof(u32) * 2);209 /* The log data size excludes the pointers */210 log_buffer_size = SOF_IPC4_DEBUG_SLOT_SIZE - (sizeof(u32) * 2);211 212 read_ptr = core_data->host_read_ptr;213 write_ptr = core_data->dsp_write_ptr;214 215 if (read_ptr < write_ptr)216 avail = write_ptr - read_ptr;217 else218 avail = log_buffer_size - read_ptr + write_ptr;219 220 if (!avail)221 return 0;222 223 if (avail > log_buffer_size)224 avail = log_buffer_size;225 226 /* Need space for the initial u32 of the avail */227 if (avail > count - sizeof(avail))228 avail = count - sizeof(avail);229 230 if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))231 dev_dbg(sdev->dev,232 "core%d, host read: %#x, dsp write: %#x, avail: %#x\n",233 core_data->id, read_ptr, write_ptr, avail);234 235 if (read_ptr < write_ptr) {236 /* Read data between read pointer and write pointer */237 sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer, avail);238 } else {239 /* read from read pointer to end of the slot */240 sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer,241 avail - write_ptr);242 /* read from slot start to write pointer */243 if (write_ptr)244 sof_mailbox_read(sdev, log_buffer_offset,245 (u8 *)(log_buffer) + avail - write_ptr,246 write_ptr);247 }248 249 /* first write the number of bytes we have gathered */250 ret = copy_to_user(buffer, &avail, sizeof(avail));251 if (ret)252 return -EFAULT;253 254 /* Followed by the data itself */255 ret = copy_to_user(buffer + sizeof(avail), log_buffer, avail);256 if (ret)257 return -EFAULT;258 259 /* Update the host_read_ptr in the slot for this core */260 read_ptr += avail;261 if (read_ptr >= log_buffer_size)262 read_ptr -= log_buffer_size;263 sof_mailbox_write(sdev, core_data->slot_offset, &read_ptr, sizeof(read_ptr));264 265 /* Only update the host_read_ptr if mtrace is enabled */266 if (priv->mtrace_state != SOF_MTRACE_DISABLED)267 core_data->host_read_ptr = read_ptr;268 269 /*270 * Ask for a new buffer from user space for the next chunk, not271 * streaming due to the heading number of bytes value.272 */273 *ppos += count;274 275 return count;276}277 278static int sof_ipc4_mtrace_dfs_release(struct inode *inode, struct file *file)279{280 struct sof_mtrace_core_data *core_data = inode->i_private;281 282 debugfs_file_put(file->f_path.dentry);283 284 mutex_lock(&core_data->buffer_lock);285 kfree(core_data->log_buffer);286 core_data->log_buffer = NULL;287 mutex_unlock(&core_data->buffer_lock);288 289 return 0;290}291 292static const struct file_operations sof_dfs_mtrace_fops = {293 .open = sof_ipc4_mtrace_dfs_open,294 .read = sof_ipc4_mtrace_dfs_read,295 .llseek = default_llseek,296 .release = sof_ipc4_mtrace_dfs_release,297 298 .owner = THIS_MODULE,299};300 301static ssize_t sof_ipc4_priority_mask_dfs_read(struct file *file, char __user *to,302 size_t count, loff_t *ppos)303{304 struct sof_mtrace_priv *priv = file->private_data;305 int i, ret, offset, remaining;306 char *buf;307 308 /*309 * one entry (14 char + new line = 15):310 * " 0: 000001ef"311 *312 * 16 * 15 + 1 = 241313 */314 buf = kzalloc(241, GFP_KERNEL);315 if (!buf)316 return -ENOMEM;317 318 for (i = 0; i < MAX_ALLOWED_LIBRARIES; i++) {319 offset = strlen(buf);320 remaining = 241 - offset;321 snprintf(buf + offset, remaining, "%2d: 0x%08x\n", i,322 priv->state_info.logs_priorities_mask[i]);323 }324 325 ret = simple_read_from_buffer(to, count, ppos, buf, strlen(buf));326 327 kfree(buf);328 return ret;329}330 331static ssize_t sof_ipc4_priority_mask_dfs_write(struct file *file,332 const char __user *from,333 size_t count, loff_t *ppos)334{335 struct sof_mtrace_priv *priv = file->private_data;336 unsigned int id;337 char *buf;338 u32 mask;339 int ret;340 341 /*342 * To update Nth mask entry, write:343 * "N,0x1234" or "N,1234" to the debugfs file344 * The mask will be interpreted as hexadecimal number345 */346 buf = memdup_user_nul(from, count);347 if (IS_ERR(buf))348 return PTR_ERR(buf);349 350 ret = sscanf(buf, "%u,0x%x", &id, &mask);351 if (ret != 2) {352 ret = sscanf(buf, "%u,%x", &id, &mask);353 if (ret != 2) {354 ret = -EINVAL;355 goto out;356 }357 }358 359 if (id >= MAX_ALLOWED_LIBRARIES) {360 ret = -EINVAL;361 goto out;362 }363 364 priv->state_info.logs_priorities_mask[id] = mask;365 ret = count;366 367out:368 kfree(buf);369 return ret;370}371 372static const struct file_operations sof_dfs_priority_mask_fops = {373 .open = simple_open,374 .read = sof_ipc4_priority_mask_dfs_read,375 .write = sof_ipc4_priority_mask_dfs_write,376 .llseek = default_llseek,377 378 .owner = THIS_MODULE,379};380 381static int mtrace_debugfs_create(struct snd_sof_dev *sdev)382{383 struct sof_mtrace_priv *priv = sdev->fw_trace_data;384 struct dentry *dfs_root;385 char dfs_name[100];386 int i;387 388 dfs_root = debugfs_create_dir("mtrace", sdev->debugfs_root);389 if (IS_ERR_OR_NULL(dfs_root))390 return 0;391 392 /* Create files for the logging parameters */393 debugfs_create_u32("aging_timer_period", 0644, dfs_root,394 &priv->state_info.aging_timer_period);395 debugfs_create_u32("fifo_full_timer_period", 0644, dfs_root,396 &priv->state_info.fifo_full_timer_period);397 debugfs_create_file("logs_priorities_mask", 0644, dfs_root, priv,398 &sof_dfs_priority_mask_fops);399 400 /* Separate log files per core */401 for (i = 0; i < sdev->num_cores; i++) {402 snprintf(dfs_name, sizeof(dfs_name), "core%d", i);403 debugfs_create_file(dfs_name, 0444, dfs_root, &priv->cores[i],404 &sof_dfs_mtrace_fops);405 }406 407 return 0;408}409 410static int ipc4_mtrace_enable(struct snd_sof_dev *sdev)411{412 struct sof_mtrace_priv *priv = sdev->fw_trace_data;413 const struct sof_ipc_ops *iops = sdev->ipc->ops;414 struct sof_ipc4_msg msg;415 u64 system_time;416 int ret;417 418 if (priv->mtrace_state != SOF_MTRACE_DISABLED)419 return 0;420 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);426 427 /*428 * local_clock() is used to align with dmesg, so both kernel and firmware logs have429 * the same base and a minor delta due to the IPC. system time is in us format but430 * local_clock() returns the time in ns, so convert to ns.431 */432 system_time = div64_u64(local_clock(), NSEC_PER_USEC);433 msg.data_size = sizeof(system_time);434 msg.data_ptr = &system_time;435 ret = iops->set_get_data(sdev, &msg, msg.data_size, true);436 if (ret)437 return ret;438 439 msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);440 441 priv->state_info.enable = 1;442 443 msg.data_size = sizeof(priv->state_info);444 msg.data_ptr = &priv->state_info;445 446 priv->mtrace_state = SOF_MTRACE_INITIALIZING;447 ret = iops->set_get_data(sdev, &msg, msg.data_size, true);448 if (ret) {449 priv->mtrace_state = SOF_MTRACE_DISABLED;450 return ret;451 }452 453 priv->mtrace_state = SOF_MTRACE_ENABLED;454 455 return 0;456}457 458static void ipc4_mtrace_disable(struct snd_sof_dev *sdev)459{460 struct sof_mtrace_priv *priv = sdev->fw_trace_data;461 const struct sof_ipc_ops *iops = sdev->ipc->ops;462 struct sof_ipc4_msg msg;463 int i;464 465 if (priv->mtrace_state == SOF_MTRACE_DISABLED)466 return;467 468 msg.primary = SOF_IPC4_MSG_TARGET(SOF_IPC4_MODULE_MSG);469 msg.primary |= SOF_IPC4_MSG_DIR(SOF_IPC4_MSG_REQUEST);470 msg.primary |= SOF_IPC4_MOD_ID(SOF_IPC4_MOD_INIT_BASEFW_MOD_ID);471 msg.primary |= SOF_IPC4_MOD_INSTANCE(SOF_IPC4_MOD_INIT_BASEFW_INSTANCE_ID);472 msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);473 474 priv->state_info.enable = 0;475 476 msg.data_size = sizeof(priv->state_info);477 msg.data_ptr = &priv->state_info;478 iops->set_get_data(sdev, &msg, msg.data_size, true);479 480 priv->mtrace_state = SOF_MTRACE_DISABLED;481 482 for (i = 0; i < sdev->num_cores; i++) {483 struct sof_mtrace_core_data *core_data = &priv->cores[i];484 485 core_data->host_read_ptr = 0;486 core_data->dsp_write_ptr = 0;487 wake_up(&core_data->trace_sleep);488 }489}490 491/*492 * Each DSP core logs to a dedicated slot.493 * Parse the slot descriptors at debug_box offset to find the debug log slots494 * and map them to cores.495 * There are 15 slots and therefore 15 descriptors to check (MAX_MTRACE_SLOTS)496 */497static void sof_mtrace_find_core_slots(struct snd_sof_dev *sdev)498{499 struct sof_mtrace_priv *priv = sdev->fw_trace_data;500 struct sof_mtrace_core_data *core_data;501 u32 slot_desc_type_offset, type, core;502 int i;503 504 for (i = 0; i < SOF_IPC4_MAX_DEBUG_SLOTS; i++) {505 /* The type is the second u32 in the slot descriptor */506 slot_desc_type_offset = sdev->debug_box.offset;507 slot_desc_type_offset += SOF_IPC4_DEBUG_DESCRIPTOR_SIZE * i + sizeof(u32);508 sof_mailbox_read(sdev, slot_desc_type_offset, &type, sizeof(type));509 510 if ((type & SOF_MTRACE_SLOT_TYPE_MASK) == SOF_IPC4_DEBUG_SLOT_DEBUG_LOG) {511 core = type & SOF_MTRACE_SLOT_CORE_MASK;512 513 if (core >= sdev->num_cores) {514 dev_dbg(sdev->dev, "core%u is invalid for slot%d\n",515 core, i);516 continue;517 }518 519 core_data = &priv->cores[core];520 /*521 * The area reserved for descriptors have the same size522 * as a slot.523 * In other words: slot0 starts at524 * debug_box + SOF_MTRACE_SLOT_SIZE offset525 */526 core_data->slot_offset = sdev->debug_box.offset;527 core_data->slot_offset += SOF_IPC4_DEBUG_SLOT_SIZE * (i + 1);528 dev_dbg(sdev->dev, "slot%d is used for core%u\n", i, core);529 if (core_data->delayed_pos_update) {530 sof_ipc4_mtrace_update_pos(sdev, core);531 core_data->delayed_pos_update = false;532 }533 } else if (type) {534 dev_dbg(sdev->dev, "slot%d is not a log slot (%#x)\n", i, type);535 }536 }537}538 539static int ipc4_mtrace_init(struct snd_sof_dev *sdev)540{541 struct sof_ipc4_fw_data *ipc4_data = sdev->private;542 struct sof_mtrace_priv *priv;543 int i, ret;544 545 if (sdev->fw_trace_data) {546 dev_err(sdev->dev, "fw_trace_data has been already allocated\n");547 return -EBUSY;548 }549 550 if (!ipc4_data->mtrace_log_bytes ||551 ipc4_data->mtrace_type != SOF_IPC4_MTRACE_INTEL_CAVS_2) {552 sdev->fw_trace_is_supported = false;553 return 0;554 }555 556 priv = devm_kzalloc(sdev->dev, struct_size(priv, cores, sdev->num_cores),557 GFP_KERNEL);558 if (!priv)559 return -ENOMEM;560 561 sdev->fw_trace_data = priv;562 563 /* Set initial values for mtrace parameters */564 priv->state_info.aging_timer_period = DEFAULT_AGING_TIMER_PERIOD_MS;565 priv->state_info.fifo_full_timer_period = DEFAULT_FIFO_FULL_TIMER_PERIOD_MS;566 /* Only enable basefw logs initially (index 0 is always basefw) */567 priv->state_info.logs_priorities_mask[0] = DEFAULT_LOGS_PRIORITIES_MASK;568 569 for (i = 0; i < sdev->num_cores; i++) {570 struct sof_mtrace_core_data *core_data = &priv->cores[i];571 572 init_waitqueue_head(&core_data->trace_sleep);573 mutex_init(&core_data->buffer_lock);574 core_data->sdev = sdev;575 core_data->id = i;576 }577 578 ret = ipc4_mtrace_enable(sdev);579 if (ret) {580 /*581 * Mark firmware tracing as not supported and return 0 to not582 * block the whole audio stack583 */584 sdev->fw_trace_is_supported = false;585 dev_dbg(sdev->dev, "initialization failed, fw tracing is disabled\n");586 return 0;587 }588 589 sof_mtrace_find_core_slots(sdev);590 591 ret = mtrace_debugfs_create(sdev);592 if (ret)593 ipc4_mtrace_disable(sdev);594 595 return ret;596}597 598static void ipc4_mtrace_free(struct snd_sof_dev *sdev)599{600 ipc4_mtrace_disable(sdev);601}602 603static int sof_ipc4_mtrace_update_pos_all_cores(struct snd_sof_dev *sdev)604{605 int i;606 607 for (i = 0; i < sdev->num_cores; i++)608 sof_ipc4_mtrace_update_pos(sdev, i);609 610 return 0;611}612 613int sof_ipc4_mtrace_update_pos(struct snd_sof_dev *sdev, int core)614{615 struct sof_mtrace_priv *priv = sdev->fw_trace_data;616 struct sof_mtrace_core_data *core_data;617 618 if (!sdev->fw_trace_is_supported ||619 priv->mtrace_state == SOF_MTRACE_DISABLED)620 return 0;621 622 if (core >= sdev->num_cores)623 return -EINVAL;624 625 core_data = &priv->cores[core];626 627 if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET) {628 core_data->delayed_pos_update = true;629 return 0;630 }631 632 /* Read out the dsp_write_ptr from the slot for this core */633 sof_mailbox_read(sdev, core_data->slot_offset + sizeof(u32),634 &core_data->dsp_write_ptr, 4);635 core_data->dsp_write_ptr -= core_data->dsp_write_ptr % 4;636 637 if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))638 dev_dbg(sdev->dev, "core%d, host read: %#x, dsp write: %#x",639 core, core_data->host_read_ptr, core_data->dsp_write_ptr);640 641 wake_up(&core_data->trace_sleep);642 643 return 0;644}645 646static void ipc4_mtrace_fw_crashed(struct snd_sof_dev *sdev)647{648 /*649 * The DSP might not be able to send SOF_IPC4_NOTIFY_LOG_BUFFER_STATUS650 * messages anymore, so check the log buffer status on all651 * cores and process any pending messages.652 */653 sof_ipc4_mtrace_update_pos_all_cores(sdev);654}655 656static int ipc4_mtrace_resume(struct snd_sof_dev *sdev)657{658 return ipc4_mtrace_enable(sdev);659}660 661static void ipc4_mtrace_suspend(struct snd_sof_dev *sdev, pm_message_t pm_state)662{663 ipc4_mtrace_disable(sdev);664}665 666const struct sof_ipc_fw_tracing_ops ipc4_mtrace_ops = {667 .init = ipc4_mtrace_init,668 .free = ipc4_mtrace_free,669 .fw_crashed = ipc4_mtrace_fw_crashed,670 .suspend = ipc4_mtrace_suspend,671 .resume = ipc4_mtrace_resume,672};673