sync: Add a "details" callback for sync points

Allow drivers to add a callback for expanded details about a sync
point.  This provides for a much richer debug experience than can
be provided by the simpler callbacks.

Change-Id: Ic0dedbad19fddc2f9b753d886994247e8025d6dc
Signed-off-by: Jordan Crouse <jcrouse@codeaurora.org>
Signed-off-by: Lynus Vaz <lvaz@codeaurora.org>

drivers/base/sync.c

@@ -34,7 +34,6 @@
 static void sync_fence_signal_pt(struct sync_pt *pt);
 static int _sync_pt_has_signaled(struct sync_pt *pt);
 static void sync_fence_free(struct kref *kref);
-static void sync_dump(struct sync_fence *fence);
 
 static LIST_HEAD(sync_timeline_list_head);
 static DEFINE_SPINLOCK(sync_timeline_list_lock);
@@ -586,6 +585,73 @@ static bool sync_fence_check(struct sync_fence *fence)
 	return fence->status != 0;
 }
 
+static const char *sync_status_str(int status)
+{
+	if (status > 0)
+		return "signaled";
+	else if (status == 0)
+		return "active";
+	else
+		return "error";
+}
+
+static void sync_pt_log(struct sync_pt *pt)
+{
+	int status = pt->status;
+	pr_cont("  %s_pt %s",
+		   pt->parent->name,
+		   sync_status_str(status));
+
+	if (pt->status) {
+		struct timeval tv = ktime_to_timeval(pt->timestamp);
+		pr_cont("@%ld.%06ld", tv.tv_sec, tv.tv_usec);
+	}
+
+	if (pt->parent->ops->timeline_value_str &&
+	    pt->parent->ops->pt_value_str) {
+		char value[64];
+		pt->parent->ops->pt_value_str(pt, value, sizeof(value));
+		pr_cont(": %s", value);
+		pt->parent->ops->timeline_value_str(pt->parent, value,
+					    sizeof(value));
+		pr_cont(" / %s", value);
+	}
+
+	pr_cont("\n");
+
+	if (pt->parent->ops->pt_log)
+		pt->parent->ops->pt_log(pt);
+}
+
+void sync_fence_log(struct sync_fence *fence)
+{
+	struct list_head *pos;
+	unsigned long flags;
+
+	pr_info("[%p] %s: %s\n", fence, fence->name,
+		sync_status_str(fence->status));
+
+	pr_info("waiters:\n");
+
+	spin_lock_irqsave(&fence->waiter_list_lock, flags);
+	list_for_each(pos, &fence->waiter_list_head) {
+		struct sync_fence_waiter *waiter =
+			container_of(pos, struct sync_fence_waiter,
+				     waiter_list);
+
+		pr_info(" %pF\n", waiter->callback);
+	}
+	spin_unlock_irqrestore(&fence->waiter_list_lock, flags);
+
+	pr_info("syncpoints:\n");
+	list_for_each(pos, &fence->pt_list_head) {
+		struct sync_pt *pt =
+			container_of(pos, struct sync_pt, pt_list);
+		sync_pt_log(pt);
+	}
+}
+EXPORT_SYMBOL(sync_fence_log);
+
 int sync_fence_wait(struct sync_fence *fence, long timeout)
 {
 	int err = 0;
@@ -611,7 +677,7 @@ int sync_fence_wait(struct sync_fence *fence, long timeout)
 
 	if (fence->status < 0) {
 		pr_info("fence error %d on [%p]\n", fence->status, fence);
-		sync_dump(fence);
+		sync_fence_log(fence);
 		return fence->status;
 	}
 
@@ -619,7 +685,7 @@ int sync_fence_wait(struct sync_fence *fence, long timeout)
 		if (timeout > 0) {
 			pr_info("fence timeout on [%p] after %dms\n", fence,
 				jiffies_to_msecs(timeout));
-			sync_dump(fence);
+			sync_fence_log(fence);
 		}
 		return -ETIME;
 	}
@@ -841,16 +907,6 @@ static long sync_fence_ioctl(struct file *file, unsigned int cmd,
 }
 
 #ifdef CONFIG_DEBUG_FS
-static const char *sync_status_str(int status)
-{
-	if (status > 0)
-		return "signaled";
-	else if (status == 0)
-		return "active";
-	else
-		return "error";
-}
-
 static void sync_print_pt(struct seq_file *s, struct sync_pt *pt, bool fence)
 {
 	int status = pt->status;
@@ -983,35 +1039,4 @@ static __init int sync_debugfs_init(void)
 	return 0;
 }
 late_initcall(sync_debugfs_init);
-
-#define DUMP_CHUNK 256
-static char sync_dump_buf[64 * 1024];
-static void sync_dump(struct sync_fence *fence)
-{
-       struct seq_file s = {
-               .buf = sync_dump_buf,
-               .size = sizeof(sync_dump_buf) - 1,
-       };
-       int i;
-
-       seq_printf(&s, "fence:\n--------------\n");
-       sync_print_fence(&s, fence);
-       seq_printf(&s, "\n");
-
-       for (i = 0; i < s.count; i += DUMP_CHUNK) {
-               if ((s.count - i) > DUMP_CHUNK) {
-                       char c = s.buf[i + DUMP_CHUNK];
-                       s.buf[i + DUMP_CHUNK] = 0;
-                       pr_cont("%s", s.buf + i);
-                       s.buf[i + DUMP_CHUNK] = c;
-               } else {
-                       s.buf[s.count] = 0;
-                       pr_cont("%s", s.buf + i);
-               }
-       }
-}
-#else
-static void sync_dump(struct sync_fence *fence)
-{
-}
 #endif

include/linux/sync.h

@@ -84,6 +84,9 @@ struct sync_timeline_ops {
 
 	/* optional */
 	void (*pt_value_str)(struct sync_pt *pt, char *str, int size);
+
+	/* optional */
+	void (*pt_log)(struct sync_pt *pt);
 };
 
 /**
@@ -342,6 +345,15 @@ int sync_fence_cancel_async(struct sync_fence *fence,
  */
 int sync_fence_wait(struct sync_fence *fence, long timeout);
 
+/**
+ * sync_fence_log() - log the details of the fence in the kernel log
+ * @fence:	fence to log
+ *
+ * Log the details of the fence and the associated sync points in the kernel
+ * log.
+ */
+void sync_fence_log(struct sync_fence *fence);
+
 #endif /* __KERNEL__ */
 
 /**