From e663ad89f8c5f0a8a15008c650a94f3783c5650e Mon Sep 17 00:00:00 2001 From: Sanrio Alvares Date: Fri, 15 Jan 2016 17:04:21 -0800 Subject: [PATCH] trace, scm: trace scm calls Create a scm group to enable profiling time spent in a scm call. This will help determine which scm call is spending how much time in a higher execution level. To enable "echo 1 > /sys/kernel/debug/tracing/events/scm/enable". It is disabled by default. If enabled, traces can be found in Ftrace logs. Ftrace Output Example: PROCESS CPU TIME SCM ID, X0, Number of args, args[0-2], X5, return values [0-2] kworker/u8:4-329 [002] 128.201129: scm_call_start: func id=0x42000904 (args: 0x6, 0x2, 0x200000000, 0x65b8000000019, 0x142e0f000) kworker/u8:4-329 [002] 128.201383: scm_call_end: ret: 0, 0, 0x4a07e00000001 kworker/u8:4-329 [002] 128.201464: scm_call_start: func id=0x42000904 (args: 0x6, 0x3, 0x1312d0000000000, 0x17900000000, 0x142e0f000) kworker/u8:4-329 [002] 128.201542: scm_call_end: ret: 0x1bf03dddddd, 0x2f72656b726f776b, 0x343a32 CRs-Fixed: 969770 Change-Id: I4e5aaff796dbc9457c55fa529114dcb57780b7ec Signed-off-by: Sanrio Alvares --- drivers/soc/qcom/scm.c | 7 ++++ include/trace/events/scm.h | 68 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 75 insertions(+) create mode 100644 include/trace/events/scm.h diff --git a/drivers/soc/qcom/scm.c b/drivers/soc/qcom/scm.c index 13362cc23ea1..978759d494f8 100644 --- a/drivers/soc/qcom/scm.c +++ b/drivers/soc/qcom/scm.c @@ -24,6 +24,9 @@ #include +#define CREATE_TRACE_POINTS +#include + #define SCM_ENOMEM -5 #define SCM_EOPNOTSUPP -4 #define SCM_EINVAL_ADDR -3 @@ -658,6 +661,8 @@ int scm_call2(u32 fn_id, struct scm_desc *desc) x0, desc->arginfo, desc->args[0], desc->args[1], desc->args[2], desc->x5); + trace_scm_call_start(x0, desc); + if (scm_version == SCM_ARMV8_64) ret = __scm_call_armv8_64(x0, desc->arginfo, desc->args[0], desc->args[1], @@ -671,6 +676,8 @@ int scm_call2(u32 fn_id, struct scm_desc *desc) &desc->ret[0], &desc->ret[1], &desc->ret[2]); + trace_scm_call_end(desc); + if (SCM_SVC_ID(fn_id) == SCM_SVC_LMH) mutex_unlock(&scm_lmh_lock); diff --git a/include/trace/events/scm.h b/include/trace/events/scm.h new file mode 100644 index 000000000000..b07a38da24bd --- /dev/null +++ b/include/trace/events/scm.h @@ -0,0 +1,68 @@ +/* Copyright (c) 2016, The Linux Foundation. All rights reserved. + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License version 2 and + * only version 2 as published by the Free Software Foundation. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + */ + +#undef TRACE_SYSTEM +#define TRACE_SYSTEM scm + +#if !defined(_TRACE_SCM_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_SCM_H +#include +#include +#include + +TRACE_EVENT(scm_call_start, + + TP_PROTO(u64 x0, struct scm_desc *p), + + TP_ARGS(x0, p), + + TP_STRUCT__entry( + __field(u64, x0) + __field(u32, arginfo) + __array(u64, args, MAX_SCM_ARGS) + __field(u64, x5) + ), + + TP_fast_assign( + __entry->x0 = x0; + __entry->arginfo = p->arginfo; + memcpy(__entry->args, p->args, MAX_SCM_ARGS); + __entry->x5 = p->x5; + ), + + TP_printk("func id=%#llx (args: %#x, %#llx, %#llx, %#llx, %#llx)", + __entry->x0, __entry->arginfo, __entry->args[0], + __entry->args[1], __entry->args[2], __entry->x5) +); + + +TRACE_EVENT(scm_call_end, + + TP_PROTO(struct scm_desc *p), + + TP_ARGS(p), + + TP_STRUCT__entry( + __array(u64, ret, MAX_SCM_RETS) + ), + + TP_fast_assign( + memcpy(__entry->ret, p->ret, MAX_SCM_RETS); + ), + + TP_printk("ret: %#llx, %#llx, %#llx", + __entry->ret[0], __entry->ret[1], __entry->ret[2]) +); +#endif /* _TRACE_SCM_H */ + +/* This part must be outside protection */ +#include