msm: camera: smmu: Profile time taken for map, unmap

Add debugging capability to profile ion alloc,
smmu map and unmap calls. Enable below debugfs settings
to get the traces with corresponding latencies.
Alloc      : echo 1 > /sys/kernel/debug/camera_memmgr/alloc_profile_enable
Map, Unmap : echo 1 > /sys/kernel/debug/camera_smmu/map_profile_enable
Capture the profiling numbers in traces.

CRs-Fixed: 2538876
Change-Id: I92dc58416a9febc77a7836b8f7b1523b547c128f
Signed-off-by: Pavan Kumar Chilamkurthi <[email protected]>

drivers/cam_req_mgr/cam_mem_mgr.c

@@ -1,6 +1,6 @@
 // SPDX-License-Identifier: GPL-2.0-only
 /*
- * Copyright (c) 2016-2019, The Linux Foundation. All rights reserved.
+ * Copyright (c) 2016-2020, The Linux Foundation. All rights reserved.
  */
 
 #include <linux/module.h>
@@ -9,12 +9,15 @@
 #include <linux/slab.h>
 #include <linux/dma-buf.h>
 #include <linux/version.h>
+#include <linux/debugfs.h>
 
 #include "cam_compat.h"
 #include "cam_req_mgr_util.h"
 #include "cam_mem_mgr.h"
 #include "cam_smmu_api.h"
 #include "cam_debug_util.h"
+#include "cam_trace.h"
+#include "cam_common_util.h"
 
 static struct cam_mem_table tbl;
 static atomic_t cam_mem_mgr_state = ATOMIC_INIT(CAM_MEM_MGR_UNINITIALIZED);
@@ -116,6 +119,29 @@ static int cam_mem_util_unmap_cpu_va(struct dma_buf *dmabuf,
 	return rc;
 }
 
+static int cam_mem_mgr_create_debug_fs(void)
+{
+	tbl.dentry = debugfs_create_dir("camera_memmgr", NULL);
+	if (!tbl.dentry) {
+		CAM_ERR(CAM_MEM, "failed to create dentry");
+		return -ENOMEM;
+	}
+
+	if (!debugfs_create_bool("alloc_profile_enable",
+		0644,
+		tbl.dentry,
+		&tbl.alloc_profile_enable)) {
+		CAM_ERR(CAM_MEM,
+			"failed to create alloc_profile_enable");
+		goto err;
+	}
+
+	return 0;
+err:
+	debugfs_remove_recursive(tbl.dentry);
+	return -ENOMEM;
+}
+
 int cam_mem_mgr_init(void)
 {
 	int i;
@@ -141,6 +167,8 @@ int cam_mem_mgr_init(void)
 
 	atomic_set(&cam_mem_mgr_state, CAM_MEM_MGR_INITIALIZED);
 
+	cam_mem_mgr_create_debug_fs();
+
 	return 0;
 }
 
@@ -375,12 +403,17 @@ static int cam_mem_util_get_dma_buf_fd(size_t len,
 {
 	struct dma_buf *dmabuf = NULL;
 	int rc = 0;
+	struct timespec64 ts1, ts2;
+	long microsec = 0;
 
 	if (!buf || !fd) {
 		CAM_ERR(CAM_MEM, "Invalid params, buf=%pK, fd=%pK", buf, fd);
 		return -EINVAL;
 	}
 
+	if (tbl.alloc_profile_enable)
+		CAM_GET_TIMESTAMP(ts1);
+
 	*buf = ion_alloc(len, heap_id_mask, flags);
 	if (IS_ERR_OR_NULL(*buf))
 		return -ENOMEM;
@@ -403,6 +436,13 @@ static int cam_mem_util_get_dma_buf_fd(size_t len,
 		rc = -EINVAL;
 	}
 
+	if (tbl.alloc_profile_enable) {
+		CAM_GET_TIMESTAMP(ts2);
+		CAM_GET_TIMESTAMP_DIFF_IN_MICRO(ts1, ts2, microsec);
+		trace_cam_log_event("IONAllocProfile", "size and time in micro",
+			len, microsec);
+	}
+
 	return rc;
 
 get_fd_fail:
@@ -639,8 +679,9 @@ int cam_mem_mgr_alloc_and_map(struct cam_mem_mgr_alloc_cmd *cmd)
 
 		if (rc) {
 			CAM_ERR(CAM_MEM,
-				"Failed in map_hw_va, flags=0x%x, fd=%d, region=%d, num_hdl=%d, rc=%d",
-				cmd->flags, fd, region, cmd->num_hdl, rc);
+				"Failed in map_hw_va, len=%llu, flags=0x%x, fd=%d, region=%d, num_hdl=%d, rc=%d",
+				cmd->len, cmd->flags, fd, region,
+				cmd->num_hdl, rc);
 			goto map_hw_fail;
 		}
 	}

drivers/cam_req_mgr/cam_mem_mgr.h

@@ -1,6 +1,6 @@
 /* SPDX-License-Identifier: GPL-2.0-only */
 /*
- * Copyright (c) 2016-2019, The Linux Foundation. All rights reserved.
+ * Copyright (c) 2016-2020, The Linux Foundation. All rights reserved.
  */
 
 #ifndef _CAM_MEM_MGR_H_
@@ -65,12 +65,16 @@ struct cam_mem_buf_queue {
  * @bitmap: bitmap of the mem mgr utility
  * @bits: max bits of the utility
  * @bufq: array of buffers
+ * @dentry: Debugfs entry
+ * @alloc_profile_enable: Whether to enable alloc profiling
  */
 struct cam_mem_table {
 	struct mutex m_lock;
 	void *bitmap;
 	size_t bits;
 	struct cam_mem_buf_queue bufq[CAM_MEM_BUFQ_MAX];
+	struct dentry *dentry;
+	bool alloc_profile_enable;
 };
 
 /**

drivers/cam_smmu/cam_smmu_api.c

@@ -23,6 +23,8 @@
 #include "cam_smmu_api.h"
 #include "cam_debug_util.h"
 #include "camera_main.h"
+#include "cam_trace.h"
+#include "cam_common_util.h"
 
 #define SHARED_MEM_POOL_GRANULARITY 16
 
@@ -147,6 +149,7 @@ struct cam_iommu_cb_set {
 	u32 non_fatal_fault;
 	struct dentry *dentry;
 	bool cb_dump_enable;
+	bool map_profile_enable;
 };
 
 static const struct of_device_id msm_cam_smmu_dt_match[] = {
@@ -1718,6 +1721,8 @@ static int cam_smmu_map_buffer_validate(struct dma_buf *buf,
 	size_t size = 0;
 	uint32_t iova = 0;
 	int rc = 0;
+	struct timespec64 ts1, ts2;
+	long microsec = 0;
 
 	if (IS_ERR_OR_NULL(buf)) {
 		rc = PTR_ERR(buf);
@@ -1732,6 +1737,9 @@ static int cam_smmu_map_buffer_validate(struct dma_buf *buf,
 		goto err_out;
 	}
 
+	if (iommu_cb_set.map_profile_enable)
+		CAM_GET_TIMESTAMP(ts1);
+
 	attach = dma_buf_attach(buf, iommu_cb_set.cb_info[idx].dev);
 	if (IS_ERR_OR_NULL(attach)) {
 		rc = PTR_ERR(attach);
@@ -1791,7 +1799,9 @@ static int cam_smmu_map_buffer_validate(struct dma_buf *buf,
 		table = dma_buf_map_attachment(attach, dma_dir);
 		if (IS_ERR_OR_NULL(table)) {
 			rc = PTR_ERR(table);
-			CAM_ERR(CAM_SMMU, "Error: dma map attachment failed");
+			CAM_ERR(CAM_SMMU,
+				"Error: dma map attachment failed, size=%zu",
+				buf->size);
 			goto err_detach;
 		}
 
@@ -1808,6 +1818,13 @@ static int cam_smmu_map_buffer_validate(struct dma_buf *buf,
 		"iova=%pK, region_id=%d, paddr=%pK, len=%d, dma_map_attrs=%d",
 		iova, region_id, *paddr_ptr, *len_ptr, attach->dma_map_attrs);
 
+	if (iommu_cb_set.map_profile_enable) {
+		CAM_GET_TIMESTAMP(ts2);
+		CAM_GET_TIMESTAMP_DIFF_IN_MICRO(ts1, ts2, microsec);
+		trace_cam_log_event("SMMUMapProfile", "size and time in micro",
+			*len_ptr, microsec);
+	}
+
 	if (table->sgl) {
 		CAM_DBG(CAM_SMMU,
 			"DMA buf: %pK, device: %pK, attach: %pK, table: %pK",
@@ -1934,6 +1951,8 @@ static int cam_smmu_unmap_buf_and_remove_from_list(
 	int rc;
 	size_t size;
 	struct iommu_domain *domain;
+	struct timespec64 ts1, ts2;
+	long microsec = 0;
 
 	if ((!mapping_info->buf) || (!mapping_info->table) ||
 		(!mapping_info->attach)) {
@@ -1952,6 +1971,9 @@ static int cam_smmu_unmap_buf_and_remove_from_list(
 		mapping_info->region_id, mapping_info->paddr, mapping_info->len,
 		mapping_info->attach->dma_map_attrs);
 
+	if (iommu_cb_set.map_profile_enable)
+		CAM_GET_TIMESTAMP(ts1);
+
 	if (mapping_info->region_id == CAM_SMMU_REGION_SHARED) {
 		CAM_DBG(CAM_SMMU,
 			"Removing SHARED buffer paddr = %pK, len = %zu",
@@ -1988,6 +2010,13 @@ static int cam_smmu_unmap_buf_and_remove_from_list(
 	dma_buf_detach(mapping_info->buf, mapping_info->attach);
 	dma_buf_put(mapping_info->buf);
 
+	if (iommu_cb_set.map_profile_enable) {
+		CAM_GET_TIMESTAMP(ts2);
+		CAM_GET_TIMESTAMP_DIFF_IN_MICRO(ts1, ts2, microsec);
+		trace_cam_log_event("SMMUUnmapProfile",
+			"size and time in micro", mapping_info->len, microsec);
+	}
+
 	mapping_info->buf = NULL;
 
 	list_del_init(&mapping_info->list);
@@ -3633,6 +3662,15 @@ static int cam_smmu_create_debug_fs(void)
 		goto err;
 	}
 
+	if (!debugfs_create_bool("map_profile_enable",
+		0644,
+		iommu_cb_set.dentry,
+		&iommu_cb_set.map_profile_enable)) {
+		CAM_ERR(CAM_SMMU,
+			"failed to create map_profile_enable");
+		goto err;
+	}
+
 	return 0;
 err:
 	debugfs_remove_recursive(iommu_cb_set.dentry);

drivers/cam_utils/cam_common_util.h

@@ -1,6 +1,6 @@
 /* SPDX-License-Identifier: GPL-2.0-only */
 /*
- * Copyright (c) 2017-2019, The Linux Foundation. All rights reserved.
+ * Copyright (c) 2017-2020, The Linux Foundation. All rights reserved.
  */
 
 #ifndef _CAM_COMMON_UTIL_H_
@@ -14,6 +14,25 @@
 #define PTR_TO_U64(ptr) ((uint64_t)(uintptr_t)ptr)
 #define U64_TO_PTR(ptr) ((void *)(uintptr_t)ptr)
 
+#define CAM_GET_TIMESTAMP(timestamp) ktime_get_real_ts64(&(timestamp))
+#define CAM_GET_TIMESTAMP_DIFF_IN_MICRO(ts_start, ts_end, diff_microsec)       \
+({                                                                             \
+	diff_microsec = 0;                                                     \
+	if (ts_end.tv_nsec >= ts_start.tv_nsec) {                              \
+		diff_microsec =                                                \
+			(ts_end.tv_nsec - ts_start.tv_nsec) / 1000;            \
+		diff_microsec +=                                               \
+			(ts_end.tv_sec - ts_start.tv_sec) * 1000 * 1000;       \
+	} else {                                                               \
+		diff_microsec =                                                \
+			(ts_end.tv_nsec +                                      \
+			(1000*1000*1000 - ts_start.tv_nsec)) / 1000;           \
+		diff_microsec +=                                               \
+			(ts_end.tv_sec - ts_start.tv_sec - 1) * 1000 * 1000;   \
+	}                                                                      \
+})
+
+
 /**
  * cam_common_util_get_string_index()
  *