[PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Yuanhan Liu]

Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
spin log, it's not enough. Say we have two processes A and B, and let
syslog_seq = N, while log_next_seq = N + 1, and the two processes both
come to syslog_print at almost the same time. And No matter which
process get the spin lock first, it will increase syslog_seq by one,
then release spin lock; thus later, another process increase syslog_seq
by one again. In this case, syslog_seq is bigger than syslog_next_seq.
And latter, it would make:
   wait_event_interruptiable(log_wait, syslog != log_next_seq)
don't wait any more even there is no new write comes. Thus it introduce
a infinite loop reading.

I can easily see this kind of issue by the following steps:
  # cat /proc/kmsg # at meantime, I don't kill rsyslog
                   # So they are the two processes.
  # xinit          # I added drm.debug=6 in the kernel parameter line,
                   # so that it will produce lots of message and let that
                   # issue happen

It's 100% reproducable on my side. And my disk will be filled up by
/var/log/messages in a quite short time.

So, introduce a mutex_lock to stop syslog_seq from going wild just like
what devkmsg_read() does. It does fix this issue as expected.

Cc: Kay Sievers <kay@vrfy.org>
Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Signed-off-by: Yuanhan Liu <yuanhan.liu@linux.intel.com>
---
 kernel/printk.c |    7 ++++++-
 1 files changed, 6 insertions(+), 1 deletions(-)

diff --git a/kernel/printk.c b/kernel/printk.c
index 32462d2..d2ddb83 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -206,6 +206,7 @@ struct log {
  * used in interesting ways to provide interlocking in console_unlock();
  */
 static DEFINE_RAW_SPINLOCK(logbuf_lock);
+static DEFINE_MUTEX(logbuf_mutex_lock);
 
 /* the next printk record to read by syslog(READ) or /proc/kmsg */
 static u64 syslog_seq;
@@ -1000,11 +1001,15 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
 			error = -EFAULT;
 			goto out;
 		}
+		mutex_lock(&logbuf_mutex_lock);
 		error = wait_event_interruptible(log_wait,
 						 syslog_seq != log_next_seq);
-		if (error)
+		if (error) {
+			mutex_unlock(&logbuf_mutex_lock);
 			goto out;
+		}
 		error = syslog_print(buf, len);
+		mutex_unlock(&logbuf_mutex_lock);
 		break;
 	/* Read/clear last kernel messages */
 	case SYSLOG_ACTION_READ_CLEAR:
-- 
1.7.3.1

[PATCH 2/2] printk: return -EINVAL if the message len is bigger than the buf size

[Yuanhan Liu]

Just like what devkmsg_read() does, return -EINVAL if the message len is
bigger than the buf size, or it will trigger a segfault error.

Cc: Kay Sievers <kay@vrfy.org>
Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Signed-off-by: Yuanhan Liu <yuanhan.liu@linux.intel.com>
---
 kernel/printk.c |    4 +++-
 1 files changed, 3 insertions(+), 1 deletions(-)

diff --git a/kernel/printk.c b/kernel/printk.c
index d2ddb83..734e2a4 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -879,7 +879,9 @@ static int syslog_print(char __user *buf, int size)
 	syslog_seq++;
 	raw_spin_unlock_irq(&logbuf_lock);
 
-	if (len > 0 && copy_to_user(buf, text, len))
+	if (len > size)
+		len = -EINVAL;
+	else if (len > 0 && copy_to_user(buf, text, len))
 		len = -EFAULT;
 
 	kfree(text);
-- 
1.7.3.1

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Kay Sievers]

On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> spin log, it's not enough. Say we have two processes A and B, and let
> syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> come to syslog_print at almost the same time. And No matter which
> process get the spin lock first, it will increase syslog_seq by one,
> then release spin lock; thus later, another process increase syslog_seq
> by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> And latter, it would make:
>    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> don't wait any more even there is no new write comes. Thus it introduce
> a infinite loop reading.

Oh, multiple readers on the same shared file descriptor are not useful,
but sure, that needs fixing. Thanks for tracking that down!

Looks like the same issue existed in the original code already, it's
just that it was granular at a single character level, and not a line,
and the seqnum which icreases one-by-one, so the issue was hard to
trigger.

We better make the mutexes interruptible, right? Something like this?

Thanks,
Kay


diff --git a/kernel/printk.c b/kernel/printk.c
index 32462d2..5a01420 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -414,7 +414,10 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 	if (!user)
 		return -EBADF;
 
-	mutex_lock(&user->lock);
+	ret = mutex_lock_interruptible(&user->lock);
+	if (ret)
+		return ret;
+
 	raw_spin_lock(&logbuf_lock);
 	while (user->seq == log_next_seq) {
 		if (file->f_flags & O_NONBLOCK) {
@@ -974,6 +977,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
 {
 	bool clear = false;
 	static int saved_console_loglevel = -1;
+	static DEFINE_MUTEX(syslog_mutex);
 	int error;
 
 	error = check_syslog_permissions(type, from_file);
@@ -1000,11 +1004,17 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
 			error = -EFAULT;
 			goto out;
 		}
+		error = mutex_lock_interruptible(&syslog_mutex);
+		if (error)
+			goto out;
 		error = wait_event_interruptible(log_wait,
 						 syslog_seq != log_next_seq);
-		if (error)
+		if (error) {
+			mutex_unlock(&syslog_mutex);
 			goto out;
+		}
 		error = syslog_print(buf, len);
+		mutex_unlock(&syslog_mutex);
 		break;
 	/* Read/clear last kernel messages */
 	case SYSLOG_ACTION_READ_CLEAR:

Re: [PATCH 2/2] printk: return -EINVAL if the message len is bigger than the buf size

[Kay Sievers]

On Sat, Jun 16, 2012 at 6:40 AM, Yuanhan Liu
<yuanhan.liu@linux.intel.com> wrote:
> Just like what devkmsg_read() does, return -EINVAL if the message len is
> bigger than the buf size, or it will trigger a segfault error.

Looks good to me.

Thanks,
Kay

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Yuanhan Liu]

On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
> On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> > spin log, it's not enough. Say we have two processes A and B, and let
> > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> > come to syslog_print at almost the same time. And No matter which
> > process get the spin lock first, it will increase syslog_seq by one,
> > then release spin lock; thus later, another process increase syslog_seq
> > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> > And latter, it would make:
> >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> > don't wait any more even there is no new write comes. Thus it introduce
> > a infinite loop reading.
> 
> Oh, multiple readers on the same shared file descriptor are not useful,
> but sure, that needs fixing. Thanks for tracking that down!
> 
> Looks like the same issue existed in the original code already, it's
> just that it was granular at a single character level, and not a line,
> and the seqnum which icreases one-by-one, so the issue was hard to
> trigger.

Yes,  I think so, too.

> 
> We better make the mutexes interruptible, right?

Yes, you are right.

> Something like this?

BTW, since you already made a patch, should I write a version 2 based
on your comments?

Thanks,
Yuanhan Liu
> 
> Thanks,
> Kay
> 
> 
> diff --git a/kernel/printk.c b/kernel/printk.c
> index 32462d2..5a01420 100644
> --- a/kernel/printk.c
> +++ b/kernel/printk.c
> @@ -414,7 +414,10 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>  	if (!user)
>  		return -EBADF;
>  
> -	mutex_lock(&user->lock);
> +	ret = mutex_lock_interruptible(&user->lock);
> +	if (ret)
> +		return ret;
> +
>  	raw_spin_lock(&logbuf_lock);
>  	while (user->seq == log_next_seq) {
>  		if (file->f_flags & O_NONBLOCK) {
> @@ -974,6 +977,7 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
>  {
>  	bool clear = false;
>  	static int saved_console_loglevel = -1;
> +	static DEFINE_MUTEX(syslog_mutex);
>  	int error;
>  
>  	error = check_syslog_permissions(type, from_file);
> @@ -1000,11 +1004,17 @@ int do_syslog(int type, char __user *buf, int len, bool from_file)
>  			error = -EFAULT;
>  			goto out;
>  		}
> +		error = mutex_lock_interruptible(&syslog_mutex);
> +		if (error)
> +			goto out;
>  		error = wait_event_interruptible(log_wait,
>  						 syslog_seq != log_next_seq);
> -		if (error)
> +		if (error) {
> +			mutex_unlock(&syslog_mutex);
>  			goto out;
> +		}
>  		error = syslog_print(buf, len);
> +		mutex_unlock(&syslog_mutex);
>  		break;
>  	/* Read/clear last kernel messages */
>  	case SYSLOG_ACTION_READ_CLEAR:

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Kay Sievers]

On Sat, Jun 16, 2012 at 2:59 PM, Yuanhan Liu
<yuanhan.liu@linux.intel.com> wrote:
> On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
>> On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
>> > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
>> > spin log, it's not enough. Say we have two processes A and B, and let
>> > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
>> > come to syslog_print at almost the same time. And No matter which
>> > process get the spin lock first, it will increase syslog_seq by one,
>> > then release spin lock; thus later, another process increase syslog_seq
>> > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
>> > And latter, it would make:
>> >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
>> > don't wait any more even there is no new write comes. Thus it introduce
>> > a infinite loop reading.
>>
>> Oh, multiple readers on the same shared file descriptor are not useful,
>> but sure, that needs fixing. Thanks for tracking that down!
>>
>> Looks like the same issue existed in the original code already, it's
>> just that it was granular at a single character level, and not a line,
>> and the seqnum which icreases one-by-one, so the issue was hard to
>> trigger.
>
> Yes,  I think so, too.
>
>>
>> We better make the mutexes interruptible, right?
>
> Yes, you are right.
>
>> Something like this?
>
> BTW, since you already made a patch, should I write a version 2 based
> on your comments?

Sure, please do.

Thanks a lot for doing this,
Kay

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Fengguang Wu]

On Sat, Jun 16, 2012 at 08:59:22PM +0800, Yuanhan Liu wrote:
> On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
> > On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> > > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> > > spin log, it's not enough. Say we have two processes A and B, and let
> > > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> > > come to syslog_print at almost the same time. And No matter which
> > > process get the spin lock first, it will increase syslog_seq by one,
> > > then release spin lock; thus later, another process increase syslog_seq
> > > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> > > And latter, it would make:
> > >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> > > don't wait any more even there is no new write comes. Thus it introduce
> > > a infinite loop reading.
> > 
> > Oh, multiple readers on the same shared file descriptor are not useful,
> > but sure, that needs fixing. Thanks for tracking that down!
> > 
> > Looks like the same issue existed in the original code already, it's
> > just that it was granular at a single character level, and not a line,
> > and the seqnum which icreases one-by-one, so the issue was hard to
> > trigger.
> 
> Yes,  I think so, too.
> 
> > 
> > We better make the mutexes interruptible, right?
> 
> Yes, you are right.

It might be better to do them in two standalone patches?
One is a bug fix, the other improves user responsiveness.

Either way, you may add my superficial

Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>

Thanks,
Fengguang

Re: [PATCH 2/2] printk: return -EINVAL if the message len is bigger than the buf size

[Fengguang Wu]

On Sat, Jun 16, 2012 at 02:50:53PM +0200, Kay Sievers wrote:
> On Sat, Jun 16, 2012 at 6:40 AM, Yuanhan Liu
> <yuanhan.liu@linux.intel.com> wrote:
> > Just like what devkmsg_read() does, return -EINVAL if the message len is
> > bigger than the buf size, or it will trigger a segfault error.
> 
> Looks good to me.

Me too :)

Thanks,
Fengguang

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Yuanhan Liu]

On Sat, Jun 16, 2012 at 03:03:37PM +0200, Kay Sievers wrote:
> On Sat, Jun 16, 2012 at 2:59 PM, Yuanhan Liu
> <yuanhan.liu@linux.intel.com> wrote:
> > On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
> >> On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> >> > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> >> > spin log, it's not enough. Say we have two processes A and B, and let
> >> > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> >> > come to syslog_print at almost the same time. And No matter which
> >> > process get the spin lock first, it will increase syslog_seq by one,
> >> > then release spin lock; thus later, another process increase syslog_seq
> >> > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> >> > And latter, it would make:
> >> >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> >> > don't wait any more even there is no new write comes. Thus it introduce
> >> > a infinite loop reading.
> >>
> >> Oh, multiple readers on the same shared file descriptor are not useful,
> >> but sure, that needs fixing. Thanks for tracking that down!
> >>
> >> Looks like the same issue existed in the original code already, it's
> >> just that it was granular at a single character level, and not a line,
> >> and the seqnum which icreases one-by-one, so the issue was hard to
> >> trigger.
> >
> > Yes,  I think so, too.
> >
> >>
> >> We better make the mutexes interruptible, right?
> >
> > Yes, you are right.
> >
> >> Something like this?
> >
> > BTW, since you already made a patch, should I write a version 2 based
> > on your comments?
> 
> Sure, please do.
> 
> Thanks a lot for doing this,

My pleasure. An updated patch just sent out. Thanks for your comments
very much.

--
yliu

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Yuanhan Liu]

On Sat, Jun 16, 2012 at 09:20:52PM +0800, Fengguang Wu wrote:
> On Sat, Jun 16, 2012 at 08:59:22PM +0800, Yuanhan Liu wrote:
> > On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
> > > On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> > > > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> > > > spin log, it's not enough. Say we have two processes A and B, and let
> > > > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> > > > come to syslog_print at almost the same time. And No matter which
> > > > process get the spin lock first, it will increase syslog_seq by one,
> > > > then release spin lock; thus later, another process increase syslog_seq
> > > > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> > > > And latter, it would make:
> > > >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> > > > don't wait any more even there is no new write comes. Thus it introduce
> > > > a infinite loop reading.
> > > 
> > > Oh, multiple readers on the same shared file descriptor are not useful,
> > > but sure, that needs fixing. Thanks for tracking that down!
> > > 
> > > Looks like the same issue existed in the original code already, it's
> > > just that it was granular at a single character level, and not a line,
> > > and the seqnum which icreases one-by-one, so the issue was hard to
> > > trigger.
> > 
> > Yes,  I think so, too.
> > 
> > > 
> > > We better make the mutexes interruptible, right?
> > 
> > Yes, you are right.
> 
> It might be better to do them in two standalone patches?
> One is a bug fix, the other improves user responsiveness.
> 
> Either way, you may add my superficial
> 
> Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>

Too late; I just sent it out ;(

Anyway, thanks for your Reviewed-by very much. I hope commiter can add
this for me.

Thanks.

--
yliu

Re: [PATCH 1/2] printk: use logbuf_mutex_lock to stop syslog_seq from going wild

[Greg Kroah-Hartman]

On Sat, Jun 16, 2012 at 09:28:32PM +0800, Yuanhan Liu wrote:
> On Sat, Jun 16, 2012 at 09:20:52PM +0800, Fengguang Wu wrote:
> > On Sat, Jun 16, 2012 at 08:59:22PM +0800, Yuanhan Liu wrote:
> > > On Sat, Jun 16, 2012 at 02:42:38PM +0200, Kay Sievers wrote:
> > > > On Sat, 2012-06-16 at 12:40 +0800, Yuanhan Liu wrote:
> > > > > Although syslog_seq and log_next_seq stuff are protected by logbuf_lock
> > > > > spin log, it's not enough. Say we have two processes A and B, and let
> > > > > syslog_seq = N, while log_next_seq = N + 1, and the two processes both
> > > > > come to syslog_print at almost the same time. And No matter which
> > > > > process get the spin lock first, it will increase syslog_seq by one,
> > > > > then release spin lock; thus later, another process increase syslog_seq
> > > > > by one again. In this case, syslog_seq is bigger than syslog_next_seq.
> > > > > And latter, it would make:
> > > > >    wait_event_interruptiable(log_wait, syslog != log_next_seq)
> > > > > don't wait any more even there is no new write comes. Thus it introduce
> > > > > a infinite loop reading.
> > > > 
> > > > Oh, multiple readers on the same shared file descriptor are not useful,
> > > > but sure, that needs fixing. Thanks for tracking that down!
> > > > 
> > > > Looks like the same issue existed in the original code already, it's
> > > > just that it was granular at a single character level, and not a line,
> > > > and the seqnum which icreases one-by-one, so the issue was hard to
> > > > trigger.
> > > 
> > > Yes,  I think so, too.
> > > 
> > > > 
> > > > We better make the mutexes interruptible, right?
> > > 
> > > Yes, you are right.
> > 
> > It might be better to do them in two standalone patches?
> > One is a bug fix, the other improves user responsiveness.
> > 
> > Either way, you may add my superficial
> > 
> > Reviewed-by: Fengguang Wu <fengguang.wu@intel.com>
> 
> Too late; I just sent it out ;(
> 
> Anyway, thanks for your Reviewed-by very much. I hope commiter can add
> this for me.

I will do so, thanks.

greg k-h