[PATCH 0/10] introduction: check pr_debug() arguments

[PATCH 0/10] introduction: check pr_debug() arguments

[Zach Brown]

introduction: check pr_debug() arguments

I was recently frustrated when I broke the arguments to a pr_debug() call and
the bug went unnoticed until I defined DEBUG.  I poked around a bit and found
that I wasn't alone in breaking pr_debug() arguments.

Instead of having pr_debug() hide broken arguments when DEBUG isn't defined,
let's make it an empty inline and have gcc check it's format specifier.

What follows are the patches that fix up the existing bad pr_debug() calls.
The worst flat out get syntax wrong or reference non-existant symbols.

With those out of the way, the final patch makes the change to pr_debug().  The
net result doesn't affect a allyesconfig x86-64 build.  My apologies to other
builds that will be exposed to broken pr_debug() arguments.  What a great
opportunity to fix them!

- z

[PATCH 1/10] futex: remove extra pr_debug format specifications

[Zach Brown]

futex: remove extra pr_debug format specifications

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 kernel/futex.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/kernel/futex.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/kernel/futex.c
+++ 2.6.18-rc6-debug-args/kernel/futex.c
@@ -1359,7 +1359,7 @@ static long futex_lock_pi_restart(struct
 			(u64) restart->arg0;
 	}
 
-	pr_debug("lock_pi restart: %p, %d (%d)\n",
+	pr_debug("lock_pi restart: %p, %d\n",
 		 (u32 __user *)restart->arg0, current->pid);
 
 	ret = do_futex_lock_pi((u32 __user *)restart->arg0, restart->arg1,
@@ -1396,7 +1396,7 @@ static int futex_lock_pi(u32 __user *uad
 	if (ret != -EINTR)
 		return ret;
 
-	pr_debug("lock_pi interrupted: %p, %d (%d)\n", uaddr, current->pid);
+	pr_debug("lock_pi interrupted: %p, %d\n", uaddr, current->pid);
 
 	restart = &current_thread_info()->restart_block;
 	restart->fn = futex_lock_pi_restart;

[PATCH 2/10] aio: use size_t length modifier in pr_debug format arguments

[Zach Brown]

aio: use size_t length modifier in pr_debug format arguments

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 fs/aio.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/fs/aio.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/fs/aio.c
+++ 2.6.18-rc6-debug-args/fs/aio.c
@@ -671,7 +671,7 @@ static ssize_t aio_run_iocb(struct kiocb
 	}
 
 	if (!(iocb->ki_retried & 0xff)) {
-		pr_debug("%ld retry: %d of %d\n", iocb->ki_retried,
+		pr_debug("%ld retry: %zd of %zd\n", iocb->ki_retried,
 			iocb->ki_nbytes - iocb->ki_left, iocb->ki_nbytes);
 	}
 
@@ -1004,7 +1004,7 @@ int fastcall aio_complete(struct kiocb *
 
 	pr_debug("added to ring %p at [%lu]\n", iocb, tail);
 
-	pr_debug("%ld retries: %d of %d\n", iocb->ki_retried,
+	pr_debug("%ld retries: %zd of %zd\n", iocb->ki_retried,
 		iocb->ki_nbytes - iocb->ki_left, iocb->ki_nbytes);
 put_rq:
 	/* everything turned out well, dispose of the aiocb. */

[PATCH 3/10] configfs: use size_t length modifier in pr_debug format argument

[Zach Brown]

configfs: use size_t length modifier in pr_debug format argument

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 fs/configfs/file.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/fs/configfs/file.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/fs/configfs/file.c
+++ 2.6.18-rc6-debug-args/fs/configfs/file.c
@@ -137,8 +137,8 @@ configfs_read_file(struct file *file, ch
 		if ((retval = fill_read_buffer(file->f_dentry,buffer)))
 			goto out;
 	}
-	pr_debug("%s: count = %d, ppos = %lld, buf = %s\n",
-		 __FUNCTION__,count,*ppos,buffer->page);
+	pr_debug("%s: count = %zd, ppos = %lld, buf = %s\n",
+		 __FUNCTION__, count, *ppos, buffer->page);
 	retval = flush_read_buffer(buffer,buf,count,ppos);
 out:
 	up(&buffer->sem);

[PATCH 4/10] sysfs: use size_t length modifier in pr_debug format arguments

[Zach Brown]

sysfs: use size_t length modifier in pr_debug format arguments

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 fs/sysfs/file.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/fs/sysfs/file.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/fs/sysfs/file.c
+++ 2.6.18-rc6-debug-args/fs/sysfs/file.c
@@ -157,8 +157,8 @@ sysfs_read_file(struct file *file, char 
 		if ((retval = fill_read_buffer(file->f_dentry,buffer)))
 			goto out;
 	}
-	pr_debug("%s: count = %d, ppos = %lld, buf = %s\n",
-		 __FUNCTION__,count,*ppos,buffer->page);
+	pr_debug("%s: count = %zd, ppos = %lld, buf = %s\n",
+		 __FUNCTION__, count, *ppos, buffer->page);
 	retval = flush_read_buffer(buffer,buf,count,ppos);
 out:
 	up(&buffer->sem);

[PATCH 5/10] umem: repair nonexistant bh pr_debug reference

[Zach Brown]

umem: repair nonexistant bh pr_debug reference

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 drivers/block/umem.c |    3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

Index: 2.6.18-rc6-debug-args/drivers/block/umem.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/drivers/block/umem.c
+++ 2.6.18-rc6-debug-args/drivers/block/umem.c
@@ -552,7 +552,8 @@ static void process_page(unsigned long d
 static int mm_make_request(request_queue_t *q, struct bio *bio)
 {
 	struct cardinfo *card = q->queuedata;
-	pr_debug("mm_make_request %ld %d\n", bh->b_rsector, bh->b_size);
+	pr_debug("mm_make_request %llu %u\n",
+		 (unsigned long long)bio->bi_sector, bio->bi_size);
 
 	bio->bi_phys_segments = bio->bi_idx; /* count of completed segments*/
 	spin_lock_irq(&card->lock);

[PATCH 6/10] tipar: repair nonexistant pr_debug argument use

[Zach Brown]

tipar: repair nonexistant pr_debug argument use 

I guessed what the pr_debug meant by 'data'.
Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 drivers/char/tipar.c |    6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/drivers/char/tipar.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/drivers/char/tipar.c
+++ 2.6.18-rc6-debug-args/drivers/char/tipar.c
@@ -224,14 +224,16 @@ probe_ti_parallel(int minor)
 {
 	int i;
 	int seq[] = { 0x00, 0x20, 0x10, 0x30 };
+	int data;
 
 	for (i = 3; i >= 0; i--) {
 		outbyte(3, minor);
 		outbyte(i, minor);
 		udelay(delay);
+		data = inbyte(minor) & 0x30;
 		pr_debug("tipar: Probing -> %i: 0x%02x 0x%02x\n", i,
-			data & 0x30, seq[i]);
-		if ((inbyte(minor) & 0x30) != seq[i]) {
+			data, seq[i]);
+		if (data != seq[i]) {
 			outbyte(3, minor);
 			return -1;
 		}

[PATCH 7/10] dell_rbu: fix pr_debug argument warnings

[Zach Brown]

dell_rbu: fix pr_debug argument warnings

Use size_t length modifier when outputting size_t and use %p instead of %lu for
'u8 *'.

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 drivers/firmware/dell_rbu.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/drivers/firmware/dell_rbu.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/drivers/firmware/dell_rbu.c
+++ 2.6.18-rc6-debug-args/drivers/firmware/dell_rbu.c
@@ -227,7 +227,7 @@ static int packetize_data(void *data, si
 	int packet_length;
 	u8 *temp;
 	u8 *end = (u8 *) data + length;
-	pr_debug("packetize_data: data length %d\n", length);
+	pr_debug("packetize_data: data length %zd\n", length);
 	if (!rbu_data.packetsize) {
 		printk(KERN_WARNING
 			"dell_rbu: packetsize not specified\n");
@@ -249,7 +249,7 @@ static int packetize_data(void *data, si
 		if ((rc = create_packet(temp, packet_length)))
 			return rc;
 
-		pr_debug("%lu:%lu\n", temp, (end - temp));
+		pr_debug("%p:%lu\n", temp, (end - temp));
 		temp += packet_length;
 	}
 

[PATCH 8/10] ifb: replace missing comma to separate pr_debug arguments

[Zach Brown]

ifb: replace missing comma to separate pr_debug arguments 

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 drivers/net/ifb.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/drivers/net/ifb.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/drivers/net/ifb.c
+++ 2.6.18-rc6-debug-args/drivers/net/ifb.c
@@ -200,8 +200,8 @@ static struct net_device_stats *ifb_get_
 
 	pr_debug("tasklets stats %ld:%ld:%ld:%ld:%ld:%ld:%ld:%ld:%ld \n",
 		dp->st_task_enter, dp->st_txq_refl_try, dp->st_rxq_enter, 
-		dp->st_rx2tx_tran dp->st_rxq_notenter, dp->st_rx_frm_egr,
-		dp->st_rx_frm_ing, dp->st_rxq_check, dp->st_rxq_rsch );
+		dp->st_rx2tx_tran, dp->st_rxq_notenter, dp->st_rx_frm_egr,
+		dp->st_rx_frm_ing, dp->st_rxq_check, dp->st_rxq_rsch);
 
 	return stats;
 }

[PATCH 9/10] trident: use size_t length modifier in pr_debug format arguments

[Zach Brown]

trident: use size_t length modifier in pr_debug format arguments

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 sound/oss/trident.c |    4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/sound/oss/trident.c
===================================================================
--- 2.6.18-rc6-debug-args.orig/sound/oss/trident.c
+++ 2.6.18-rc6-debug-args/sound/oss/trident.c
@@ -1873,7 +1873,7 @@ trident_read(struct file *file, char __u
 	unsigned swptr;
 	int cnt;
 
-	pr_debug("trident: trident_read called, count = %d\n", count);
+	pr_debug("trident: trident_read called, count = %zd\n", count);
 
 	VALIDATE_STATE(state);
 
@@ -1989,7 +1989,7 @@ trident_write(struct file *file, const c
 	unsigned int copy_count;
 	int lret; /* for lock_set_fmt */
 
-	pr_debug("trident: trident_write called, count = %d\n", count);
+	pr_debug("trident: trident_write called, count = %zd\n", count);
 
 	VALIDATE_STATE(state);
 

[PATCH 10/10] check pr_debug() arguments

[Zach Brown]

check pr_debug() arguments

When DEBUG isn't defined pr_debug() is defined away as an empty macro.  By
throwing away the arguments we allow completely incorrect code to build.

Instead let's make it an empty inline which checks arguments and mark it so gcc
can check the format specification.

This results in a seemingly insignificant code size increase.  A x86-64
allyesconfig:

   text    data     bss     dec     hex filename
25354768        7191098 4854720 37400586        23ab00a vmlinux.before
25354945        7191138 4854720 37400803        23ab0e3 vmlinux

Signed-off-by: Zach Brown <zach.brown@oracle.com>
---

 include/linux/kernel.h |    6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

Index: 2.6.18-rc6-debug-args/include/linux/kernel.h
===================================================================
--- 2.6.18-rc6-debug-args.orig/include/linux/kernel.h
+++ 2.6.18-rc6-debug-args/include/linux/kernel.h
@@ -214,8 +214,10 @@ extern void dump_stack(void);
 #define pr_debug(fmt,arg...) \
 	printk(KERN_DEBUG fmt,##arg)
 #else
-#define pr_debug(fmt,arg...) \
-	do { } while (0)
+static inline int __attribute__ ((format (printf, 1, 2))) pr_debug(const char * fmt, ...)
+{
+	return 0;
+}
 #endif
 
 #define pr_info(fmt,arg...) \

Re: [PATCH 10/10] check pr_debug() arguments

[Andrew Morton]

On Fri,  8 Sep 2006 15:55:29 -0700 (PDT)
Zach Brown <zach.brown@oracle.com> wrote:

> check pr_debug() arguments
> 
> When DEBUG isn't defined pr_debug() is defined away as an empty macro.  By
> throwing away the arguments we allow completely incorrect code to build.
> 
> Instead let's make it an empty inline which checks arguments and mark it so gcc
> can check the format specification.

Desirable.

> This results in a seemingly insignificant code size increase.  A x86-64
> allyesconfig:
> 
>    text    data     bss     dec     hex filename
> 25354768        7191098 4854720 37400586        23ab00a vmlinux.before
> 25354945        7191138 4854720 37400803        23ab0e3 vmlinux

Which would indicate that we might have expressions-with-side-effects
inside pr_debug() statements somewhere, which is risky.  I wonder where?

It looks like the version of gcc which you used is correctly discarding the
pr_debug() format string.  gcc hasn't always done that, and there's a risk
of bloatiness on older gccs.  I checked gcc-3.3.2/x86 and it does the right
thing, so...

btw, what's up with aio.c using a combination of pr_debug() and dprintk(),
and a combination of `#ifdef DEBUG' and `#if DEBUG > 1'?  Confusing.


It would be nice to have a single way of doing developer-debug in-tree.  We
have 182(!) different definitions of dprintk().  Please nobody cc me on that
discussion though ;)

Re: [PATCH 3/10] configfs: use size_t length modifier in pr_debug format argument

[Joel Becker]

On Fri, Sep 08, 2006 at 03:54:53PM -0700, Zach Brown wrote:
> configfs: use size_t length modifier in pr_debug format argument

Signed-off-by: Joel Becker <joel.becker@oracle.com>
> 
> Signed-off-by: Zach Brown <zach.brown@oracle.com>
> ---
> 
>  fs/configfs/file.c |    4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> Index: 2.6.18-rc6-debug-args/fs/configfs/file.c
> ===================================================================
> --- 2.6.18-rc6-debug-args.orig/fs/configfs/file.c
> +++ 2.6.18-rc6-debug-args/fs/configfs/file.c
> @@ -137,8 +137,8 @@ configfs_read_file(struct file *file, ch
>  		if ((retval = fill_read_buffer(file->f_dentry,buffer)))
>  			goto out;
>  	}
> -	pr_debug("%s: count = %d, ppos = %lld, buf = %s\n",
> -		 __FUNCTION__,count,*ppos,buffer->page);
> +	pr_debug("%s: count = %zd, ppos = %lld, buf = %s\n",
> +		 __FUNCTION__, count, *ppos, buffer->page);
>  	retval = flush_read_buffer(buffer,buf,count,ppos);
>  out:
>  	up(&buffer->sem);
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

-- 

 The herd instinct among economists makes sheep look like
 independant thinkers.

Joel Becker
Principal Software Developer
Oracle
E-mail: joel.becker@oracle.com
Phone: (650) 506-8127

Re: [PATCH 10/10] check pr_debug() arguments

[Zach Brown]

>> This results in a seemingly insignificant code size increase.  A x86-64
>> allyesconfig:
>>
>>    text    data     bss     dec     hex filename
>> 25354768        7191098 4854720 37400586        23ab00a vmlinux.before
>> 25354945        7191138 4854720 37400803        23ab0e3 vmlinux
> 
> Which would indicate that we might have expressions-with-side-effects
> inside pr_debug() statements somewhere, which is risky.  I wonder where?

I browsed through some of the functions that bloat-o-meter reported an
increase for.  Some seemed reasonable as they used things like current
or AFFS_I() in arguments.  Others seemed pretty mysterious as they
didn't have obvious pr_debug() calls.

$ uname -m ; gcc --version
x86_64
gcc (GCC) 4.1.1 20060525 (Red Hat 4.1.1-1)

> btw, what's up with aio.c using a combination of pr_debug() and dprintk(),
> and a combination of `#ifdef DEBUG' and `#if DEBUG > 1'?  Confusing.

I'm not sure how it got that way but I don't think anyone will object to
simplifying it.  I'll spend those 5 minutes :).

> It would be nice to have a single way of doing developer-debug in-tree.  We
> have 182(!) different definitions of dprintk().  Please nobody cc me on that
> discussion though ;)

Agreed, on both counts :).

- z