EDGEML-8777 - [Linux NPU Driver]: Support firmware log buffer

[Why]
  Log buffer support is required to enhance debugging support on NPU stack

[How]
  1. Allocate log buffer and share with firmware via 'start_event_trace' message
     Config start_event_trace request param, send via mgmt channel.
     Handle the send buffer resp.
  2. Receive interrupt about log buffer half fullness from firmware.
     Handle interrupt, process further buffer data and update buffer head_offset for FW.
  3. Add stop_event_trace_send api and it's handle to stop logging when aie2 shutdown.

Signed-off-by: vinit shukla <vinitkumar.shukla@amd.com>

src/driver/amdxdna/Kbuild

@@ -31,6 +31,7 @@ amdxdna-y := \
 	aie2_error.o \
 	aie2_debugfs.o \
 	aie2_message.o \
+	aie2_event_trace.o \
 	aie2_pm.o \
 	aie2_pci.o \
 	npu1_regs.o \

src/driver/amdxdna/aie2_event_trace.c

@@ -0,0 +1,222 @@
+// SPDX-License-Identifier: GPL-2.0
+/*
+ * Copyright (C) 2025, Advanced Micro Devices, Inc.
+ */
+
+#include <linux/kthread.h>
+#include <linux/kernel.h>
+#include <linux/dma-mapping.h>
+#include <drm/drm_cache.h>
+#include "aie2_msg_priv.h"
+#include "aie2_pci.h"
+#include "amdxdna_trace.h"
+#include "amdxdna_mailbox.h"
+
+#define LOG_BUFFER_IRQ 27
+#define MPIPU_IOHUB_INT_27_ALIAS 0xD7008
+#define LOG_BUFFER_MAILBOX MPIPU_IOHUB_INT_27_ALIAS
+
+uint8_t g_fwLogBuf[TRACE_EVENT_BUFFER_SIZE];
+
+struct trace_event_metadata {
+	uint64_t tail_offset;
+	uint64_t head_offset;
+	uint32_t padding[12];
+};
+
+struct trace_event_log_data {
+	uint64_t counter;
+	uint16_t payload_hi;
+	uint16_t type;
+	uint32_t payload_low;
+};
+
+void aie2_set_trace_timestamp(struct amdxdna_dev_hdl *ndev, uint32_t *resp)
+{
+	struct start_event_trace_resp *trace_resp = (struct start_event_trace_resp *)resp;
+
+	ndev->event_trace_req->resp_timestamp = trace_resp->current_timestamp;
+
+}
+
+uint32_t aie2_get_trace_event_content(struct event_trace_req_buf *trace_req_buf, uint8_t *kern_buf)
+{
+	u8 *sysBuf;
+	uint32_t rd_ptr, wr_ptr, wr_ptr_wrap;
+	// Log size is the size of the log content in the trace buff in bytes.
+	uint32_t total_log_size = 0, log_size = 0;
+	uint32_t rb_size, offset = 0;
+	struct trace_event_metadata *trace_metadata;
+	struct amdxdna_dev_hdl *ndev = trace_req_buf->ndev;
+
+	sysBuf = (u8 *)trace_req_buf->buf;
+	rb_size = TRACE_EVENT_BUFFER_SIZE - 64;
+	if (rb_size == 0)
+		return 0;
+
+	trace_metadata = (struct trace_event_metadata *)(sysBuf + rb_size);
+	if (!trace_metadata) {
+		XDNA_ERR(ndev->xdna, "FW trace buffer metadata is null!");
+		return 0;
+	}
+
+	// Get the ring buffer read and write pointers, update the ring buffer content size
+	rd_ptr = (uint32_t)(trace_metadata->head_offset % rb_size);
+	wr_ptr = (uint32_t)(trace_metadata->tail_offset);
+	wr_ptr_wrap = wr_ptr % rb_size;
+
+	// Update the Ring Buffer read pointer
+	trace_metadata->head_offset = wr_ptr;
+	// Clear the log buffer interrupt
+	clear_logbuff_irq(LOG_BUFFER_MAILBOX, ndev);
+
+	do {
+		if (wr_ptr_wrap > rd_ptr)
+			log_size = wr_ptr_wrap - rd_ptr;
+		else if (wr_ptr_wrap < rd_ptr)
+			log_size = rb_size - rd_ptr;
+		else
+			return 0;
+
+		if (log_size > rb_size) {
+			XDNA_ERR(ndev->xdna, "log_size > rb_size");
+			return 0;
+		}
+		// Copy the ring buffer content to the kernel buffer
+		memcpy(kern_buf + offset, (u8 *)(sysBuf + rd_ptr), log_size);
+
+		offset += log_size;
+		total_log_size += log_size;
+		rd_ptr = (rd_ptr + log_size) % rb_size;
+	} while (rd_ptr < wr_ptr_wrap); // If the buffer is rolling over, continue to copy the content
+
+	return total_log_size;
+}
+
+void aie2_print_trace_event_log(struct amdxdna_dev_hdl *ndev)
+{
+	uint32_t log_size;
+	uint64_t payload;
+	struct event_trace_req_buf *trace_req_buf;
+	struct trace_event_log_data *log_content;
+
+	trace_req_buf = ndev->event_trace_req;
+
+	if (!trace_req_buf) {
+		XDNA_ERR(ndev->xdna, "FW resp trace buffer is null!");
+		return;
+	}
+
+	log_size = aie2_get_trace_event_content(trace_req_buf, g_fwLogBuf);
+	XDNA_INFO(ndev->xdna, "FW log size in bytes %u", log_size);
+
+	if (log_size) {
+		uint64_t fwTicks;
+		char *str = (char *)g_fwLogBuf;
+		char *end = ((char *)str + log_size);
+
+		g_fwLogBuf[log_size] = 0;
+
+		// Print the raw counter value from NPU first
+		while (str < end) {
+			log_content = (struct trace_event_log_data *)str;
+			payload = (uint64_t)((uint64_t)(log_content->payload_hi) << 32 | log_content->payload_low);
+			fwTicks = log_content->counter - trace_req_buf->resp_timestamp;
+			XDNA_INFO(ndev->xdna, "[%llu][FW] type: 0x%04x payload:0x%016llx", fwTicks, log_content->type, payload);
+			str += MAX_ONE_TIME_LOG_INFO_LEN;
+		}
+	}
+}
+
+static irqreturn_t log_buffer_irq_handler(int irq, void *data)
+{
+	struct amdxdna_dev_hdl *ndev = (struct amdxdna_dev_hdl *)data;
+
+	if (!ndev) {
+		XDNA_INFO(ndev->xdna, "xdna dev is null !");
+		return IRQ_NONE;
+	}
+
+	trace_mbox_irq_handle("LOG_BUFFER", irq);
+	aie2_print_trace_event_log(ndev);
+	return IRQ_HANDLED;
+}
+
+int aie2_stop_event_trace_send(struct amdxdna_dev_hdl *ndev)
+{
+	struct amdxdna_dev *xdna = ndev->xdna;
+
+	drm_WARN_ON(&xdna->ddev, !mutex_is_locked(&xdna->dev_lock));
+	return aie2_stop_event_trace(ndev);
+}
+
+int aie2_event_trace_alloc(struct amdxdna_dev_hdl *ndev)
+{
+	int ret;
+	struct amdxdna_dev *xdna = ndev->xdna;
+	struct event_trace_req_buf *req_buf;
+
+	req_buf = kzalloc(sizeof(struct event_trace_req_buf), GFP_KERNEL);
+	if (!req_buf)
+		return -ENOMEM;
+
+	req_buf->buf = dma_alloc_noncoherent(xdna->ddev.dev, TRACE_EVENT_BUFFER_SIZE, (dma_addr_t *)&req_buf->trace_req.dram_buffer_address,
+						DMA_BIDIRECTIONAL, GFP_KERNEL);
+	if (!req_buf->buf) {
+		ret = -ENOMEM;
+		goto free_event_trace_req_buf;
+	}
+	req_buf->trace_req.dram_buffer_size = TRACE_EVENT_BUFFER_SIZE;
+	ndev->event_trace_req = req_buf;
+	req_buf->ndev = ndev;
+
+	req_buf->log_ch_irq = pci_irq_vector(to_pci_dev(xdna->ddev.dev), LOG_BUFFER_IRQ);
+	ret = request_irq(req_buf->log_ch_irq, log_buffer_irq_handler, 0, "LOG_BUFFER", ndev);
+	if (ret) {
+		XDNA_ERR(xdna, "Failed to register irq %d ret %d", LOG_BUFFER_IRQ, ret);
+		goto free_event_trace_req_buf;
+	}
+
+	XDNA_INFO(xdna, "Start event trace buf addr: 0x%llx size 0x%x", req_buf->trace_req.dram_buffer_address,
+			  req_buf->trace_req.dram_buffer_size);
+	return 0;
+
+free_event_trace_req_buf:
+	kfree(req_buf);
+	return ret;
+}
+
+void aie2_event_trace_free(struct amdxdna_dev_hdl *ndev)
+{
+	struct amdxdna_dev *xdna = ndev->xdna;
+	struct event_trace_req_buf *req_buf = ndev->event_trace_req;
+
+	if (!req_buf)
+		return;
+
+	dma_free_noncoherent(xdna->ddev.dev, req_buf->trace_req.dram_buffer_size, req_buf->buf,
+					(dma_addr_t)req_buf->trace_req.dram_buffer_address, DMA_BIDIRECTIONAL);
+	free_irq(req_buf->log_ch_irq, ndev);
+	kfree(req_buf);
+}
+
+int aie2_start_event_trace_send(struct amdxdna_dev_hdl *ndev)
+{
+	int ret;
+	struct event_trace_req_buf *trace_req_buf = NULL;
+	struct amdxdna_dev *xdna = ndev->xdna;
+
+	ret = aie2_event_trace_alloc(ndev);
+
+	if (!ret) {
+		trace_req_buf = ndev->event_trace_req;
+		drm_WARN_ON(&xdna->ddev, !mutex_is_locked(&xdna->dev_lock));
+		drm_clflush_virt_range(trace_req_buf->buf, trace_req_buf->trace_req.dram_buffer_size);
+		ret = aie2_start_event_trace(ndev, trace_req_buf->trace_req.dram_buffer_address,
+									 trace_req_buf->trace_req.dram_buffer_size, &trace_req_buf->trace_req);
+	} else {
+		XDNA_ERR(xdna, "Failed to allocate and register event trace");
+	}
+
+	return ret;
+}

src/driver/amdxdna/aie2_message.c

@@ -16,6 +16,9 @@
 #define DECLARE_AIE2_MSG(name, op) \
 	DECLARE_XDNA_MSG_COMMON(name, op, MAX_AIE2_STATUS_CODE)
 
+#define DECLARE_AIE2_STOP_EVENT_TRACE_MSG(name, op) \
+	DECLARE_XDNA_STOP_EVENT_TRACE_MSG(name, op, MAX_AIE2_STATUS_CODE)
+
 #define aie2_send_mgmt_msg_wait(ndev, msg) \
 	aie2_send_mgmt_msg_wait_offset(ndev, msg, 0)
 
@@ -66,6 +69,9 @@ aie2_send_mgmt_msg_wait_offset(struct amdxdna_dev_hdl *ndev,
 		XDNA_ERR(xdna, "command opcode 0x%x failed, status 0x%x",
 			 msg->opcode, *hdl->data);
 		ret = -EINVAL;
+	} else {
+		if (msg->opcode == MSG_OP_START_EVENT_TRACE)
+			aie2_set_trace_timestamp(ndev, hdl->data);
 	}
 
 	return ret;
@@ -255,6 +261,29 @@ int aie2_query_firmware_version(struct amdxdna_dev_hdl *ndev,
 	return 0;
 }
 
+int aie2_start_event_trace(struct amdxdna_dev_hdl *ndev, dma_addr_t addr,
+										u32 size, void *handle)
+{
+	DECLARE_AIE2_MSG(start_event_trace, MSG_OP_START_EVENT_TRACE);
+
+	req.dram_buffer_address = addr;
+	req.dram_buffer_size = size;
+	req.event_trace_dest = EVENT_TRACE_DEST_DRAM;
+	req.event_trace_categories = 0xFFFFFFFF;
+	req.event_trace_timestamp = EVENT_TRACE_TIMESTAMP_FW_CHRONO;
+
+	XDNA_INFO(ndev->xdna, "send start event trace msg");
+	return aie2_send_mgmt_msg_wait(ndev, &msg);
+}
+
+int aie2_stop_event_trace(struct amdxdna_dev_hdl *ndev)
+{
+	DECLARE_AIE2_STOP_EVENT_TRACE_MSG(stop_event_trace, MSG_OP_STOP_EVENT_TRACE);
+
+	XDNA_INFO(ndev->xdna, "send stop event trace msg");
+	return aie2_send_mgmt_msg_wait(ndev, &msg);
+}
+
 int aie2_create_context(struct amdxdna_dev_hdl *ndev, struct amdxdna_hwctx *hwctx,
 			struct xdna_mailbox_chann_info *info)
 {

src/driver/amdxdna/aie2_msg_priv.h

@@ -40,6 +40,8 @@ enum aie2_msg_opcode {
 	MSG_OP_SET_RUNTIME_CONFIG          = 0x10A,
 	MSG_OP_GET_RUNTIME_CONFIG          = 0x10B,
 	MSG_OP_REGISTER_ASYNC_EVENT_MSG    = 0x10C,
+	MSG_OP_START_EVENT_TRACE		= 0x10F,
+	MSG_OP_STOP_EVENT_TRACE			= 0x110,
 	MSG_OP_MAX_DRV_OPCODE,
 	MSG_OP_GET_PROTOCOL_VERSION        = 0x301,
 	MSG_OP_MAX_OPCODE
@@ -387,6 +389,64 @@ struct async_event_msg_resp {
 	enum async_event_type	type;
 } __packed;
 
+/***************Start of event tracing data struct ****************/
+
+#define TRACE_EVENT_BUFFER_SIZE	0x2000
+#define MAX_ONE_TIME_LOG_INFO_LEN	16
+
+enum event_trace_destination {
+	EVENT_TRACE_DEST_DEBUG_BUS,
+	EVENT_TRACE_DEST_DRAM,
+	EVENT_TRACE_DEST_COUNT
+};
+
+enum event_trace_timestamp {
+	EVENT_TRACE_TIMESTAMP_FW_CHRONO,
+	EVENT_TRACE_TIMESTAMP_CPU_CCOUNT,
+	EVENT_TRACE_TIMESTAMP_COUNT
+};
+
+struct start_event_trace_req {
+	uint32_t event_trace_categories;
+	enum event_trace_destination event_trace_dest;
+	enum event_trace_timestamp event_trace_timestamp;
+	//DRAM log buffer address and size
+	uint64_t dram_buffer_address;
+	uint32_t dram_buffer_size;
+} __packed;
+
+struct start_event_trace_resp {
+	enum aie2_msg_status status;
+	uint32_t msi_idx;
+	uint64_t current_timestamp;
+} __packed;
+
+struct stop_event_trace_req {
+	uint32_t:32;
+} __packed;
+
+struct stop_event_trace_resp {
+	enum aie2_msg_status status;
+} __packed;
+
+struct set_event_trace_categories_req {
+	uint32_t event_trace_categories;
+};
+
+struct set_event_trace_categories_resp {
+	enum aie2_msg_status status;
+};
+
+struct event_trace_req_buf {
+	struct amdxdna_dev_hdl *ndev;
+	struct start_event_trace_req trace_req;
+	uint64_t resp_timestamp;
+	int log_ch_irq;
+	u8 *buf;
+};
+
+/***************End of event tracing data structs ****************/
+
 #define MAX_CHAIN_CMDBUF_SIZE 0x1000
 #define slot_cf_has_space(offset, payload_size) \
 	(MAX_CHAIN_CMDBUF_SIZE - ((offset) + (payload_size)) > \

src/driver/amdxdna/aie2_pci.c

@@ -605,6 +605,12 @@ static int aie2_init(struct amdxdna_dev *xdna)
 		goto async_event_free;
 	}
 
+	ret = aie2_start_event_trace_send(ndev);
+	if(ret) {
+		XDNA_ERR(xdna, "Send start event trace failed, ret %d", ret);
+		goto event_trace_free;
+	}
+
 	/* Just to make sure firmware handled async events */
 	ret = aie2_query_firmware_version(ndev, &ndev->xdna->fw_ver);
 	if (ret) {
@@ -617,6 +623,8 @@ static int aie2_init(struct amdxdna_dev *xdna)
 
 async_event_free:
 	aie2_error_async_events_free(ndev);
+event_trace_free:
+	aie2_event_trace_free(ndev);
 stop_hw:
 	aie2_hw_stop(xdna);
 disable_sva:
@@ -634,7 +642,11 @@ static void aie2_fini(struct amdxdna_dev *xdna)
 	struct pci_dev *pdev = to_pci_dev(xdna->ddev.dev);
 	struct amdxdna_dev_hdl *ndev = xdna->dev_handle;
 
+	if (ndev && ndev->dev_status >= AIE2_DEV_START)
+		aie2_stop_event_trace_send(ndev);
+
 	aie2_hw_stop(xdna);
+	aie2_event_trace_free(ndev);
 	aie2_error_async_events_free(ndev);
 #ifdef AMDXDNA_DEVEL
 	if (iommu_mode != AMDXDNA_IOMMU_PASID)