Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 6d33a144 authored by Robert Nance's avatar Robert Nance
Browse files

SMCInvoke: Add ipc_logging to improve debuggability of use 



The smcinvoke processing is opaque to the secure app developer,
so adding some tracing capabilities to the HLOS, Android kernel,
and QTEE to make it easier to diagnose some programming errors.

Change-Id: I6f71f08a2497fdb0887801724f391368502f4740
Signed-off-by: default avatarRobert Nance <rnance@codeaurora.org>
parent 7db29dee

drivers/soc/qcom/smcinvoke.c

+84 −0
Original line number Diff line number Diff line
@@ -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"
@@ -258,6 +260,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,
@@ -491,6 +501,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)  {
@@ -882,6 +894,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);

}
@@ -1055,6 +1069,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;
@@ -1080,6 +1097,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.
@@ -1141,6 +1162,12 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp) 
	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,
@@ -1199,6 +1226,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;
@@ -1390,6 +1421,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;
@@ -1424,6 +1458,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,
@@ -1495,6 +1532,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;
@@ -1545,6 +1584,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))
@@ -1871,6 +1912,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) {
@@ -1914,6 +1958,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);
@@ -1927,6 +1975,24 @@ static long process_invoke_req(struct file *filp, unsigned int cmd, 
	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)

{
@@ -1935,20 +2001,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;

}
@@ -2140,11 +2221,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);

}

include/uapi/linux/smcinvoke.h

+9 −1
Original line number Diff line number Diff line 
/* 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_ */