Merge "SMCInvoke: Add ipc_logging to improve debuggability of use"

This commit is contained in:
qctecmdr 2021-04-26 14:57:51 -07:00 • committed by Gerrit - the friendly Code Review server
commit ea4a184bb8
2 changed files with 93 additions and 1 deletions

View file

@ -28,6 +28,8 @@
#include <soc/qcom/qseecomi.h>
#include <linux/qtee_shmbridge.h>
#include <linux/ipc_logging.h>
#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);
}

View file

@ -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_ */