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

Commit 110c8d8f authored by Anmolpreet Kaur's avatar Anmolpreet Kaur Committed by Gerrit - the friendly Code Review server
Browse files

smcinvoke : Add logging in smcinvoke driver



This change adds necessary logging in smcinvoke
driver for handling proper error conditions and
ease the debugging process.

Change-Id: Ic0d9694f299ba52ab2c556785e4a583a37400142
Signed-off-by: default avatarAnmolpreet Kaur <anmolpre@codeaurora.org>
parent 54d02587
Loading
Loading
Loading
Loading
+86 −22
Original line number Original line Diff line number Diff line
@@ -3,6 +3,8 @@
 * Copyright (c) 2016-2020, The Linux Foundation. All rights reserved.
 * Copyright (c) 2016-2020, The Linux Foundation. All rights reserved.
 */
 */


#define pr_fmt(fmt) "smcinvoke: %s: " fmt, __func__

#include <linux/module.h>
#include <linux/module.h>
#include <linux/mod_devicetable.h>
#include <linux/mod_devicetable.h>
#include <linux/device.h>
#include <linux/device.h>
@@ -400,8 +402,10 @@ static int release_mem_obj_locked(int32_t tzhandle)
	struct smcinvoke_mem_obj *mem_obj = find_mem_obj_locked(
	struct smcinvoke_mem_obj *mem_obj = find_mem_obj_locked(
			TZHANDLE_GET_OBJID(tzhandle), is_mem_regn_obj);
			TZHANDLE_GET_OBJID(tzhandle), is_mem_regn_obj);


	if (!mem_obj)
	if (!mem_obj) {
		pr_err("memory object not found\n");
		return OBJECT_ERROR_BADOBJ;
		return OBJECT_ERROR_BADOBJ;
	}


	if (is_mem_regn_obj)
	if (is_mem_regn_obj)
		kref_put(&mem_obj->mem_regn_ref_cnt, del_mem_regn_obj_locked);
		kref_put(&mem_obj->mem_regn_ref_cnt, del_mem_regn_obj_locked);
@@ -432,8 +436,10 @@ static int get_pending_cbobj_locked(uint16_t srvr_id, int16_t obj_id)
	struct smcinvoke_cbobj *obj = NULL;
	struct smcinvoke_cbobj *obj = NULL;
	struct smcinvoke_server_info *server = get_cb_server_locked(srvr_id);
	struct smcinvoke_server_info *server = get_cb_server_locked(srvr_id);


	if (!server)
	if (!server) {
		pr_err("%s, server id : %u not found\n", __func__, srvr_id);
		return OBJECT_ERROR_BADOBJ;
		return OBJECT_ERROR_BADOBJ;
	}


	head = &server->pending_cbobjs;
	head = &server->pending_cbobjs;
	list_for_each_entry(cbobj, head, list)
	list_for_each_entry(cbobj, head, list)
@@ -471,8 +477,10 @@ static int put_pending_cbobj_locked(uint16_t srvr_id, int16_t obj_id)
	struct list_head *head = NULL;
	struct list_head *head = NULL;
	struct smcinvoke_cbobj *cbobj = NULL;
	struct smcinvoke_cbobj *cbobj = NULL;


	if (!srvr_info)
	if (!srvr_info) {
		pr_err("%s, server id : %u not found\n", __func__, srvr_id);
		return ret;
		return ret;
	}


	head = &srvr_info->pending_cbobjs;
	head = &srvr_info->pending_cbobjs;
	list_for_each_entry(cbobj, head, list)
	list_for_each_entry(cbobj, head, list)
@@ -784,8 +792,10 @@ static int32_t smcinvoke_release_mem_obj_locked(void *buf, size_t buf_len)
{
{
	struct smcinvoke_tzcb_req *msg = buf;
	struct smcinvoke_tzcb_req *msg = buf;


	if (msg->hdr.counts != OBJECT_COUNTS_PACK(0, 0, 0, 0))
	if (msg->hdr.counts != OBJECT_COUNTS_PACK(0, 0, 0, 0)) {
		pr_err("Invalid object count in %s\n", __func__);
		return OBJECT_ERROR_INVALID;
		return OBJECT_ERROR_INVALID;
	}


	return release_tzhandle_locked(msg->hdr.tzhandle);
	return release_tzhandle_locked(msg->hdr.tzhandle);
}
}
@@ -805,9 +815,10 @@ static int32_t smcinvoke_map_mem_region(void *buf, size_t buf_len)
	struct sg_table *sgt = NULL;
	struct sg_table *sgt = NULL;


	if (msg->hdr.counts != OBJECT_COUNTS_PACK(0, 1, 1, 1) ||
	if (msg->hdr.counts != OBJECT_COUNTS_PACK(0, 1, 1, 1) ||
		(buf_len - msg->args[0].b.offset <  msg->args[0].b.size))
		(buf_len - msg->args[0].b.offset <  msg->args[0].b.size)) {
		pr_err("Invalid counts received for mapping mem obj\n");
		return OBJECT_ERROR_INVALID;
		return OBJECT_ERROR_INVALID;

	}
	/* args[0] = BO, args[1] = OI, args[2] = OO */
	/* args[0] = BO, args[1] = OI, args[2] = OO */
	ob = buf + msg->args[0].b.offset;
	ob = buf + msg->args[0].b.offset;
	oo =  &msg->args[2].handle;
	oo =  &msg->args[2].handle;
@@ -817,6 +828,7 @@ static int32_t smcinvoke_map_mem_region(void *buf, size_t buf_len)
						SMCINVOKE_MEM_RGN_OBJ);
						SMCINVOKE_MEM_RGN_OBJ);
	if (!mem_obj) {
	if (!mem_obj) {
		mutex_unlock(&g_smcinvoke_lock);
		mutex_unlock(&g_smcinvoke_lock);
		pr_err("Memory object not found\n");
		return OBJECT_ERROR_BADOBJ;
		return OBJECT_ERROR_BADOBJ;
	}
	}


@@ -826,6 +838,7 @@ static int32_t smcinvoke_map_mem_region(void *buf, size_t buf_len)
					&smcinvoke_pdev->dev);
					&smcinvoke_pdev->dev);
		if (IS_ERR(buf_attach)) {
		if (IS_ERR(buf_attach)) {
			ret = OBJECT_ERROR_KMEM;
			ret = OBJECT_ERROR_KMEM;
			pr_err("dma buf attach failed, ret: %d\n", ret);
			goto out;
			goto out;
		}
		}
		mem_obj->buf_attach = buf_attach;
		mem_obj->buf_attach = buf_attach;
@@ -833,6 +846,7 @@ static int32_t smcinvoke_map_mem_region(void *buf, size_t buf_len)
		sgt = dma_buf_map_attachment(buf_attach, DMA_BIDIRECTIONAL);
		sgt = dma_buf_map_attachment(buf_attach, DMA_BIDIRECTIONAL);
		if (IS_ERR(sgt)) {
		if (IS_ERR(sgt)) {
			ret = OBJECT_ERROR_KMEM;
			ret = OBJECT_ERROR_KMEM;
			pr_err("mapping dma buffers failed, ret: %d\n", ret);
			goto out;
			goto out;
		}
		}
		mem_obj->sgt = sgt;
		mem_obj->sgt = sgt;
@@ -840,12 +854,14 @@ static int32_t smcinvoke_map_mem_region(void *buf, size_t buf_len)
		/* contiguous only => nents=1 */
		/* contiguous only => nents=1 */
		if (sgt->nents != 1) {
		if (sgt->nents != 1) {
			ret = OBJECT_ERROR_INVALID;
			ret = OBJECT_ERROR_INVALID;
			pr_err("sg enries are not contigous, ret: %d\n", ret);
			goto out;
			goto out;
		}
		}
		mem_obj->p_addr = sg_dma_address(sgt->sgl);
		mem_obj->p_addr = sg_dma_address(sgt->sgl);
		mem_obj->p_addr_len = sgt->sgl->length;
		mem_obj->p_addr_len = sgt->sgl->length;
		if (!mem_obj->p_addr) {
		if (!mem_obj->p_addr) {
			ret = OBJECT_ERROR_INVALID;
			ret = OBJECT_ERROR_INVALID;
			pr_err("invalid physical address, ret: %d\n", ret);
			goto out;
			goto out;
		}
		}
		mem_obj->mem_map_obj_id = next_mem_map_obj_id_locked();
		mem_obj->mem_map_obj_id = next_mem_map_obj_id_locked();
@@ -875,6 +891,7 @@ static void process_kernel_obj(void *buf, size_t buf_len)
		cb_req->result = OBJECT_OK;
		cb_req->result = OBJECT_OK;
		break;
		break;
	default:
	default:
		pr_err(" invalid operation for tz kernel object\n");
		cb_req->result = OBJECT_ERROR_INVALID;
		cb_req->result = OBJECT_ERROR_INVALID;
		break;
		break;
	}
	}
@@ -902,8 +919,10 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp)
	struct smcinvoke_tzcb_req *cb_req = NULL, *tmp_cb_req = NULL;
	struct smcinvoke_tzcb_req *cb_req = NULL, *tmp_cb_req = NULL;
	struct smcinvoke_server_info *srvr_info = NULL;
	struct smcinvoke_server_info *srvr_info = NULL;


	if (buf_len < sizeof(struct smcinvoke_tzcb_req))
	if (buf_len < sizeof(struct smcinvoke_tzcb_req)) {
		pr_err("smaller buffer length : %u\n", buf_len);
		return;
		return;
	}


	cb_req = buf;
	cb_req = buf;


@@ -913,6 +932,7 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp)
	} else if (TZHANDLE_IS_MEM_OBJ(cb_req->hdr.tzhandle)) {
	} else if (TZHANDLE_IS_MEM_OBJ(cb_req->hdr.tzhandle)) {
		return process_mem_obj(buf, buf_len);
		return process_mem_obj(buf, buf_len);
	} else if (!TZHANDLE_IS_CB_OBJ(cb_req->hdr.tzhandle)) {
	} else if (!TZHANDLE_IS_CB_OBJ(cb_req->hdr.tzhandle)) {
		pr_err("Request object is not a callback object\n");
		cb_req->result = OBJECT_ERROR_INVALID;
		cb_req->result = OBJECT_ERROR_INVALID;
		return;
		return;
	}
	}
@@ -926,12 +946,16 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp)
	if (!tmp_cb_req) {
	if (!tmp_cb_req) {
		/* we need to return error to caller so fill up result */
		/* we need to return error to caller so fill up result */
		cb_req->result = OBJECT_ERROR_KMEM;
		cb_req->result = OBJECT_ERROR_KMEM;
		pr_err("failed to create copy of request, set result: %d\n",
							cb_req->result);
		return;
		return;
	}
	}


	cb_txn = kzalloc(sizeof(*cb_txn), GFP_KERNEL);
	cb_txn = kzalloc(sizeof(*cb_txn), GFP_KERNEL);
	if (!cb_txn) {
	if (!cb_txn) {
		cb_req->result = OBJECT_ERROR_KMEM;
		cb_req->result = OBJECT_ERROR_KMEM;
		pr_err("failed to allocate memory for request, result: %d\n",
							cb_req->result);
		kfree(tmp_cb_req);
		kfree(tmp_cb_req);
		return;
		return;
	}
	}
@@ -950,6 +974,7 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp)
				TZHANDLE_GET_SERVER(cb_req->hdr.tzhandle));
				TZHANDLE_GET_SERVER(cb_req->hdr.tzhandle));
	if (!srvr_info || srvr_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT) {
	if (!srvr_info || srvr_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT) {
		/* ret equals Object_ERROR_DEFUNCT, at this point go to out */
		/* ret equals Object_ERROR_DEFUNCT, at this point go to out */
		pr_err("sever is either invalid or defunct\n");
		mutex_unlock(&g_smcinvoke_lock);
		mutex_unlock(&g_smcinvoke_lock);
		goto out;
		goto out;
	}
	}
@@ -983,6 +1008,7 @@ static void process_tzcb_req(void *buf, size_t buf_len, struct file **arr_filp)
	} else if (!srvr_info ||
	} else if (!srvr_info ||
		srvr_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT) {
		srvr_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT) {
		cb_req->result = OBJECT_ERROR_DEFUNCT;
		cb_req->result = OBJECT_ERROR_DEFUNCT;
		pr_err("server invalid, res: %d\n", cb_req->result);
	} else {
	} else {
		pr_debug("%s wait_event interrupted ret = %d\n", __func__, ret);
		pr_debug("%s wait_event interrupted ret = %d\n", __func__, ret);
		cb_req->result = OBJECT_ERROR_ABORT;
		cb_req->result = OBJECT_ERROR_ABORT;
@@ -1460,14 +1486,16 @@ static long process_server_req(struct file *filp, unsigned int cmd,
	struct smcinvoke_server server_req = {0};
	struct smcinvoke_server server_req = {0};
	struct smcinvoke_server_info *server_info = NULL;
	struct smcinvoke_server_info *server_info = NULL;


	if (_IOC_SIZE(cmd) != sizeof(server_req))
	if (_IOC_SIZE(cmd) != sizeof(server_req)) {
		pr_err("invalid command size received for server request\n");
		return -EINVAL;
		return -EINVAL;

	}
	ret = copy_from_user(&server_req, (void __user *)(uintptr_t)arg,
	ret = copy_from_user(&server_req, (void __user *)(uintptr_t)arg,
					sizeof(server_req));
					sizeof(server_req));
	if (ret)
	if (ret) {
		pr_err("copying server request from user failed\n");
		return -EFAULT;
		return -EFAULT;

	}
	server_info = kzalloc(sizeof(*server_info), GFP_KERNEL);
	server_info = kzalloc(sizeof(*server_info), GFP_KERNEL);
	if (!server_info)
	if (!server_info)
		return -ENOMEM;
		return -ENOMEM;
@@ -1507,25 +1535,36 @@ static long process_accept_req(struct file *filp, unsigned int cmd,
	struct smcinvoke_cb_txn *cb_txn = NULL;
	struct smcinvoke_cb_txn *cb_txn = NULL;
	struct smcinvoke_server_info *server_info = NULL;
	struct smcinvoke_server_info *server_info = NULL;


	if (_IOC_SIZE(cmd) != sizeof(struct smcinvoke_accept))
	if (_IOC_SIZE(cmd) != sizeof(struct smcinvoke_accept)) {
		pr_err("command size invalid for accept request\n");
		return -EINVAL;
		return -EINVAL;
	}


	if (copy_from_user(&user_args, (void __user *)arg,
	if (copy_from_user(&user_args, (void __user *)arg,
					sizeof(struct smcinvoke_accept)))
					sizeof(struct smcinvoke_accept))) {
		pr_err("copying accept request from user failed\n");
		return -EFAULT;
		return -EFAULT;
	}


	if (user_args.argsize != sizeof(union smcinvoke_arg))
	if (user_args.argsize != sizeof(union smcinvoke_arg)) {
		pr_err("arguments size is invalid for accept thread\n");
		return -EINVAL;
		return -EINVAL;
	}


	/* ACCEPT is available only on server obj */
	/* ACCEPT is available only on server obj */
	if (server_obj->context_type != SMCINVOKE_OBJ_TYPE_SERVER)
	if (server_obj->context_type != SMCINVOKE_OBJ_TYPE_SERVER) {
		pr_err("invalid object type received for accept req\n");
		return -EPERM;
		return -EPERM;
	}


	mutex_lock(&g_smcinvoke_lock);
	mutex_lock(&g_smcinvoke_lock);
	server_info = get_cb_server_locked(server_obj->server_id);
	server_info = get_cb_server_locked(server_obj->server_id);
	mutex_unlock(&g_smcinvoke_lock);
	mutex_unlock(&g_smcinvoke_lock);
	if (!server_info)
	if (!server_info) {
		pr_err("No matching server with server id : %u found\n",
						server_obj->server_id);
		return -EINVAL;
		return -EINVAL;
	}


	if (server_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT)
	if (server_info->state == SMCINVOKE_SERVER_STATE_DEFUNCT)
		server_info->state = 0;
		server_info->state = 0;
@@ -1602,6 +1641,7 @@ static long process_accept_req(struct file *filp, unsigned int cmd,
			ret = marshal_in_tzcb_req(cb_txn, &user_args,
			ret = marshal_in_tzcb_req(cb_txn, &user_args,
							server_obj->server_id);
							server_obj->server_id);
			if (ret) {
			if (ret) {
				pr_err("failed to marshal in the callback request\n");
				cb_txn->cb_req->result = OBJECT_ERROR_UNAVAIL;
				cb_txn->cb_req->result = OBJECT_ERROR_UNAVAIL;
				cb_txn->state = SMCINVOKE_REQ_PROCESSED;
				cb_txn->state = SMCINVOKE_REQ_PROCESSED;
				kref_put(&cb_txn->ref_cnt, delete_cb_txn);
				kref_put(&cb_txn->ref_cnt, delete_cb_txn);
@@ -1620,6 +1660,10 @@ static long process_accept_req(struct file *filp, unsigned int cmd,
out:
out:
	if (server_info)
	if (server_info)
		kref_put(&server_info->ref_cnt, destroy_cb_server);
		kref_put(&server_info->ref_cnt, destroy_cb_server);

	if (ret && ret != -ERESTARTSYS)
		pr_err("accept thread returning with ret: %d\n", ret);

	return ret;
	return ret;
}
}


@@ -1645,18 +1689,26 @@ static long process_invoke_req(struct file *filp, unsigned int cmd,
	int32_t tzhandles_to_release[OBJECT_COUNTS_MAX_OO] = {0};
	int32_t tzhandles_to_release[OBJECT_COUNTS_MAX_OO] = {0};
	bool tz_acked = false;
	bool tz_acked = false;


	if (_IOC_SIZE(cmd) != sizeof(req))
	if (_IOC_SIZE(cmd) != sizeof(req)) {
		pr_err("command size for invoke req is invalid\n");
		return -EINVAL;
		return -EINVAL;
	}


	if (tzobj->context_type != SMCINVOKE_OBJ_TYPE_TZ_OBJ)
	if (tzobj->context_type != SMCINVOKE_OBJ_TYPE_TZ_OBJ) {
		pr_err("object type for invoke req is invalid\n");
		return -EPERM;
		return -EPERM;
	}


	ret = copy_from_user(&req, (void __user *)arg, sizeof(req));
	ret = copy_from_user(&req, (void __user *)arg, sizeof(req));
	if (ret)
	if (ret) {
		pr_err("copying invoke req failed\n");
		return -EFAULT;
		return -EFAULT;
	}


	if (req.argsize != sizeof(union smcinvoke_arg))
	if (req.argsize != sizeof(union smcinvoke_arg)) {
		pr_err("arguments size for invoke req is invalid\n");
		return -EINVAL;
		return -EINVAL;
	}


	nr_args = OBJECT_COUNTS_NUM_buffers(req.counts) +
	nr_args = OBJECT_COUNTS_NUM_buffers(req.counts) +
			OBJECT_COUNTS_NUM_objects(req.counts);
			OBJECT_COUNTS_NUM_objects(req.counts);
@@ -1679,6 +1731,7 @@ static long process_invoke_req(struct file *filp, unsigned int cmd,
	ret = qtee_shmbridge_allocate_shm(inmsg_size, &in_shm);
	ret = qtee_shmbridge_allocate_shm(inmsg_size, &in_shm);
	if (ret) {
	if (ret) {
		ret = -ENOMEM;
		ret = -ENOMEM;
		pr_err("shmbridge alloc failed for in msg in invoke req\n");
		goto out;
		goto out;
	}
	}
	in_msg = in_shm.vaddr;
	in_msg = in_shm.vaddr;
@@ -1689,14 +1742,17 @@ static long process_invoke_req(struct file *filp, unsigned int cmd,
	ret = qtee_shmbridge_allocate_shm(outmsg_size, &out_shm);
	ret = qtee_shmbridge_allocate_shm(outmsg_size, &out_shm);
	if (ret) {
	if (ret) {
		ret = -ENOMEM;
		ret = -ENOMEM;
		pr_err("shmbridge alloc failed for out msg in invoke req\n");
		goto out;
		goto out;
	}
	}
	out_msg = out_shm.vaddr;
	out_msg = out_shm.vaddr;


	ret = marshal_in_invoke_req(&req, args_buf, tzobj->tzhandle, in_msg,
	ret = marshal_in_invoke_req(&req, args_buf, tzobj->tzhandle, in_msg,
			inmsg_size, filp_to_release, tzhandles_to_release);
			inmsg_size, filp_to_release, tzhandles_to_release);
	if (ret)
	if (ret) {
		pr_err("failed to marshal in invoke req, ret :%d\n", ret);
		goto out;
		goto out;
	}


	ret = prepare_send_scm_msg(in_msg, in_shm.paddr, inmsg_size,
	ret = prepare_send_scm_msg(in_msg, in_shm.paddr, inmsg_size,
					out_msg, out_shm.paddr, outmsg_size,
					out_msg, out_shm.paddr, outmsg_size,
@@ -1706,8 +1762,10 @@ static long process_invoke_req(struct file *filp, unsigned int cmd,
	 * If scm_call is success, TZ owns responsibility to release
	 * If scm_call is success, TZ owns responsibility to release
	 * refs for local objs.
	 * refs for local objs.
	 */
	 */
	if (!tz_acked)
	if (!tz_acked) {
		pr_debug("scm call successful\n");
		goto out;
		goto out;
	}
	memset(tzhandles_to_release, 0, sizeof(tzhandles_to_release));
	memset(tzhandles_to_release, 0, sizeof(tzhandles_to_release));


	/*
	/*
@@ -1738,6 +1796,10 @@ static long process_invoke_req(struct file *filp, unsigned int cmd,
	qtee_shmbridge_free_shm(&in_shm);
	qtee_shmbridge_free_shm(&in_shm);
	qtee_shmbridge_free_shm(&out_shm);
	qtee_shmbridge_free_shm(&out_shm);
	kfree(args_buf);
	kfree(args_buf);

	if (ret)
		pr_err("invoke thread returning with ret = %d\n", ret);

	return ret;
	return ret;
}
}


@@ -1818,12 +1880,14 @@ static int smcinvoke_release(struct inode *nodp, struct file *filp)
	ret = qtee_shmbridge_allocate_shm(SMCINVOKE_TZ_MIN_BUF_SIZE, &in_shm);
	ret = qtee_shmbridge_allocate_shm(SMCINVOKE_TZ_MIN_BUF_SIZE, &in_shm);
	if (ret) {
	if (ret) {
		ret = -ENOMEM;
		ret = -ENOMEM;
		pr_err("shmbridge alloc failed for in msg in release\n");
		goto out;
		goto out;
	}
	}


	ret = qtee_shmbridge_allocate_shm(SMCINVOKE_TZ_MIN_BUF_SIZE, &out_shm);
	ret = qtee_shmbridge_allocate_shm(SMCINVOKE_TZ_MIN_BUF_SIZE, &out_shm);
	if (ret) {
	if (ret) {
		ret = -ENOMEM;
		ret = -ENOMEM;
		pr_err("shmbridge alloc failed for out msg in release\n");
		goto out;
		goto out;
	}
	}