drm/msm: add event log for profiling msm drm driver events

Provide highspeed lockless logging facility for profiling time
sensitive events in the drm msm driver. Registers with debugfs
as evtlog. Can be cleared with echo 0.

Conflicts:
	drivers/gpu/drm/msm/msm_drv.h

Change-Id: I6b8887b5fa2172ce38dced86128f4ba84b1a58f1
Signed-off-by: Lloyd Atkinson <latkinso@codeaurora.org>
Signed-off-by: Dhaval Patel <pdhaval@codeaurora.org>
[narendram@codeaurora.org: resolve conflict in
msm_drv.h conflict]
Signed-off-by: Narendra Muppalla <narendram@codeaurora.org>
diff --git a/drivers/gpu/drm/msm/Makefile b/drivers/gpu/drm/msm/Makefile
index 0ce53b7..4a34ffb 100644
--- a/drivers/gpu/drm/msm/Makefile
+++ b/drivers/gpu/drm/msm/Makefile
@@ -62,7 +62,8 @@
 	msm_smmu.o \
 	msm_perf.o \
 	msm_rd.o \
-	msm_ringbuffer.o
+	msm_ringbuffer.o \
+	msm_evtlog.o \
 
 msm-$(CONFIG_DRM_FBDEV_EMULATION) += msm_fbdev.o
 msm-$(CONFIG_SYNC) += sde/sde_fence.o
diff --git a/drivers/gpu/drm/msm/msm_drv.h b/drivers/gpu/drm/msm/msm_drv.h
index b8bbfbe..44b2d32 100644
--- a/drivers/gpu/drm/msm/msm_drv.h
+++ b/drivers/gpu/drm/msm/msm_drv.h
@@ -43,6 +43,8 @@
 #include <drm/msm_drm.h>
 #include <drm/drm_gem.h>
 
+#include "msm_evtlog.h"
+
 struct msm_kms;
 struct msm_gpu;
 struct msm_mmu;
@@ -185,6 +187,8 @@
 	 * ioctl.
 	 */
 	struct task_struct *struct_mutex_task;
+
+	struct msm_evtlog evtlog;
 };
 
 struct msm_format {
diff --git a/drivers/gpu/drm/msm/msm_evtlog.c b/drivers/gpu/drm/msm/msm_evtlog.c
new file mode 100644
index 0000000..0562be4
--- /dev/null
+++ b/drivers/gpu/drm/msm/msm_evtlog.c
@@ -0,0 +1,172 @@
+/* Copyright (c) 2016, The Linux Foundation. All rights reserved.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License version 2 and
+ * only version 2 as published by the Free Software Foundation.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+
+#define pr_fmt(fmt)	"msm_evtlog:[%s] " fmt, __func__
+
+#include "msm_evtlog.h"
+#include <linux/slab.h>
+#include <linux/sched.h>
+#include <asm-generic/current.h>
+#include <linux/uaccess.h>
+#include <linux/debugfs.h>
+
+#define SIZE_MASK(x) (x - 1)
+
+static int msm_evtlog_debugfs_dump(struct seq_file *s, void *data)
+{
+	struct msm_evtlog *log = s->private;
+	unsigned long cnt;	/* # of samples since clear */
+	unsigned long n;	/* # of samples to print, also head index */
+	unsigned long i;
+	struct timespec timespec;
+
+	/**
+	 * Prints in chronological order, oldest -> newest
+	 * Note due to lock-less design, the first few printed entries
+	 * may be corrupted by new writer not oldest.
+	 * This is a tradeoff for speed of sampling
+	 */
+	cnt = atomic_read(&log->cnt);
+	if (!cnt)
+		return 0;
+
+	n = cnt & SIZE_MASK(log->size);
+
+	/**
+	 * If not full, print from first log
+	 * (which is index 1 since atomic_inc_return is prefix operator)
+	 */
+	i = (cnt < log->size) ? 0 : n;
+
+	seq_puts(s, "time_ns, pid, func, line, val1, val2, msg\n");
+	do {
+		i = (i + 1) & SIZE_MASK(log->size);
+		timespec = ktime_to_timespec(log->events[i].ktime);
+		seq_printf(s, "[%5lu.%06lu], %d, %s, %d, %llu, %llu, %s\n",
+				timespec.tv_sec,
+				timespec.tv_nsec / 1000,
+				log->events[i].pid,
+				log->events[i].func,
+				log->events[i].line,
+				log->events[i].val1,
+				log->events[i].val2,
+				log->events[i].msg);
+	} while (i != n);
+
+	return 0;
+}
+
+static int msm_evtlog_debugfs_open_dump(struct inode *inode, struct file *file)
+{
+	return single_open(file, msm_evtlog_debugfs_dump, inode->i_private);
+}
+
+static ssize_t msm_evtlog_debugfs_write(
+		struct file *file,
+		const char __user *user_buf,
+		size_t size,
+		loff_t *ppos)
+{
+	struct seq_file *s = file->private_data;
+	struct msm_evtlog *log = s->private;
+	char buf[64];
+	int buf_size;
+
+	buf_size = min(size, (sizeof(buf) - 1));
+	if (strncpy_from_user(buf, user_buf, buf_size) < 0)
+		return -EFAULT;
+	buf[buf_size] = 0;
+
+	if (strcmp(buf, "0") == 0)
+		atomic_set(&log->cnt, 0);
+
+	return size;
+
+}
+
+static const struct file_operations msm_evtlog_fops = {
+	.open =		msm_evtlog_debugfs_open_dump,
+	.read =		seq_read,
+	.write =	msm_evtlog_debugfs_write,
+	.llseek =	seq_lseek,
+	.release =	single_release,
+};
+
+int msm_evtlog_init(
+		struct msm_evtlog *log,
+		int size,
+		struct dentry *parent)
+{
+	if (!log || size < 1) {
+		pr_err("Invalid params\n");
+		return -EINVAL;
+	}
+
+	memset(log, 0, sizeof(*log));
+	log->size = roundup_pow_of_two(size);
+	log->events = kcalloc(log->size, sizeof(struct msm_evtlog_evt),
+			GFP_KERNEL);
+
+	if (!log->events) {
+		pr_err("Insufficient memory\n");
+		return -ENOMEM;
+	}
+
+	atomic_set(&log->cnt, 0);
+
+	log->dentry = debugfs_create_file("evtlog", 0644, parent,
+			log, &msm_evtlog_fops);
+
+	if (IS_ERR_OR_NULL(log->dentry)) {
+		int rc = PTR_ERR(log->dentry);
+
+		pr_err("debugfs create file failed, rc=%d\n", rc);
+		kfree(log->events);
+		return rc;
+	}
+
+	return 0;
+}
+
+void msm_evtlog_destroy(struct msm_evtlog *log)
+{
+	debugfs_remove(log->dentry);
+
+	/* Caller needs to make sure that log sampling has stopped */
+	kfree(log->events);
+
+}
+
+void msm_evtlog_sample(
+		struct msm_evtlog *log,
+		const char *func,
+		const char *msg,
+		uint64_t val1,
+		uint64_t val2,
+		uint32_t line)
+{
+	unsigned long i;
+
+	/**
+	 * Since array sized with pow of 2, roll to 0 when cnt overflows
+	 * mod the value with the size to get current idx into array
+	 */
+	i = (unsigned long)(atomic_inc_return(&log->cnt)) &
+			SIZE_MASK(log->size);
+	log->events[i].ktime = ktime_get();
+	log->events[i].func = func;
+	log->events[i].msg = msg;
+	log->events[i].val1 = val1;
+	log->events[i].val2 = val2;
+	log->events[i].line = line;
+	log->events[i].pid = current->pid;
+}
diff --git a/drivers/gpu/drm/msm/msm_evtlog.h b/drivers/gpu/drm/msm/msm_evtlog.h
new file mode 100644
index 0000000..15b5e96
--- /dev/null
+++ b/drivers/gpu/drm/msm/msm_evtlog.h
@@ -0,0 +1,102 @@
+/* Copyright (c) 2016, The Linux Foundation. All rights reserved.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License version 2 and
+ * only version 2 as published by the Free Software Foundation.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ */
+
+#ifndef MSM_MSM_EVTLOG_H_
+#define MSM_MSM_EVTLOG_H_
+
+#include <linux/ktime.h>
+#include <linux/atomic.h>
+#include <linux/dcache.h>
+
+/**
+ * struct msm_evtlog_evt - Event log entry
+ * @ktime:     Timestamp of event
+ * @func:      Calling function name
+ * @msg:       User provided string
+ * @val1:      User provided value
+ * @val2:      User provided value
+ * @line:      Line number of caller
+ * @pid:       Process id of logger
+ */
+struct msm_evtlog_evt {
+	ktime_t ktime;
+	const char *func;
+	const char *msg;
+	uint64_t val1;
+	uint64_t val2;
+	uint32_t line;
+	uint32_t pid;
+};
+
+/**
+ * struct msm_evtlog - current driver state information
+ * @events:    Pointer to dynamically allocated event log buffer
+ * @cnt:       Atomic number of events since clear. Can be used to calculate
+ *             the current index. Note: The count does not wrap.
+ *             Reset the event log by setting to zero.
+ *             Used for lock-less producer synchronization.
+ * @size:      Size of events array. Must be power of 2 to facilitate fast
+ *             increments by using a bitmask to get rollover.
+ * @dentry:    Filesystem entry of debugfs registration
+ */
+struct msm_evtlog {
+	struct msm_evtlog_evt *events;
+	atomic_t cnt;
+	unsigned long size;
+	struct dentry *dentry;
+};
+
+/**
+ * msm_evtlog_init() - Create an event log, registered with debugfs.
+ * @log:     Event log handle
+ * @size:    Max # of events in buffer. Will be rounded up to power of 2.
+ * @parent:  Parent directory entry for debugfs registration
+ *
+ * Return: error code.
+ */
+int msm_evtlog_init(struct msm_evtlog *log, int size, struct dentry *parent);
+
+/**
+ * msm_evtlog_destroy() - Destroy event log
+ * @log:            Event log handle
+ *
+ * Unregisters debugfs node and frees memory.
+ * Caller needs to make sure that log sampling has stopped.
+ */
+void msm_evtlog_destroy(struct msm_evtlog *log);
+
+/**
+ * msm_evtlog_sample() - Add entry to the event log
+ * @evtlog:            Event log handle
+ * @func:              Calling function name
+ * @msg:               User provided string
+ * @val1:              User provided value
+ * @val2:              User provided value
+ * @line:              Line number of caller
+ */
+void msm_evtlog_sample(
+		struct msm_evtlog *log,
+		const char *func,
+		const char *msg,
+		uint64_t val1,
+		uint64_t val2,
+		uint32_t line);
+
+/**
+ * Helper macros
+ */
+#define MSM_EVT_MSG(log, msg, x, y) ( \
+		msm_evtlog_sample((log), __func__, (msg), \
+			((uint64_t) x), (uint64_t)(y), __LINE__))
+#define MSM_EVT(log, x, y) MSM_EVT_MSG((log), 0, (x), (y))
+
+#endif /* MSM_MSM_EVTLOG_H_ */
diff --git a/drivers/gpu/drm/msm/sde/sde_crtc.c b/drivers/gpu/drm/msm/sde/sde_crtc.c
index 2b63240..cfd690d 100644
--- a/drivers/gpu/drm/msm/sde/sde_crtc.c
+++ b/drivers/gpu/drm/msm/sde/sde_crtc.c
@@ -363,6 +363,7 @@
 	struct sde_crtc *sde_crtc = to_sde_crtc(crtc);
 	struct sde_kms *sde_kms = get_kms(crtc);
 	struct drm_device *dev = sde_kms->dev;
+	struct msm_drm_private *priv = dev->dev_private;
 	unsigned int pending;
 
 	pending = atomic_xchg(&sde_crtc->pending, 0);
@@ -373,6 +374,7 @@
 	if (sde_crtc->drm_requested_vblank) {
 		drm_handle_vblank(dev, sde_crtc->id);
 		DBG_IRQ("");
+		MSM_EVT(&priv->evtlog, sde_crtc->id, 0);
 	}
 }
 
diff --git a/drivers/gpu/drm/msm/sde/sde_encoder.c b/drivers/gpu/drm/msm/sde/sde_encoder.c
index 55c200d..69b2206 100644
--- a/drivers/gpu/drm/msm/sde/sde_encoder.c
+++ b/drivers/gpu/drm/msm/sde/sde_encoder.c
@@ -27,6 +27,10 @@
 #define MAX_PHYS_ENCODERS_PER_VIRTUAL \
 	(MAX_H_TILES_PER_DISPLAY * NUM_PHYS_ENCODER_TYPES)
 
+#define EVTLOG(enc) (!enc ? NULL : \
+		!enc->base.dev ? NULL : \
+		&((struct msm_drm_private *)enc->base.dev->dev_private)->evtlog)
+
 /**
  * struct sde_encoder_virt - virtual encoder. Container of one or more physical
  *	encoders. Virtual encoder manages one "logical" display. Physical
@@ -205,6 +209,7 @@
 	}
 
 	sde_enc = to_sde_encoder_virt(drm_enc);
+	MSM_EVT(EVTLOG(sde_enc), 0, 0);
 
 	for (i = 0; i < sde_enc->num_phys_encs; i++) {
 		struct sde_encoder_phys *phys = sde_enc->phys_encs[i];
@@ -226,6 +231,8 @@
 	/* Call to populate mode->crtc* information required by framework */
 	drm_mode_set_crtcinfo(adj_mode, 0);
 
+	MSM_EVT(EVTLOG(sde_enc), adj_mode->flags, adj_mode->private_flags);
+
 	return ret;
 }
 
@@ -244,6 +251,7 @@
 	}
 
 	sde_enc = to_sde_encoder_virt(drm_enc);
+	MSM_EVT(EVTLOG(sde_enc), 0, 0);
 
 	for (i = 0; i < sde_enc->num_phys_encs; i++) {
 		struct sde_encoder_phys *phys = sde_enc->phys_encs[i];
@@ -272,6 +280,7 @@
 	}
 
 	sde_enc = to_sde_encoder_virt(drm_enc);
+	MSM_EVT(EVTLOG(sde_enc), 0, 0);
 
 	bs_set(sde_enc, 1);
 
@@ -308,6 +317,7 @@
 	}
 
 	sde_enc = to_sde_encoder_virt(drm_enc);
+	MSM_EVT(EVTLOG(sde_enc), 0, 0);
 
 	for (i = 0; i < sde_enc->num_phys_encs; i++) {
 		struct sde_encoder_phys *phys = sde_enc->phys_encs[i];
diff --git a/drivers/gpu/drm/msm/sde/sde_kms.c b/drivers/gpu/drm/msm/sde/sde_kms.c
index 7a25ffa..c45e6c4 100644
--- a/drivers/gpu/drm/msm/sde/sde_kms.c
+++ b/drivers/gpu/drm/msm/sde/sde_kms.c
@@ -581,7 +581,7 @@
 	sde_debugfs_init(sde_kms);
 	msm_evtlog_init(&priv->evtlog, SDE_EVTLOG_SIZE,
 			sde_debugfs_get_root(sde_kms));
-	MSM_EVT(dev, 0, 0);
+	MSM_EVT(&priv->evtlog, 0, 0);
 
 	/*
 	 * modeset_init should create the DRM related objects i.e. CRTCs,