ivtv: improve debug messages

From: Hans Verkuil <hverkuil@xs4all.nl>

- add FILE debug flag for open/close/read/write/poll.
- show cmd for encoder/decoder command ioctl.

Signed-off-by: Hans Verkuil <hverkuil@xs4all.nl>

5 files changed, 64 insertions, 42 deletions

diff --git a/linux/drivers/media/video/ivtv/ivtv-driver.c b/linux/drivers/media/video/ivtv/ivtv-driver.c
index 619efb5f3..241c43b38 100644
--- a/linux/drivers/media/video/ivtv/ivtv-driver.c
+++ b/linux/drivers/media/video/ivtv/ivtv-driver.c
@@ -186,8 +186,18 @@ MODULE_PARM_DESC(pal, "Set PAL standard: B, G, H, D, K, I, M, N, Nc, 60");
 MODULE_PARM_DESC(secam, "Set SECAM standard: B, G, H, D, K, L, LC");
 MODULE_PARM_DESC(ntsc, "Set NTSC standard: M, J, K");
 MODULE_PARM_DESC(debug,
-		 "Debug level (bitmask). Default: errors only\n"
-		 "\t\t\t(debug = 1023 gives full debugging)");
+		 "Debug level (bitmask). Default: 0\n"
+		 "\t\t\t   1/0x0001: warning\n"
+		 "\t\t\t   2/0x0002: info\n"
+		 "\t\t\t   4/0x0004: mailbox\n"
+		 "\t\t\t   8/0x0008: ioctl\n"
+		 "\t\t\t  16/0x0010: file\n"
+		 "\t\t\t  32/0x0020: dma\n"
+		 "\t\t\t  64/0x0040: irq\n"
+		 "\t\t\t 128/0x0080: decoder\n"
+		 "\t\t\t 256/0x0100: yuv\n"
+		 "\t\t\t 512/0x0200: i2c\n"
+		 "\t\t\t1024/0x0400: high volume\n");
 MODULE_PARM_DESC(ivtv_pci_latency,
 		 "Change the PCI latency to 64 if lower: 0 = No, 1 = Yes,\n"
 		 "\t\t\tDefault: Yes");
@@ -1358,9 +1368,9 @@ static int module_start(void)
 		return -1;
 	}
 
-	if (ivtv_debug < 0 || ivtv_debug > 1023) {
+	if (ivtv_debug < 0 || ivtv_debug > 2047) {
 		ivtv_debug = 0;
-		printk(KERN_INFO "ivtv:  Debug value must be >= 0 and <= 1023\n");
+		printk(KERN_INFO "ivtv:  Debug value must be >= 0 and <= 2047\n");
 	}
 
 	if (pci_register_driver(&ivtv_pci_driver)) {
diff --git a/linux/drivers/media/video/ivtv/ivtv-driver.h b/linux/drivers/media/video/ivtv/ivtv-driver.h
index 7ca9a775d..7d5a64447 100644
--- a/linux/drivers/media/video/ivtv/ivtv-driver.h
+++ b/linux/drivers/media/video/ivtv/ivtv-driver.h
@@ -262,17 +262,18 @@ extern const u32 yuv_offset[4];
 
 /* debugging */
 
-#define IVTV_DBGFLG_WARN  (1 << 0)
-#define IVTV_DBGFLG_INFO  (1 << 1)
-#define IVTV_DBGFLG_API   (1 << 2)
-#define IVTV_DBGFLG_DMA   (1 << 3)
-#define IVTV_DBGFLG_IOCTL (1 << 4)
-#define IVTV_DBGFLG_I2C   (1 << 5)
-#define IVTV_DBGFLG_IRQ   (1 << 6)
-#define IVTV_DBGFLG_DEC   (1 << 7)
-#define IVTV_DBGFLG_YUV   (1 << 8)
+#define IVTV_DBGFLG_WARN    (1 << 0)
+#define IVTV_DBGFLG_INFO    (1 << 1)
+#define IVTV_DBGFLG_MB      (1 << 2)
+#define IVTV_DBGFLG_IOCTL   (1 << 3)
+#define IVTV_DBGFLG_FILE    (1 << 4)
+#define IVTV_DBGFLG_DMA     (1 << 5)
+#define IVTV_DBGFLG_IRQ     (1 << 6)
+#define IVTV_DBGFLG_DEC     (1 << 7)
+#define IVTV_DBGFLG_YUV     (1 << 8)
+#define IVTV_DBGFLG_I2C     (1 << 9)
 /* Flag to turn on high volume debugging */
-#define IVTV_DBGFLG_HIGHVOL (1 << 9)
+#define IVTV_DBGFLG_HIGHVOL (1 << 10)
 
 /* NOTE: extra space before comma in 'itv->num , ## args' is required for
    gcc-2.95, otherwise it won't compile. */
@@ -281,30 +282,32 @@ extern const u32 yuv_offset[4];
 		if ((x) & ivtv_debug) \
 			printk(KERN_INFO "ivtv%d " type ": " fmt, itv->num , ## args); \
 	} while (0)
-#define IVTV_DEBUG_WARN(fmt, args...)  IVTV_DEBUG(IVTV_DBGFLG_WARN, "warning", fmt , ## args)
-#define IVTV_DEBUG_INFO(fmt, args...)  IVTV_DEBUG(IVTV_DBGFLG_INFO, "info",fmt , ## args)
-#define IVTV_DEBUG_API(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_API, "api", fmt , ## args)
-#define IVTV_DEBUG_DMA(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_DMA, "dma", fmt , ## args)
+#define IVTV_DEBUG_WARN(fmt, args...)  IVTV_DEBUG(IVTV_DBGFLG_WARN,  "warn",  fmt , ## args)
+#define IVTV_DEBUG_INFO(fmt, args...)  IVTV_DEBUG(IVTV_DBGFLG_INFO,  "info",  fmt , ## args)
+#define IVTV_DEBUG_MB(fmt, args...)    IVTV_DEBUG(IVTV_DBGFLG_MB,    "mb",    fmt , ## args)
+#define IVTV_DEBUG_DMA(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_DMA,   "dma",   fmt , ## args)
 #define IVTV_DEBUG_IOCTL(fmt, args...) IVTV_DEBUG(IVTV_DBGFLG_IOCTL, "ioctl", fmt , ## args)
-#define IVTV_DEBUG_I2C(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_I2C, "i2c", fmt , ## args)
-#define IVTV_DEBUG_IRQ(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_IRQ, "irq", fmt , ## args)
-#define IVTV_DEBUG_DEC(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_DEC, "dec", fmt , ## args)
-#define IVTV_DEBUG_YUV(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_YUV, "yuv", fmt , ## args)
+#define IVTV_DEBUG_FILE(fmt, args...)  IVTV_DEBUG(IVTV_DBGFLG_FILE,  "file",  fmt , ## args)
+#define IVTV_DEBUG_I2C(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_I2C,   "i2c",   fmt , ## args)
+#define IVTV_DEBUG_IRQ(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_IRQ,   "irq",   fmt , ## args)
+#define IVTV_DEBUG_DEC(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_DEC,   "dec",   fmt , ## args)
+#define IVTV_DEBUG_YUV(fmt, args...)   IVTV_DEBUG(IVTV_DBGFLG_YUV,   "yuv",   fmt , ## args)
 
 #define IVTV_DEBUG_HIGH_VOL(x, type, fmt, args...) \
 	do { \
 		if (((x) & ivtv_debug) && (ivtv_debug & IVTV_DBGFLG_HIGHVOL)) \
 			printk(KERN_INFO "ivtv%d " type ": " fmt, itv->num , ## args); \
 	} while (0)
-#define IVTV_DEBUG_HI_WARN(fmt, args...)  IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_WARN, "warning", fmt , ## args)
-#define IVTV_DEBUG_HI_INFO(fmt, args...)  IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_INFO, "info",fmt , ## args)
-#define IVTV_DEBUG_HI_API(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_API, "api", fmt , ## args)
-#define IVTV_DEBUG_HI_DMA(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_DMA, "dma", fmt , ## args)
+#define IVTV_DEBUG_HI_WARN(fmt, args...)  IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_WARN,  "warn",  fmt , ## args)
+#define IVTV_DEBUG_HI_INFO(fmt, args...)  IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_INFO,  "info",  fmt , ## args)
+#define IVTV_DEBUG_HI_MB(fmt, args...)    IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_MB,    "mb",    fmt , ## args)
+#define IVTV_DEBUG_HI_DMA(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_DMA,   "dma",   fmt , ## args)
 #define IVTV_DEBUG_HI_IOCTL(fmt, args...) IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_IOCTL, "ioctl", fmt , ## args)
-#define IVTV_DEBUG_HI_I2C(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_I2C, "i2c", fmt , ## args)
-#define IVTV_DEBUG_HI_IRQ(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_IRQ, "irq", fmt , ## args)
-#define IVTV_DEBUG_HI_DEC(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_DEC, "dec", fmt , ## args)
-#define IVTV_DEBUG_HI_YUV(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_YUV, "yuv", fmt , ## args)
+#define IVTV_DEBUG_HI_FILE(fmt, args...)  IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_FILE,  "file",  fmt , ## args)
+#define IVTV_DEBUG_HI_I2C(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_I2C,   "i2c",   fmt , ## args)
+#define IVTV_DEBUG_HI_IRQ(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_IRQ,   "irq",   fmt , ## args)
+#define IVTV_DEBUG_HI_DEC(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_DEC,   "dec",   fmt , ## args)
+#define IVTV_DEBUG_HI_YUV(fmt, args...)   IVTV_DEBUG_HIGH_VOL(IVTV_DBGFLG_YUV,   "yuv",   fmt , ## args)
 
 /* Standard kernel messages */
 #define IVTV_ERR(fmt, args...)      printk(KERN_ERR  "ivtv%d: " fmt, itv->num , ## args)
diff --git a/linux/drivers/media/video/ivtv/ivtv-fileops.c b/linux/drivers/media/video/ivtv/ivtv-fileops.c
index b2ff2488d..5add53ef6 100644
--- a/linux/drivers/media/video/ivtv/ivtv-fileops.c
+++ b/linux/drivers/media/video/ivtv/ivtv-fileops.c
@@ -407,7 +407,7 @@ static ssize_t ivtv_read_pos(struct ivtv_stream *s, char __user *ubuf, size_t co
 	ssize_t rc = count ? ivtv_read(s, ubuf, count, non_block) : 0;
 	struct ivtv *itv = s->itv;
 
-	IVTV_DEBUG_HI_INFO("read %zd from %s, got %zd\n", count, s->name, rc);
+	IVTV_DEBUG_HI_FILE("read %zd from %s, got %zd\n", count, s->name, rc);
 	if (rc > 0)
 		pos += rc;
 	return rc;
@@ -498,7 +498,7 @@ ssize_t ivtv_v4l2_read(struct file * filp, char __user *buf, size_t count, loff_
 	struct ivtv_stream *s = &itv->streams[id->type];
 	int rc;
 
-	IVTV_DEBUG_HI_IOCTL("read %zd bytes from %s\n", count, s->name);
+	IVTV_DEBUG_HI_FILE("read %zd bytes from %s\n", count, s->name);
 
 	rc = ivtv_start_capture(id);
 	if (rc)
@@ -536,7 +536,7 @@ ssize_t ivtv_v4l2_write(struct file *filp, const char __user *user_buf, size_t c
 	int rc;
 	DEFINE_WAIT(wait);
 
-	IVTV_DEBUG_HI_IOCTL("write %zd bytes to %s\n", count, s->name);
+	IVTV_DEBUG_HI_FILE("write %zd bytes to %s\n", count, s->name);
 
 	if (s->type != IVTV_DEC_STREAM_TYPE_MPG &&
 	    s->type != IVTV_DEC_STREAM_TYPE_YUV &&
@@ -644,7 +644,7 @@ retry:
 	   to transfer the rest. */
 	if (count && !(filp->f_flags & O_NONBLOCK))
 		goto retry;
-	IVTV_DEBUG_HI_INFO("Wrote %d bytes to %s (%d)\n", bytes_written, s->name, s->q_full.bytesused);
+	IVTV_DEBUG_HI_FILE("Wrote %d bytes to %s (%d)\n", bytes_written, s->name, s->q_full.bytesused);
 	return bytes_written;
 }
 
@@ -656,6 +656,7 @@ unsigned int ivtv_v4l2_dec_poll(struct file *filp, poll_table *wait)
 	int res = 0;
 
 	/* add stream's waitq to the poll list */
+	IVTV_DEBUG_HI_FILE("Decoder poll\n");
 	poll_wait(filp, &s->waitq, wait);
 
 	set_bit(IVTV_F_I_EV_VSYNC_ENABLED, &itv->i_flags);
@@ -685,9 +686,11 @@ unsigned int ivtv_v4l2_enc_poll(struct file *filp, poll_table * wait)
 					s->name, rc);
 			return POLLERR;
 		}
+		IVTV_DEBUG_FILE("Encoder poll started capture\n");
 	}
 
 	/* add stream's waitq to the poll list */
+	IVTV_DEBUG_HI_FILE("Encoder poll\n");
 	poll_wait(filp, &s->waitq, wait);
 
 	if (eof || s->q_full.length)
@@ -700,7 +703,7 @@ void ivtv_stop_capture(struct ivtv_open_id *id, int gop_end)
 	struct ivtv *itv = id->itv;
 	struct ivtv_stream *s = &itv->streams[id->type];
 
-	IVTV_DEBUG_IOCTL("close() of %s\n", s->name);
+	IVTV_DEBUG_FILE("close() of %s\n", s->name);
 
 	/* 'Unclaim' this stream */
 
@@ -738,7 +741,7 @@ static void ivtv_stop_decoding(struct ivtv_open_id *id, int flags, u64 pts)
 	struct ivtv *itv = id->itv;
 	struct ivtv_stream *s = &itv->streams[id->type];
 
-	IVTV_DEBUG_IOCTL("close() of %s\n", s->name);
+	IVTV_DEBUG_FILE("close() of %s\n", s->name);
 
 	/* Stop decoding */
 	if (test_bit(IVTV_F_S_STREAMING, &s->s_flags)) {
@@ -770,7 +773,7 @@ int ivtv_v4l2_close(struct inode *inode, struct file *filp)
 	struct ivtv *itv = id->itv;
 	struct ivtv_stream *s = &itv->streams[id->type];
 
-	IVTV_DEBUG_IOCTL("close() of %s\n", s->name);
+	IVTV_DEBUG_FILE("close %s\n", s->name);
 
 	v4l2_prio_close(&itv->prio, &id->prio);
 
@@ -853,6 +856,7 @@ int ivtv_v4l2_open(struct inode *inode, struct file *filp)
 		IVTV_ERR("Failed to initialize on minor %d\n", minor);
 		return -ENXIO;
 	}
+	IVTV_DEBUG_FILE("open %s\n", s->name);
 
 	if (y == IVTV_DEC_STREAM_TYPE_MPG &&
 		test_bit(IVTV_F_S_CLAIMED, &itv->streams[IVTV_DEC_STREAM_TYPE_YUV].s_flags))
diff --git a/linux/drivers/media/video/ivtv/ivtv-ioctl.c b/linux/drivers/media/video/ivtv/ivtv-ioctl.c
index 9a0c3df8d..3cf6bbb04 100644
--- a/linux/drivers/media/video/ivtv/ivtv-ioctl.c
+++ b/linux/drivers/media/video/ivtv/ivtv-ioctl.c
@@ -1143,12 +1143,14 @@ int ivtv_v4l2_ioctls(struct ivtv *itv, struct file *filp, unsigned int cmd, void
 		memset(&enc->raw, 0, sizeof(enc->raw));
 		switch (enc->cmd) {
 		case V4L2_ENC_CMD_START:
+			IVTV_DEBUG_IOCTL("V4L2_ENC_CMD_START\n");
 			enc->flags = 0;
 			if (try)
 				return 0;
 			return ivtv_start_capture(id);
 
 		case V4L2_ENC_CMD_STOP:
+			IVTV_DEBUG_IOCTL("V4L2_ENC_CMD_STOP\n");
 			enc->flags &= V4L2_ENC_CMD_STOP_AT_GOP_END;
 			if (try)
 				return 0;
@@ -1156,6 +1158,7 @@ int ivtv_v4l2_ioctls(struct ivtv *itv, struct file *filp, unsigned int cmd, void
 			return 0;
 
 		case V4L2_ENC_CMD_PAUSE:
+			IVTV_DEBUG_IOCTL("V4L2_ENC_CMD_PAUSE\n");
 			enc->flags = 0;
 			if (try)
 				return 0;
@@ -1168,6 +1171,7 @@ int ivtv_v4l2_ioctls(struct ivtv *itv, struct file *filp, unsigned int cmd, void
 			break;
 
 		case V4L2_ENC_CMD_RESUME:
+			IVTV_DEBUG_IOCTL("V4L2_ENC_CMD_RESUME\n");
 			enc->flags = 0;
 			if (try)
 				return 0;
@@ -1179,6 +1183,7 @@ int ivtv_v4l2_ioctls(struct ivtv *itv, struct file *filp, unsigned int cmd, void
 			ivtv_unmute(itv);
 			break;
 		default:
+			IVTV_DEBUG_IOCTL("Unknown cmd %d\n", enc->cmd);
 			return -EINVAL;
 		}
 		break;
@@ -1413,9 +1418,9 @@ static int ivtv_decoder_ioctls(struct file *filp, unsigned int cmd, void *arg)
 		int try = (cmd == VIDEO_TRY_COMMAND);
 
 		if (try)
-			IVTV_DEBUG_IOCTL("VIDEO_TRY_COMMAND\n");
+			IVTV_DEBUG_IOCTL("VIDEO_TRY_COMMAND %d\n", vc->cmd);
 		else
-			IVTV_DEBUG_IOCTL("VIDEO_COMMAND\n");
+			IVTV_DEBUG_IOCTL("VIDEO_COMMAND %d\n", vc->cmd);
 		return ivtv_video_command(itv, id, vc, try);
 	}
 
diff --git a/linux/drivers/media/video/ivtv/ivtv-mailbox.c b/linux/drivers/media/video/ivtv/ivtv-mailbox.c
index 5e3b67920..b05436da7 100644
--- a/linux/drivers/media/video/ivtv/ivtv-mailbox.c
+++ b/linux/drivers/media/video/ivtv/ivtv-mailbox.c
@@ -225,15 +225,15 @@ static int ivtv_api_call(struct ivtv *itv, int cmd, int args, u32 data[])
 	}
 	if (args < 0 || args > CX2341X_MBOX_MAX_DATA ||
 	    cmd < 0 || cmd > 255 || api_info[cmd].name == NULL) {
-		IVTV_ERR("Invalid API call: cmd = 0x%02x, args = %d\n", cmd, args);
+		IVTV_ERR("Invalid MB call: cmd = 0x%02x, args = %d\n", cmd, args);
 		return -EINVAL;
 	}
 
 	if (api_info[cmd].flags & API_HIGH_VOL) {
-	    IVTV_DEBUG_HI_API("API Call: %s\n", api_info[cmd].name);
+	    IVTV_DEBUG_HI_MB("MB Call: %s\n", api_info[cmd].name);
 	}
 	else {
-	    IVTV_DEBUG_API("API Call: %s\n", api_info[cmd].name);
+	    IVTV_DEBUG_MB("MB Call: %s\n", api_info[cmd].name);
 	}
 
 	/* clear possibly uninitialized part of data array */