drm: Add DRM_DEBUG_VBL()

Add a new debug class for _verbose_ debug message from the vblank code.
That is message we spew out potentially for every vblank interrupt.
Thierry already got annoyed at the spew, and now I managed to lock up
my box with these debug prints (seems serial console + a few debug
prints every vblank aren't a good combination).

Or should I maybe call it DRM_DEBUG_IRQ?

Cc: Thierry Reding <thierry.reding@gmail.com>
Signed-off-by: Ville Syrjälä <ville.syrjala@linux.intel.com>
Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

drivers/gpu/drm/drm_irq.c

@@ -213,17 +213,17 @@ static void drm_update_vblank_count(struct drm_device *dev, unsigned int pipe,
 		diff = DIV_ROUND_CLOSEST_ULL(diff_ns, framedur_ns);
 
 		if (diff == 0 && flags & DRM_CALLED_FROM_VBLIRQ)
-			DRM_DEBUG("crtc %u: Redundant vblirq ignored."
-				  " diff_ns = %lld, framedur_ns = %d)\n",
-				  pipe, (long long) diff_ns, framedur_ns);
+			DRM_DEBUG_VBL("crtc %u: Redundant vblirq ignored."
+				      " diff_ns = %lld, framedur_ns = %d)\n",
+				      pipe, (long long) diff_ns, framedur_ns);
 	} else {
 		/* some kind of default for drivers w/o accurate vbl timestamping */
 		diff = (flags & DRM_CALLED_FROM_VBLIRQ) != 0;
 	}
 
-	DRM_DEBUG("updating vblank count on crtc %u:"
-		  " current=%u, diff=%u, hw=%u hw_last=%u\n",
-		  pipe, vblank->count, diff, cur_vblank, vblank->last);
+	DRM_DEBUG_VBL("updating vblank count on crtc %u:"
+		      " current=%u, diff=%u, hw=%u hw_last=%u\n",
+		      pipe, vblank->count, diff, cur_vblank, vblank->last);
 
 	if (diff == 0) {
 		WARN_ON_ONCE(cur_vblank != vblank->last);
@@ -800,11 +800,11 @@ int drm_calc_vbltimestamp_from_scanoutpos(struct drm_device *dev,
 		etime = ktime_sub_ns(etime, delta_ns);
 	*vblank_time = ktime_to_timeval(etime);
 
-	DRM_DEBUG("crtc %u : v 0x%x p(%d,%d)@ %ld.%ld -> %ld.%ld [e %d us, %d rep]\n",
-		  pipe, vbl_status, hpos, vpos,
-		  (long)tv_etime.tv_sec, (long)tv_etime.tv_usec,
-		  (long)vblank_time->tv_sec, (long)vblank_time->tv_usec,
-		  duration_ns/1000, i);
+	DRM_DEBUG_VBL("crtc %u : v 0x%x p(%d,%d)@ %ld.%ld -> %ld.%ld [e %d us, %d rep]\n",
+		      pipe, vbl_status, hpos, vpos,
+		      (long)tv_etime.tv_sec, (long)tv_etime.tv_usec,
+		      (long)vblank_time->tv_sec, (long)vblank_time->tv_usec,
+		      duration_ns/1000, i);
 
 	return ret;
 }

include/drm/drmP.h

@@ -107,6 +107,9 @@ struct dma_buf_attachment;
  * ATOMIC: used in the atomic code.
  *	  This is the category used by the DRM_DEBUG_ATOMIC() macro.
  *
+ * VBL: used for verbose debug message in the vblank code
+ *	  This is the category used by the DRM_DEBUG_VBL() macro.
+ *
  * Enabling verbose debug messages is done through the drm.debug parameter,
  * each category being enabled by a bit.
  *
@@ -114,7 +117,7 @@ struct dma_buf_attachment;
  * drm.debug=0x2 will enable DRIVER messages
  * drm.debug=0x3 will enable CORE and DRIVER messages
  * ...
- * drm.debug=0xf will enable all messages
+ * drm.debug=0x3f will enable all messages
  *
  * An interesting feature is that it's possible to enable verbose logging at
  * run-time by echoing the debug value in its sysfs node:
@@ -125,6 +128,7 @@ struct dma_buf_attachment;
 #define DRM_UT_KMS		0x04
 #define DRM_UT_PRIME		0x08
 #define DRM_UT_ATOMIC		0x10
+#define DRM_UT_VBL		0x20
 
 extern __printf(2, 3)
 void drm_ut_debug_printk(const char *function_name,
@@ -217,6 +221,11 @@ void drm_err(const char *format, ...);
 		if (unlikely(drm_debug & DRM_UT_ATOMIC))		\
 			drm_ut_debug_printk(__func__, fmt, ##args);	\
 	} while (0)
+#define DRM_DEBUG_VBL(fmt, args...)					\
+	do {								\
+		if (unlikely(drm_debug & DRM_UT_VBL))			\
+			drm_ut_debug_printk(__func__, fmt, ##args);	\
+	} while (0)
 
 /*@}*/