diff --git a/drivers/nna/Makefile b/drivers/nna/Makefile index f51a45dc5..2cc656849 100644 --- a/drivers/nna/Makefile +++ b/drivers/nna/Makefile @@ -5,3 +5,4 @@ obj-$(CONFIG_VHA) += vha/ img_mem/ obj-$(CONFIG_LOKI) += fenrir_loki/ subdir-ccflags-y += -I$(srctree)/$(src)/include +subdir-ccflags-y += -DTRACE_INCLUDE_PATH=$(srctree)/$(src)/include diff --git a/drivers/nna/include/vha_trace_point.h b/drivers/nna/include/vha_trace_point.h new file mode 100644 index 000000000..d4223a9d6 --- /dev/null +++ b/drivers/nna/include/vha_trace_point.h @@ -0,0 +1,97 @@ +/* SPDX-License-Identifier: GPL-2.0-or-later */ +/* vha message transfer tracepoints + * + * Copyright (C) 2013 Red Hat, Inc. All Rights Reserved. + * Written by David Howells (dhowells@redhat.com) + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM vha_trace_point + +#if !defined(_TRACE_VHA_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_VHA_H + +#include +#include +#include + +TRACE_EVENT(vha_session_in, + TP_PROTO(uint32_t session_id, uint64_t kicks), + + TP_ARGS(session_id, kicks), + + TP_STRUCT__entry( + __field( uint32_t, session_id) + __field( uint64_t, kicks) + ), + + TP_fast_assign( + __entry->session_id = session_id; + __entry->kicks = kicks; + ), + + TP_printk("session_id %d, kicks=%d", __entry->session_id, __entry->kicks) +); + +TRACE_EVENT(vha_session_out, + TP_PROTO(uint32_t session_id, uint64_t kicks), + + TP_ARGS(session_id, kicks), + + TP_STRUCT__entry( + __field( uint32_t, session_id) + __field( uint64_t, kicks) + ), + + TP_fast_assign( + __entry->session_id = session_id; + __entry->kicks = kicks; + ), + + TP_printk("session_id %d, kicks=%d", __entry->session_id, __entry->kicks) +); + +TRACE_EVENT(vha_hwexec_in, + TP_PROTO(uint32_t session_id, uint32_t subseg_current), + + TP_ARGS(session_id, subseg_current), + + TP_STRUCT__entry( + __field( uint32_t, session_id) + __field( uint32_t, subseg_current) + ), + + TP_fast_assign( + __entry->session_id = session_id; + __entry->subseg_current = subseg_current; + ), + + TP_printk("session_id %d, subseg_current=%d", __entry->session_id, __entry->subseg_current) +); + +TRACE_EVENT(vha_irq, + TP_PROTO(unsigned int dev_id, uint64_t status, uint8_t count, uint64_t last_proc_us), + + TP_ARGS(dev_id, status, count, last_proc_us), + + TP_STRUCT__entry( + __field( unsigned int, dev_id) + __field( uint64_t, status) + __field( uint8_t, count) + __field( uint64_t, last_proc_us) + ), + + TP_fast_assign( + __entry->dev_id = dev_id; + __entry->status = status; + __entry->count = count; + __entry->last_proc_us = last_proc_us; + ), + + TP_printk("dev_id=%d, status=%lld, count=%d, last_proc_us=%lld", + __entry->dev_id, __entry->status, __entry->count, __entry->last_proc_us) +); + +#endif /* _TRACE_VHA_H */ + +/* This part must be outside protection */ +#include diff --git a/drivers/nna/vha/single/vha_cnn.c b/drivers/nna/vha/single/vha_cnn.c index e6948b6d7..1ec3ed472 100644 --- a/drivers/nna/vha/single/vha_cnn.c +++ b/drivers/nna/vha/single/vha_cnn.c @@ -50,6 +50,8 @@ #include "vha_plat.h" #include "vha_regs.h" +#include + static uint32_t cnn_pdump_poll_count = 10000000; module_param(cnn_pdump_poll_count, uint, 0444); MODULE_PARM_DESC(cnn_pdump_poll_count, @@ -314,6 +316,7 @@ hw_kick: img_pdump_printf("-- CNN_SETUP_END\n"); /* Remember the time cnn is kicked */ + trace_vha_hwexec_in(session->id, cmd->subseg_current); GETNSTIMEOFDAY(&cmd->hw_proc_start); vha->stats.hw_proc_start = cmd->hw_proc_start; /* Need to generate proper pdump */ @@ -639,6 +642,14 @@ void vha_cnn_cmd_completed(struct vha_cmd *cmd, int status) dev_dbg(session->vha->dev, "%s: %p, hw_cycles %llx\n", __func__, cmd, session->vha->stats.cnn_last_cycles); + session->last_proc_us = cmd->proc_us; + session->total_proc_us += cmd->proc_us; + if (session->kicks) { + uint64_t avg = session->total_proc_us; + do_div(avg, session->kicks); + session->avg_proc_us = avg; + } + if (session->vha->stats.cnn_last_cycles > (uint32_t)~0) dev_warn(session->vha->dev, "%s: hw_cycles %llx exceeds 32bit limit\n", diff --git a/drivers/nna/vha/single/vha_dev.c b/drivers/nna/vha/single/vha_dev.c index 31ea97878..6599d4832 100644 --- a/drivers/nna/vha/single/vha_dev.c +++ b/drivers/nna/vha/single/vha_dev.c @@ -54,6 +54,8 @@ #include #endif +#include + #define ERR_EVENT_DESC(b) VHA_CR_OS(VHA_EVENT_STATUS_VHA_##b##_EN), __stringify(b) static void vha_dev_disable_events(struct vha_dev *vha) @@ -824,6 +826,7 @@ exit: if (vha->fault_inject & VHA_FI_IRQ_WORKER) current->make_it_fail = false; #endif + trace_vha_irq(vha->id, status, count, vha->stats.last_proc_us); mutex_unlock(&vha->lock); return ret; diff --git a/drivers/nna/vha/vha_common.c b/drivers/nna/vha/vha_common.c index 4f52518fb..00823a44e 100644 --- a/drivers/nna/vha/vha_common.c +++ b/drivers/nna/vha/vha_common.c @@ -54,6 +54,7 @@ #include #include +#include #include "vha_common.h" #include "vha_plat.h" #include @@ -72,6 +73,10 @@ #error Invalid HW architecture series define. Only one of HW_AX2 or HW_AX3 must be defined. #endif +#undef linux +#define CREATE_TRACE_POINTS +#include + #define MIN_ONCHIP_MAP 1 #define MAX_ONCHIP_MAP 128 @@ -230,6 +235,8 @@ static struct { /* Session id counter. */ static uint32_t vha_session_id_cnt = 0; +/* Reset counter. */ +static uint32_t vha_reset_cnt = 0; static void cmd_worker(struct work_struct *work); @@ -821,6 +828,8 @@ int vha_add_session(struct vha_session *session) "%s: %p ctxid:%d\n", __func__, session, session->mmu_ctxs[VHA_MMU_REQ_MODEL_CTXID].id); + trace_vha_session_in(session->id, 0); + mutex_unlock(&vha->lock); return ret; @@ -987,6 +996,8 @@ void vha_rm_session(struct vha_session *session) mutex_lock(&vha->lock); } + trace_vha_session_out(session->id, session->kicks); + mutex_unlock(&vha->lock); /* Reschedule once the session is removed. */ @@ -1004,6 +1015,7 @@ static int vha_alloc_common(struct vha_dev *vha) return 0; } +/****************** vha sysfs definition *************************************/ static ssize_t BVNC_show(struct device *dev, struct device_attribute *attr, char *buf) { @@ -1017,6 +1029,68 @@ BVNC_show(struct device *dev, struct device_attribute *attr, char *buf) (unsigned short)props->core_id); } +static ssize_t log_store(struct device *dev, struct device_attribute *attr, + const char *buf, size_t count) +{ + struct vha_dev *vha = vha_dev_get_drvdata(dev); + + mutex_lock(&vha->lock); + memset(&vha->stats, 0, sizeof(struct vha_stats)); + vha_reset_cnt++; + mutex_unlock(&vha->lock); + + return count; +} + +static ssize_t log_show(struct device *dev, struct device_attribute *attr, char *buf) +{ + ssize_t len = 0; + struct vha_dev *vha = vha_dev_get_drvdata(dev); + struct vha_session *session = NULL; + int ret = 0; + size_t mem_val = 0; + + mutex_lock(&vha->lock); + + len += scnprintf(buf + len, PAGE_SIZE - len, + "[NPU] Driver Version: " VERSION_STRING "\n" + "---------------------------------------MODULE STATUS--------------------------------------\n" + "DevId DevStatus DevSessionNum DevLoadingAvg_%% TotalTasks CompletedTasks\n" + " %d %d %d %d %lld %lld\n" + "-----------------------------------------MEM INFO-----------------------------------------\n" + "MMU_page_size MMU_mode\n" + " %ld %d\n" + "---------------------------------------INSTANCE INFO--------------------------------------\n" + "AvgHwProcUs LastHwProcUs TotalHwProcUs LastMemUsage LastMmuUsage\n" + " %lld %lld %lld %d %d\n" + "--------------------------------------EXCEPTION INFO--------------------------------------\n" + "total_failures reset\n" + " %lld %d\n", + vha->id, vha->state, vha_session_id_cnt, vha->stats.cnn_utilization/10, + vha->stats.cnn_kicks, vha->stats.cnn_kicks_completed, + mmu_page_size_kb_lut[vha->mmu_page_size], vha->mmu_mode, + vha->stats.cnn_avg_proc_us, vha->stats.last_proc_us, vha->stats.cnn_total_proc_us, + vha->stats.mem_usage_last, vha->stats.mmu_usage_last, + vha->stats.total_failures, vha_reset_cnt); + + list_for_each_entry(session, &vha->sessions, list) { + if (!ret++) { + len += scnprintf(buf + len, PAGE_SIZE - len, + "---------------------------------------SESSION INFO--------------------------------------\n" + "SessionId MemUsage Cmds AvgProcUs LastProcUs TotalProcUs\n"); + } + img_mem_get_usage(session->mem_ctx, &mem_val, NULL); + len += scnprintf(buf + len, PAGE_SIZE - len, + " %-7d %-12ld %-8lld %-13lld %-13lld %lld\n", + session->id, mem_val, session->kicks, session->avg_proc_us, + session->last_proc_us, session->total_proc_us); + } + + mutex_unlock(&vha->lock); + + return len; +} + static DEVICE_ATTR_RO(BVNC); static struct attribute *vha_sysfs_entries[] = { @@ -1024,11 +1098,23 @@ static struct attribute *vha_sysfs_entries[] = { NULL, }; +static struct device_attribute dev_attr_log = __ATTR(log, 0664, log_show, log_store); + +static struct attribute *vha_sysfs_attrs[] = { + &dev_attr_log.attr, + NULL, +}; + static const struct attribute_group vha_attr_group = { .name = NULL, /* put in device directory */ .attrs = vha_sysfs_entries, }; +static struct attribute_group vha_dev_attr_group = { + .name = "info", /* put in info directory */ + .attrs = vha_sysfs_attrs, +}; + void vha_sched_apm(struct vha_dev *vha, struct vha_apm_work *apm_work) { unsigned long work_at = jiffies + msecs_to_jiffies(apm_work->delay_ms); @@ -1224,6 +1310,9 @@ int vha_add_dev(struct device *dev, if (sysfs_create_group(&dev->kobj, &vha_attr_group)) dev_err(dev, "failed to create sysfs entries\n"); + if (sysfs_create_group(&dev->kobj, &vha_dev_attr_group)) + dev_err(dev, "failed to create info sysfs entries\n"); + vha->freq_khz = freq_khz; #ifndef CONFIG_VHA_DUMMY if (vha->freq_khz < 0) @@ -1358,6 +1447,7 @@ void vha_rm_dev(struct device *dev) list_del(&vha->heaps); BUG_ON(!drv.num_devs--); sysfs_remove_group(&dev->kobj, &vha_attr_group); + sysfs_remove_group(&dev->kobj, &vha_dev_attr_group); vha_dbg_deinit(vha); vha_pdump_deinit(&vha_common->pdump); @@ -1412,7 +1502,7 @@ int vha_map_to_onchip(struct vha_session *session, buf = vha_find_bufid(session, buf_id); if (!buf) { - pr_err("%s: buffer id %d not found\n", __func__, buf_id); + dev_err(vha->dev, "%s: buffer id %d not found\n", __func__, buf_id); ret = -EINVAL; goto out_unlock; } @@ -1427,7 +1517,7 @@ int vha_map_to_onchip(struct vha_session *session, map_id = idr_alloc(&session->onchip_maps, onchip_map, MIN_ONCHIP_MAP, MAX_ONCHIP_MAP, GFP_KERNEL); if (map_id < 0) { - pr_err("%s: idr_alloc failed\n", __func__); + dev_err(vha->dev, "%s: idr_alloc failed\n", __func__); ret = map_id; goto alloc_id_failed; } @@ -1450,7 +1540,7 @@ int vha_map_to_onchip(struct vha_session *session, } else { onchip_map = idr_find(&session->onchip_maps, map_id); if (!onchip_map) { - pr_err("%s: idr_find failed\n", __func__); + dev_err(vha->dev, "%s: idr_find failed\n", __func__); ret = -EINVAL; goto out_unlock; } diff --git a/drivers/nna/vha/vha_common.h b/drivers/nna/vha/vha_common.h index 22ce091cc..a5ceccf1c 100644 --- a/drivers/nna/vha/vha_common.h +++ b/drivers/nna/vha/vha_common.h @@ -192,6 +192,21 @@ #define GET_CNN_DBG_MODE(type, session) \ (session->cnn_dbg.cnn_dbg_modes[VHA_CNN_DBG_MODE_##type]) +extern int debug_log_enable; +#if defined(CONFIG_DYNAMIC_DEBUG) || \ + (defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE)) || \ + defined(DEBUG) +#else +#define dev_dbg(dev, fmt, ...) \ +({ \ + do { \ + if(debug_log_enable) \ + printk(KERN_DEBUG,dev_fmt(fmt), ##__VA_ARGS__); \ + + }while(0);\ +}) +#endif + #if LINUX_VERSION_CODE < KERNEL_VERSION(5, 6, 0) # define TIMESPEC timespec # define TIMESPEC_VALID(ts) timespec_valid(ts) @@ -760,6 +775,9 @@ struct vha_session { uint64_t kicks; uint64_t polled; uint64_t responsed; + uint64_t avg_proc_us; + uint64_t total_proc_us; + uint64_t last_proc_us; }; /* pdump cache info structure used for LDB commands */ diff --git a/drivers/nna/vha/vha_dbg.c b/drivers/nna/vha/vha_dbg.c index da379df5d..b2f18d4d3 100644 --- a/drivers/nna/vha/vha_dbg.c +++ b/drivers/nna/vha/vha_dbg.c @@ -52,6 +52,12 @@ #include "vha_plat.h" #include "vha_io.h" +int debug_log_enable = 0; +module_param(debug_log_enable, int, 0644); +MODULE_PARM_DESC( + debug_log_enable, + "flag to on/off debug log when dynamic debug is dissable.0:disable, other :enable"); + #ifdef CONFIG_DEBUG_FS #define VHA_DBG_CONBINED_CRC_BUF_SIZE 0x1000 diff --git a/drivers/nna/vha/vha_devfreq.c b/drivers/nna/vha/vha_devfreq.c index 9c3657dc6..197361cec 100644 --- a/drivers/nna/vha/vha_devfreq.c +++ b/drivers/nna/vha/vha_devfreq.c @@ -163,9 +163,9 @@ static int vhafreq_get_dev_status(struct device *dev, vha_get_cnntotal_proc_us(dev, &proc_total_time, &proc_cur_time); - /* Galculate the busy_time */ + /* Calculate the busy_time */ busytime = proc_total_time + proc_cur_time; - if (busytime < vhafreq_dev->vha_load_data.total_proc_us){ + if (busytime < vhafreq_dev->vha_load_data.total_proc_us) { busytime = 0; } else { busytime = busytime - vhafreq_dev->vha_load_data.total_proc_us; @@ -173,7 +173,7 @@ static int vhafreq_get_dev_status(struct device *dev, vhafreq_dev->vha_load_data.total_proc_us = proc_total_time + proc_cur_time; - /* Galculate the total_time */ + /* Calculate the total_time */ GETNSTIMEOFDAY(&vhafreq_dev->vha_load_data.new_mark); if (!get_timespan_us(&vhafreq_dev->vha_load_data.old_mark, &vhafreq_dev->vha_load_data.new_mark, &proc_cur_time)) @@ -181,7 +181,7 @@ static int vhafreq_get_dev_status(struct device *dev, vhafreq_dev->vha_load_data.old_mark = vhafreq_dev->vha_load_data.new_mark; - /* correct the busytime */ + /* correct the busytime */ if (busytime > proc_cur_time) { dev_dbg(dev,"busytime :%lu bigger, totaltime :%lu .\n", busytime, proc_cur_time); busytime = proc_cur_time; @@ -450,7 +450,7 @@ int vha_devfreq_init(struct device *dev) #ifdef CONFIG_DEVFREQ_THERMAL if (of_property_read_u32(dev->of_node, "dynamic-power-coefficient", (u32 *)&vha_cooling_power.dyn_power_coeff)) - pr_err("Failed to read dynamic power coefficient property.\n"); + dev_err(dev, "%s: Failed to read dynamic power coefficient property.\n", __func__); devfreq_vhadev->devfreq_cooling = of_devfreq_cooling_register_power( dev->of_node, devfreq_vhadev->devfreq, &vha_cooling_power);