diff --git a/drivers/soc/qcom/smcinvoke.c b/drivers/soc/qcom/smcinvoke.c index 581d9942a773..4125c597258c 100644 --- a/drivers/soc/qcom/smcinvoke.c +++ b/drivers/soc/qcom/smcinvoke.c @@ -28,6 +28,8 @@ #include #include +#include + #include "smcinvoke_object.h" #include "../../misc/qseecom_kernel.h" @@ -259,6 +261,14 @@ struct smcinvoke_mem_obj { uint64_t shmbridge_handle; }; +#define IPC_LOG_PAGE_COUNT 50 +static void *ipc_logging_context; +#define IPC_LOG(fmt, args...) \ + ipc_log_string(ipc_logging_context, \ + "[%04x:%04x] %s:%d " fmt, \ + current->pid, current->tgid, __func__, __LINE__, \ + ## args) + static void destroy_cb_server(struct kref *kref) { struct smcinvoke_server_info *server = container_of(kref, @@ -492,6 +502,8 @@ static int put_pending_cbobj_locked(uint16_t srvr_id, int16_t obj_id) return ret; } + IPC_LOG("srvr_id=0x%x obj_id=0x%x", srvr_id, obj_id); + head = &srvr_info->pending_cbobjs; list_for_each_entry(cbobj, head, list) if (cbobj->cbobj_id == obj_id) { @@ -883,6 +895,8 @@ static int32_t smcinvoke_release_mem_obj_locked(void *buf, size_t buf_len) return OBJECT_ERROR_INVALID; } + IPC_LOG("tzhandle=0x%08x", msg->hdr.tzhandle); + return release_tzhandle_locked(msg->hdr.tzhandle); } @@ -1091,6 +1105,9 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp) /* no need for memcpy as we did kmemdup() above */ cb_req = tmp_cb_req; + IPC_LOG("tzhandle=0x%08x op=0x%02x counts=0x%04x", + cb_req->hdr.tzhandle, cb_req->hdr.op, cb_req->hdr.counts); + cb_txn->state = SMCINVOKE_REQ_PLACED; cb_txn->cb_req = cb_req; cb_txn->cb_req_bytes = buf_len; @@ -1116,6 +1133,10 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp) cb_txn->txn_id = ++srvr_info->txn_id; hash_add(srvr_info->reqs_table, &cb_txn->hash, cb_txn->txn_id); mutex_unlock(&g_smcinvoke_lock); + + IPC_LOG("txn_id=%d, server_id=0x%x, cb_reqs_inflight=%d", + cb_txn->txn_id, srvr_info->server_id, cb_reqs_inflight); + /* * we need not worry that server_info will be deleted because as long * as this CBObj is served by this server, srvr_info will be valid. @@ -1177,6 +1198,12 @@ out: if (srvr_info) kref_put(&srvr_info->ref_cnt, destroy_cb_server); mutex_unlock(&g_smcinvoke_lock); + + IPC_LOG("result=%d tzhandle=0x%08x op=0x%02x counts=0x%04x, cb_reqs_inflight=%d", + cb_req->result, + cb_req->hdr.tzhandle, cb_req->hdr.op, cb_req->hdr.counts, + cb_reqs_inflight); + } static int marshal_out_invoke_req(const uint8_t *buf, uint32_t buf_size, @@ -1235,6 +1262,10 @@ static int marshal_out_invoke_req(const uint8_t *buf, uint32_t buf_size, if (ret) goto out; + IPC_LOG("OO[%d]: tzhandle=0x%x server=0x%x fd=0x%x", + i, tz_args->handle, + TZHANDLE_GET_SERVER(tz_args->handle), temp_fd); + tz_args++; } ret = 0; @@ -1415,6 +1446,9 @@ static int marshal_in_invoke_req(const struct smcinvoke_cmd_req *req, &(tz_args[i].handle)); if (ret) goto out; + IPC_LOG("OI[%d]: fd=0x%x cb_server_fd=0x%x tzhandle=0x%x", + i, args_buf[i].o.fd, args_buf[i].o.cb_server_fd, + tz_args[i].handle); tzhandles_to_release[k++] = tz_args[i].handle; } ret = 0; @@ -1449,6 +1483,9 @@ static int marshal_in_tzcb_req(const struct smcinvoke_cb_txn *cb_txn, user_req->op = tzcb_req->hdr.op; user_req->counts = tzcb_req->hdr.counts; user_req->argsize = sizeof(union smcinvoke_arg); + IPC_LOG("tzhandle=0x%x srvr_id=0x%x cbobj_id=0x%08x op=0x%02x counts=0x%04x", + tzcb_req->hdr.tzhandle, srvr_id, user_req->cbobj_id, + user_req->op, user_req->counts); FOR_ARGS(i, tzcb_req->hdr.counts, BI) { user_req_buf_offset = size_align(user_req_buf_offset, @@ -1520,6 +1557,8 @@ static int marshal_in_tzcb_req(const struct smcinvoke_cb_txn *cb_txn, ret = -EFAULT; goto out; } + IPC_LOG("OI[%d]: tzhandle=0x%x srvr_id=0x%x fd=0x%x", + i, tz_args[i].handle, srvr_id, temp_fd); } out: return ret; @@ -1570,6 +1609,8 @@ static int marshal_out_tzcb_req(const struct smcinvoke_accept *user_req, if (ret) goto out; tzhandles_to_release[i] = tz_args[i].handle; + IPC_LOG("OO[%d]: fd=0x%x cb_server_fd=0x%x tzhandle=0x%x", + i, tmp_arg.o.fd, tmp_arg.o.cb_server_fd, tz_args[i].handle); } FOR_ARGS(i, tzcb_req->hdr.counts, OI) { if (TZHANDLE_IS_CB_OBJ(tz_args[i].handle)) @@ -1896,6 +1937,9 @@ static long process_invoke_req(struct file *filp, unsigned int cmd, } out_msg = out_shm.vaddr; + IPC_LOG("tzhandle=0x%08x op=0x%02x counts=0x%04x", + tzobj->tzhandle, req.op, req.counts); + ret = marshal_in_invoke_req(&req, args_buf, tzobj->tzhandle, in_msg, inmsg_size, filp_to_release, tzhandles_to_release); if (ret) { @@ -1939,6 +1983,10 @@ static long process_invoke_req(struct file *filp, unsigned int cmd, /* Outbuf could be carrying local objs to be released. */ process_piggyback_data(out_msg, outmsg_size); out: + IPC_LOG("ret=%d result=%d tzhandle=0x%08x op=0x%02x counts=0x%04x", + ret, req.result, + tzobj->tzhandle, req.op, req.counts); + release_filp(filp_to_release, OBJECT_COUNTS_MAX_OO); if (ret) release_tzhandles(tzhandles_to_release, OBJECT_COUNTS_MAX_OO); @@ -1952,6 +2000,24 @@ out: return ret; } +static long process_log_info(struct file *filp, unsigned int cmd, + unsigned long arg) +{ + int ret = 0; + char buf[SMCINVOKE_LOG_BUF_SIZE]; + struct smcinvoke_file_data *tzobj = filp->private_data; + + ret = copy_from_user(buf, (void __user *)arg, SMCINVOKE_LOG_BUF_SIZE); + if (ret) { + pr_err("logging HLOS info copy failed\n"); + return -EFAULT; + } + buf[SMCINVOKE_LOG_BUF_SIZE - 1] = '\0'; + IPC_LOG("%s context_type=%d tzhandle=0x%08x", buf, tzobj->context_type, + tzobj->tzhandle); + return ret; +} + static long smcinvoke_ioctl(struct file *filp, unsigned int cmd, unsigned long arg) { @@ -1960,20 +2026,35 @@ static long smcinvoke_ioctl(struct file *filp, unsigned int cmd, switch (cmd) { case SMCINVOKE_IOCTL_INVOKE_REQ: ret = process_invoke_req(filp, cmd, arg); + if (ret) + IPC_LOG("cmd=SMCINVOKE_IOCTL_INVOKE_REQ ret=%ld", ret); break; case SMCINVOKE_IOCTL_ACCEPT_REQ: ret = process_accept_req(filp, cmd, arg); + if (ret) + IPC_LOG("cmd=SMCINVOKE_IOCTL_ACCEPT_REQ ret=%ld", ret); break; case SMCINVOKE_IOCTL_SERVER_REQ: ret = process_server_req(filp, cmd, arg); + if (ret) + IPC_LOG("cmd=SMCINVOKE_IOCTL_SERVER_REQ ret=%ld", ret); break; case SMCINVOKE_IOCTL_ACK_LOCAL_OBJ: ret = process_ack_local_obj(filp, cmd, arg); + if (ret) + IPC_LOG("cmd=SMCINVOKE_IOCTL_ACK_LOCAL_OBJ ret=%ld", ret); + break; + case SMCINVOKE_IOCTL_LOG: + ret = process_log_info(filp, cmd, arg); + if (ret) + IPC_LOG("cmd=SMCINVOKE_IOCTL_LOG ret=%ld", ret); break; default: ret = -ENOIOCTLCMD; + IPC_LOG("invalid cmd=%x ret=%ld", cmd, ret); break; } + return ret; } @@ -2167,11 +2248,14 @@ static struct platform_driver smcinvoke_plat_driver = { static int smcinvoke_init(void) { + ipc_logging_context = ipc_log_context_create(IPC_LOG_PAGE_COUNT, + "smcinvoke", 0); return platform_driver_register(&smcinvoke_plat_driver); } static void smcinvoke_exit(void) { + ipc_log_context_destroy(ipc_logging_context); platform_driver_unregister(&smcinvoke_plat_driver); } diff --git a/include/uapi/linux/smcinvoke.h b/include/uapi/linux/smcinvoke.h index 33649754502f..4d9b5b86fd8b 100644 --- a/include/uapi/linux/smcinvoke.h +++ b/include/uapi/linux/smcinvoke.h @@ -1,6 +1,6 @@ /* SPDX-License-Identifier: GPL-2.0-only WITH Linux-syscall-note */ /* - * Copyright (c) 2017-2020, The Linux Foundation. All rights reserved. + * Copyright (c) 2017-2021, The Linux Foundation. All rights reserved. */ #ifndef _UAPI_SMCINVOKE_H_ #define _UAPI_SMCINVOKE_H_ @@ -92,4 +92,12 @@ struct smcinvoke_server { #define SMCINVOKE_IOCTL_ACK_LOCAL_OBJ \ _IOWR(SMCINVOKE_IOC_MAGIC, 4, __s32) +/* + * smcinvoke logging buffer is for communicating with the smcinvoke driver additional + * info for debugging to be included in driver's log (if any) + */ +#define SMCINVOKE_LOG_BUF_SIZE 100 +#define SMCINVOKE_IOCTL_LOG \ + _IOC(_IOC_READ|_IOC_WRITE, SMCINVOKE_IOC_MAGIC, 255, SMCINVOKE_LOG_BUF_SIZE) + #endif /* _UAPI_SMCINVOKE_H_ */