Linux 6.13-rc6

[linux.git] / sound / soc / sof / ipc4-mtrace.c

// SPDX-License-Identifier: GPL-2.0-only
//
// Copyright(c) 2022 Intel Corporation

#include <linux/debugfs.h>
#include <linux/sched/signal.h>
#include <linux/sched/clock.h>
#include <sound/sof/ipc4/header.h>
#include "sof-priv.h"
#include "ipc4-priv.h"

/*
 * debug info window is organized in 16 (equal sized) pages:
 *
 *      ------------------------
 *      | Page0  - descriptors |
 *      ------------------------
 *      | Page1  - slot0       |
 *      ------------------------
 *      | Page2  - slot1       |
 *      ------------------------
 *      |         ...          |
 *      ------------------------
 *      | Page14  - slot13     |
 *      ------------------------
 *      | Page15  - slot14     |
 *      ------------------------
 *
 * The slot size == page size
 *
 * The first page contains descriptors for the remaining 15 cores
 * The slot descriptor is:
 * u32 res_id;
 * u32 type;
 * u32 vma;
 *
 * Log buffer slots have the following layout:
 * u32 host_read_ptr;
 * u32 dsp_write_ptr;
 * u8 buffer[];
 *
 * The two pointers are offsets within the buffer.
 */

#define FW_EPOCH_DELTA                          11644473600LL

#define MAX_ALLOWED_LIBRARIES                   16

#define SOF_IPC4_INVALID_SLOT_OFFSET            0xffffffff

 /* for debug and critical types */
#define SOF_MTRACE_SLOT_CORE_MASK               GENMASK(7, 0)
#define SOF_MTRACE_SLOT_TYPE_MASK               GENMASK(31, 8)

#define DEFAULT_AGING_TIMER_PERIOD_MS           0x100
#define DEFAULT_FIFO_FULL_TIMER_PERIOD_MS       0x1000

/* ipc4 log level and source definitions for logs_priorities_mask */
#define SOF_MTRACE_LOG_LEVEL_CRITICAL           BIT(0)
#define SOF_MTRACE_LOG_LEVEL_ERROR              BIT(1)
#define SOF_MTRACE_LOG_LEVEL_WARNING            BIT(2)
#define SOF_MTRACE_LOG_LEVEL_INFO               BIT(3)
#define SOF_MTRACE_LOG_LEVEL_VERBOSE            BIT(4)
#define SOF_MTRACE_LOG_SOURCE_INFRA             BIT(5) /* log source 0 */
#define SOF_MTRACE_LOG_SOURCE_HAL               BIT(6)
#define SOF_MTRACE_LOG_SOURCE_MODULE            BIT(7)
#define SOF_MTRACE_LOG_SOURCE_AUDIO             BIT(8)
#define SOF_MTRACE_LOG_SOURCE_SCHEDULER         BIT(9)
#define SOF_MTRACE_LOG_SOURCE_ULP_INFRA         BIT(10)
#define SOF_MTRACE_LOG_SOURCE_ULP_MODULE        BIT(11)
#define SOF_MTRACE_LOG_SOURCE_VISION            BIT(12) /* log source 7 */
#define DEFAULT_LOGS_PRIORITIES_MASK    (SOF_MTRACE_LOG_LEVEL_CRITICAL | \
                                         SOF_MTRACE_LOG_LEVEL_ERROR |    \
                                         SOF_MTRACE_LOG_LEVEL_WARNING |  \
                                         SOF_MTRACE_LOG_LEVEL_INFO |     \
                                         SOF_MTRACE_LOG_SOURCE_INFRA |   \
                                         SOF_MTRACE_LOG_SOURCE_HAL |     \
                                         SOF_MTRACE_LOG_SOURCE_MODULE |  \
                                         SOF_MTRACE_LOG_SOURCE_AUDIO)

struct sof_log_state_info {
        u32 aging_timer_period;
        u32 fifo_full_timer_period;
        u32 enable;
        u32 logs_priorities_mask[MAX_ALLOWED_LIBRARIES];
} __packed;

enum sof_mtrace_state {
        SOF_MTRACE_DISABLED,
        SOF_MTRACE_INITIALIZING,
        SOF_MTRACE_ENABLED,
};

struct sof_mtrace_core_data {
        struct snd_sof_dev *sdev;

        int id;
        u32 slot_offset;
        void *log_buffer;
        struct mutex buffer_lock; /* for log_buffer alloc/free */
        u32 host_read_ptr;
        u32 dsp_write_ptr;
        /* pos update IPC arrived before the slot offset is known, queried */
        bool delayed_pos_update;
        wait_queue_head_t trace_sleep;
};

struct sof_mtrace_priv {
        struct snd_sof_dev *sdev;
        enum sof_mtrace_state mtrace_state;
        struct sof_log_state_info state_info;

        struct sof_mtrace_core_data cores[];
};

static int sof_ipc4_mtrace_dfs_open(struct inode *inode, struct file *file)
{
        struct sof_mtrace_core_data *core_data = inode->i_private;
        int ret;

        mutex_lock(&core_data->buffer_lock);

        if (core_data->log_buffer) {
                ret = -EBUSY;
                goto out;
        }

        ret = debugfs_file_get(file->f_path.dentry);
        if (unlikely(ret))
                goto out;

        core_data->log_buffer = kmalloc(SOF_IPC4_DEBUG_SLOT_SIZE, GFP_KERNEL);
        if (!core_data->log_buffer) {
                debugfs_file_put(file->f_path.dentry);
                ret = -ENOMEM;
                goto out;
        }

        ret = simple_open(inode, file);
        if (ret) {
                kfree(core_data->log_buffer);
                debugfs_file_put(file->f_path.dentry);
        }

out:
        mutex_unlock(&core_data->buffer_lock);

        return ret;
}

static bool sof_wait_mtrace_avail(struct sof_mtrace_core_data *core_data)
{
        wait_queue_entry_t wait;

        /* data immediately available */
        if (core_data->host_read_ptr != core_data->dsp_write_ptr)
                return true;

        /* wait for available trace data from FW */
        init_waitqueue_entry(&wait, current);
        set_current_state(TASK_INTERRUPTIBLE);
        add_wait_queue(&core_data->trace_sleep, &wait);

        if (!signal_pending(current)) {
                /* set timeout to max value, no error code */
                schedule_timeout(MAX_SCHEDULE_TIMEOUT);
        }
        remove_wait_queue(&core_data->trace_sleep, &wait);

        if (core_data->host_read_ptr != core_data->dsp_write_ptr)
                return true;

        return false;
}

static ssize_t sof_ipc4_mtrace_dfs_read(struct file *file, char __user *buffer,
                                        size_t count, loff_t *ppos)
{
        struct sof_mtrace_core_data *core_data = file->private_data;
        u32 log_buffer_offset, log_buffer_size, read_ptr, write_ptr;
        struct snd_sof_dev *sdev = core_data->sdev;
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        void *log_buffer = core_data->log_buffer;
        loff_t lpos = *ppos;
        u32 avail;
        int ret;

        /* check pos and count */
        if (lpos < 0)
                return -EINVAL;
        if (!count || count < sizeof(avail))
                return 0;

        /* get available count based on current host offset */
        if (!sof_wait_mtrace_avail(core_data)) {
                /* No data available */
                avail = 0;
                if (copy_to_user(buffer, &avail, sizeof(avail)))
                        return -EFAULT;

                return 0;
        }

        if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET)
                return 0;

        /* The log data buffer starts after the two pointer in the slot */
        log_buffer_offset =  core_data->slot_offset + (sizeof(u32) * 2);
        /* The log data size excludes the pointers */
        log_buffer_size = SOF_IPC4_DEBUG_SLOT_SIZE - (sizeof(u32) * 2);

        read_ptr = core_data->host_read_ptr;
        write_ptr = core_data->dsp_write_ptr;

        if (read_ptr < write_ptr)
                avail = write_ptr - read_ptr;
        else
                avail = log_buffer_size - read_ptr + write_ptr;

        if (!avail)
                return 0;

        if (avail > log_buffer_size)
                avail = log_buffer_size;

        /* Need space for the initial u32 of the avail */
        if (avail > count - sizeof(avail))
                avail = count - sizeof(avail);

        if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))
                dev_dbg(sdev->dev,
                        "core%d, host read: %#x, dsp write: %#x, avail: %#x\n",
                        core_data->id, read_ptr, write_ptr, avail);

        if (read_ptr < write_ptr) {
                /* Read data between read pointer and write pointer */
                sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer, avail);
        } else {
                /* read from read pointer to end of the slot */
                sof_mailbox_read(sdev, log_buffer_offset + read_ptr, log_buffer,
                                 avail - write_ptr);
                /* read from slot start to write pointer */
                if (write_ptr)
                        sof_mailbox_read(sdev, log_buffer_offset,
                                         (u8 *)(log_buffer) + avail - write_ptr,
                                         write_ptr);
        }

        /* first write the number of bytes we have gathered */
        ret = copy_to_user(buffer, &avail, sizeof(avail));
        if (ret)
                return -EFAULT;

        /* Followed by the data itself */
        ret = copy_to_user(buffer + sizeof(avail), log_buffer, avail);
        if (ret)
                return -EFAULT;

        /* Update the host_read_ptr in the slot for this core */
        read_ptr += avail;
        if (read_ptr >= log_buffer_size)
                read_ptr -= log_buffer_size;
        sof_mailbox_write(sdev, core_data->slot_offset, &read_ptr, sizeof(read_ptr));

        /* Only update the host_read_ptr if mtrace is enabled */
        if (priv->mtrace_state != SOF_MTRACE_DISABLED)
                core_data->host_read_ptr = read_ptr;

        /*
         * Ask for a new buffer from user space for the next chunk, not
         * streaming due to the heading number of bytes value.
         */
        *ppos += count;

        return count;
}

static int sof_ipc4_mtrace_dfs_release(struct inode *inode, struct file *file)
{
        struct sof_mtrace_core_data *core_data = inode->i_private;

        debugfs_file_put(file->f_path.dentry);

        mutex_lock(&core_data->buffer_lock);
        kfree(core_data->log_buffer);
        core_data->log_buffer = NULL;
        mutex_unlock(&core_data->buffer_lock);

        return 0;
}

static const struct file_operations sof_dfs_mtrace_fops = {
        .open = sof_ipc4_mtrace_dfs_open,
        .read = sof_ipc4_mtrace_dfs_read,
        .llseek = default_llseek,
        .release = sof_ipc4_mtrace_dfs_release,

        .owner = THIS_MODULE,
};

static ssize_t sof_ipc4_priority_mask_dfs_read(struct file *file, char __user *to,
                                               size_t count, loff_t *ppos)
{
        struct sof_mtrace_priv *priv = file->private_data;
        int i, ret, offset, remaining;
        char *buf;

        /*
         * one entry (14 char + new line = 15):
         * " 0: 000001ef"
         *
         * 16 * 15 + 1 = 241
         */
        buf = kzalloc(241, GFP_KERNEL);
        if (!buf)
                return -ENOMEM;

        for (i = 0; i < MAX_ALLOWED_LIBRARIES; i++) {
                offset = strlen(buf);
                remaining = 241 - offset;
                snprintf(buf + offset, remaining, "%2d: 0x%08x\n", i,
                         priv->state_info.logs_priorities_mask[i]);
        }

        ret = simple_read_from_buffer(to, count, ppos, buf, strlen(buf));

        kfree(buf);
        return ret;
}

static ssize_t sof_ipc4_priority_mask_dfs_write(struct file *file,
                                                const char __user *from,
                                                size_t count, loff_t *ppos)
{
        struct sof_mtrace_priv *priv = file->private_data;
        unsigned int id;
        char *buf;
        u32 mask;
        int ret;

        /*
         * To update Nth mask entry, write:
         * "N,0x1234" or "N,1234" to the debugfs file
         * The mask will be interpreted as hexadecimal number
         */
        buf = memdup_user_nul(from, count);
        if (IS_ERR(buf))
                return PTR_ERR(buf);

        ret = sscanf(buf, "%u,0x%x", &id, &mask);
        if (ret != 2) {
                ret = sscanf(buf, "%u,%x", &id, &mask);
                if (ret != 2) {
                        ret = -EINVAL;
                        goto out;
                }
        }

        if (id >= MAX_ALLOWED_LIBRARIES) {
                ret = -EINVAL;
                goto out;
        }

        priv->state_info.logs_priorities_mask[id] = mask;
        ret = count;

out:
        kfree(buf);
        return ret;
}

static const struct file_operations sof_dfs_priority_mask_fops = {
        .open = simple_open,
        .read = sof_ipc4_priority_mask_dfs_read,
        .write = sof_ipc4_priority_mask_dfs_write,
        .llseek = default_llseek,

        .owner = THIS_MODULE,
};

static int mtrace_debugfs_create(struct snd_sof_dev *sdev)
{
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        struct dentry *dfs_root;
        char dfs_name[100];
        int i;

        dfs_root = debugfs_create_dir("mtrace", sdev->debugfs_root);
        if (IS_ERR_OR_NULL(dfs_root))
                return 0;

        /* Create files for the logging parameters */
        debugfs_create_u32("aging_timer_period", 0644, dfs_root,
                           &priv->state_info.aging_timer_period);
        debugfs_create_u32("fifo_full_timer_period", 0644, dfs_root,
                           &priv->state_info.fifo_full_timer_period);
        debugfs_create_file("logs_priorities_mask", 0644, dfs_root, priv,
                            &sof_dfs_priority_mask_fops);

        /* Separate log files per core */
        for (i = 0; i < sdev->num_cores; i++) {
                snprintf(dfs_name, sizeof(dfs_name), "core%d", i);
                debugfs_create_file(dfs_name, 0444, dfs_root, &priv->cores[i],
                                    &sof_dfs_mtrace_fops);
        }

        return 0;
}

static int ipc4_mtrace_enable(struct snd_sof_dev *sdev)
{
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        const struct sof_ipc_ops *iops = sdev->ipc->ops;
        struct sof_ipc4_msg msg;
        u64 system_time;
        int ret;

        if (priv->mtrace_state != SOF_MTRACE_DISABLED)
                return 0;

        msg.primary = SOF_IPC4_MSG_TARGET(SOF_IPC4_MODULE_MSG);
        msg.primary |= SOF_IPC4_MSG_DIR(SOF_IPC4_MSG_REQUEST);
        msg.primary |= SOF_IPC4_MOD_ID(SOF_IPC4_MOD_INIT_BASEFW_MOD_ID);
        msg.primary |= SOF_IPC4_MOD_INSTANCE(SOF_IPC4_MOD_INIT_BASEFW_INSTANCE_ID);
        msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_SYSTEM_TIME);

        /*
         * local_clock() is used to align with dmesg, so both kernel and firmware logs have
         * the same base and a minor delta due to the IPC. system time is in us format but
         * local_clock() returns the time in ns, so convert to ns.
         */
        system_time = div64_u64(local_clock(), NSEC_PER_USEC);
        msg.data_size = sizeof(system_time);
        msg.data_ptr = &system_time;
        ret = iops->set_get_data(sdev, &msg, msg.data_size, true);
        if (ret)
                return ret;

        msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);

        priv->state_info.enable = 1;

        msg.data_size = sizeof(priv->state_info);
        msg.data_ptr = &priv->state_info;

        priv->mtrace_state = SOF_MTRACE_INITIALIZING;
        ret = iops->set_get_data(sdev, &msg, msg.data_size, true);
        if (ret) {
                priv->mtrace_state = SOF_MTRACE_DISABLED;
                return ret;
        }

        priv->mtrace_state = SOF_MTRACE_ENABLED;

        return 0;
}

static void ipc4_mtrace_disable(struct snd_sof_dev *sdev)
{
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        const struct sof_ipc_ops *iops = sdev->ipc->ops;
        struct sof_ipc4_msg msg;
        int i;

        if (priv->mtrace_state == SOF_MTRACE_DISABLED)
                return;

        msg.primary = SOF_IPC4_MSG_TARGET(SOF_IPC4_MODULE_MSG);
        msg.primary |= SOF_IPC4_MSG_DIR(SOF_IPC4_MSG_REQUEST);
        msg.primary |= SOF_IPC4_MOD_ID(SOF_IPC4_MOD_INIT_BASEFW_MOD_ID);
        msg.primary |= SOF_IPC4_MOD_INSTANCE(SOF_IPC4_MOD_INIT_BASEFW_INSTANCE_ID);
        msg.extension = SOF_IPC4_MOD_EXT_MSG_PARAM_ID(SOF_IPC4_FW_PARAM_ENABLE_LOGS);

        priv->state_info.enable = 0;

        msg.data_size = sizeof(priv->state_info);
        msg.data_ptr = &priv->state_info;
        iops->set_get_data(sdev, &msg, msg.data_size, true);

        priv->mtrace_state = SOF_MTRACE_DISABLED;

        for (i = 0; i < sdev->num_cores; i++) {
                struct sof_mtrace_core_data *core_data = &priv->cores[i];

                core_data->host_read_ptr = 0;
                core_data->dsp_write_ptr = 0;
                wake_up(&core_data->trace_sleep);
        }
}

/*
 * Each DSP core logs to a dedicated slot.
 * Parse the slot descriptors at debug_box offset to find the debug log slots
 * and map them to cores.
 * There are 15 slots and therefore 15 descriptors to check (MAX_MTRACE_SLOTS)
 */
static void sof_mtrace_find_core_slots(struct snd_sof_dev *sdev)
{
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        struct sof_mtrace_core_data *core_data;
        u32 slot_desc_type_offset, type, core;
        int i;

        for (i = 0; i < SOF_IPC4_MAX_DEBUG_SLOTS; i++) {
                /* The type is the second u32 in the slot descriptor */
                slot_desc_type_offset = sdev->debug_box.offset;
                slot_desc_type_offset += SOF_IPC4_DEBUG_DESCRIPTOR_SIZE * i + sizeof(u32);
                sof_mailbox_read(sdev, slot_desc_type_offset, &type, sizeof(type));

                if ((type & SOF_MTRACE_SLOT_TYPE_MASK) == SOF_IPC4_DEBUG_SLOT_DEBUG_LOG) {
                        core = type & SOF_MTRACE_SLOT_CORE_MASK;

                        if (core >= sdev->num_cores) {
                                dev_dbg(sdev->dev, "core%u is invalid for slot%d\n",
                                        core, i);
                                continue;
                        }

                        core_data = &priv->cores[core];
                        /*
                         * The area reserved for descriptors have the same size
                         * as a slot.
                         * In other words: slot0 starts at
                         * debug_box + SOF_MTRACE_SLOT_SIZE offset
                         */
                        core_data->slot_offset = sdev->debug_box.offset;
                        core_data->slot_offset += SOF_IPC4_DEBUG_SLOT_SIZE * (i + 1);
                        dev_dbg(sdev->dev, "slot%d is used for core%u\n", i, core);
                        if (core_data->delayed_pos_update) {
                                sof_ipc4_mtrace_update_pos(sdev, core);
                                core_data->delayed_pos_update = false;
                        }
                } else if (type) {
                        dev_dbg(sdev->dev, "slot%d is not a log slot (%#x)\n", i, type);
                }
        }
}

static int ipc4_mtrace_init(struct snd_sof_dev *sdev)
{
        struct sof_ipc4_fw_data *ipc4_data = sdev->private;
        struct sof_mtrace_priv *priv;
        int i, ret;

        if (sdev->fw_trace_data) {
                dev_err(sdev->dev, "fw_trace_data has been already allocated\n");
                return -EBUSY;
        }

        if (!ipc4_data->mtrace_log_bytes ||
            ipc4_data->mtrace_type != SOF_IPC4_MTRACE_INTEL_CAVS_2) {
                sdev->fw_trace_is_supported = false;
                return 0;
        }

        priv = devm_kzalloc(sdev->dev, struct_size(priv, cores, sdev->num_cores),
                            GFP_KERNEL);
        if (!priv)
                return -ENOMEM;

        sdev->fw_trace_data = priv;

        /* Set initial values for mtrace parameters */
        priv->state_info.aging_timer_period = DEFAULT_AGING_TIMER_PERIOD_MS;
        priv->state_info.fifo_full_timer_period = DEFAULT_FIFO_FULL_TIMER_PERIOD_MS;
        /* Only enable basefw logs initially (index 0 is always basefw) */
        priv->state_info.logs_priorities_mask[0] = DEFAULT_LOGS_PRIORITIES_MASK;

        for (i = 0; i < sdev->num_cores; i++) {
                struct sof_mtrace_core_data *core_data = &priv->cores[i];

                init_waitqueue_head(&core_data->trace_sleep);
                mutex_init(&core_data->buffer_lock);
                core_data->sdev = sdev;
                core_data->id = i;
        }

        ret = ipc4_mtrace_enable(sdev);
        if (ret) {
                /*
                 * Mark firmware tracing as not supported and return 0 to not
                 * block the whole audio stack
                 */
                sdev->fw_trace_is_supported = false;
                dev_dbg(sdev->dev, "initialization failed, fw tracing is disabled\n");
                return 0;
        }

        sof_mtrace_find_core_slots(sdev);

        ret = mtrace_debugfs_create(sdev);
        if (ret)
                ipc4_mtrace_disable(sdev);

        return ret;
}

static void ipc4_mtrace_free(struct snd_sof_dev *sdev)
{
        ipc4_mtrace_disable(sdev);
}

static int sof_ipc4_mtrace_update_pos_all_cores(struct snd_sof_dev *sdev)
{
        int i;

        for (i = 0; i < sdev->num_cores; i++)
                sof_ipc4_mtrace_update_pos(sdev, i);

        return 0;
}

int sof_ipc4_mtrace_update_pos(struct snd_sof_dev *sdev, int core)
{
        struct sof_mtrace_priv *priv = sdev->fw_trace_data;
        struct sof_mtrace_core_data *core_data;

        if (!sdev->fw_trace_is_supported ||
            priv->mtrace_state == SOF_MTRACE_DISABLED)
                return 0;

        if (core >= sdev->num_cores)
                return -EINVAL;

        core_data = &priv->cores[core];

        if (core_data->slot_offset == SOF_IPC4_INVALID_SLOT_OFFSET) {
                core_data->delayed_pos_update = true;
                return 0;
        }

        /* Read out the dsp_write_ptr from the slot for this core */
        sof_mailbox_read(sdev, core_data->slot_offset + sizeof(u32),
                         &core_data->dsp_write_ptr, 4);
        core_data->dsp_write_ptr -= core_data->dsp_write_ptr % 4;

        if (sof_debug_check_flag(SOF_DBG_PRINT_DMA_POSITION_UPDATE_LOGS))
                dev_dbg(sdev->dev, "core%d, host read: %#x, dsp write: %#x",
                        core, core_data->host_read_ptr, core_data->dsp_write_ptr);

        wake_up(&core_data->trace_sleep);

        return 0;
}

static void ipc4_mtrace_fw_crashed(struct snd_sof_dev *sdev)
{
        /*
         * The DSP might not be able to send SOF_IPC4_NOTIFY_LOG_BUFFER_STATUS
         * messages anymore, so check the log buffer status on all
         * cores and process any pending messages.
         */
        sof_ipc4_mtrace_update_pos_all_cores(sdev);
}

static int ipc4_mtrace_resume(struct snd_sof_dev *sdev)
{
        return ipc4_mtrace_enable(sdev);
}

static void ipc4_mtrace_suspend(struct snd_sof_dev *sdev, pm_message_t pm_state)
{
        ipc4_mtrace_disable(sdev);
}

const struct sof_ipc_fw_tracing_ops ipc4_mtrace_ops = {
        .init = ipc4_mtrace_init,
        .free = ipc4_mtrace_free,
        .fw_crashed = ipc4_mtrace_fw_crashed,
        .suspend = ipc4_mtrace_suspend,
        .resume = ipc4_mtrace_resume,
};