lp: hung task in lp_open

lp: hung task in lp_open

[Sasha Levin]

Hi all,

I've observed the following hung_test error while fuzzing with trinity inside a KVM guest:

[2966799.413925] INFO: task trinity:7230 blocked for more than 120 seconds.
[2966799.413925] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[2966799.413948] trinity         D ffff88035d9534c8  4576  7230   7227 0x00000000
[2966799.413948]  ffff8808295fbab8 0000000000000046 0000000000000000 ffff880829c6b000
[2966799.413948]  ffff8808295fa000 ffff8808295fa010 ffff8808295fbfd8 ffff8808295fa000
[2966799.414281]  ffff8808295fa010 ffff8808295fbfd8 ffff8808299eb000 ffff880829c6b000
[2966799.414281] Call Trace:
[2966799.414304]  [<ffffffff837cfc25>] ? __mutex_lock_common+0x345/0x590
[2966799.414353]  [<ffffffff837d1535>] schedule+0x55/0x60
[2966799.414366]  [<ffffffff837d18b3>] schedule_preempt_disabled+0x13/0x20
[2966799.414398]  [<ffffffff837cfc65>] __mutex_lock_common+0x385/0x590
[2966799.414474]  [<ffffffff81b99366>] ? lp_open+0x36/0x280
[2966799.414602]  [<ffffffff8106f5ed>] ? sched_clock+0x1d/0x30
[2966799.414616]  [<ffffffff81b99366>] ? lp_open+0x36/0x280
[2966799.414638]  [<ffffffff837cffa0>] mutex_lock_nested+0x40/0x50
[2966799.414638]  [<ffffffff81b99366>] lp_open+0x36/0x280
[2966799.414638]  [<ffffffff81985790>] ? do_raw_spin_unlock+0xd0/0xe0
[2966799.414640]  [<ffffffff8123eddf>] chrdev_open+0x10f/0x160
[2966799.414654]  [<ffffffff8123ecd0>] ? cdev_put+0x10/0x10
[2966799.414691]  [<ffffffff81238449>] do_dentry_open+0x229/0x320
[2966799.414722]  [<ffffffff8123862e>] nameidata_to_filp+0x6e/0x100
[2966799.414748]  [<ffffffff812490fc>] do_last+0x6cc/0x950
[2966799.414770]  [<ffffffff8124bb88>] path_openat+0xd8/0x4d0
[2966799.414806]  [<ffffffff8106f5ed>] ? sched_clock+0x1d/0x30
[2966799.414896]  [<ffffffff811222b7>] ? sched_clock_cpu+0x67/0x120
[2966799.414927]  [<ffffffff8124c094>] do_filp_open+0x44/0xa0
[2966799.414973]  [<ffffffff837d2f20>] ? _raw_spin_unlock+0x30/0x60
[2966799.415062]  [<ffffffff81259dcd>] ? alloc_fd+0x1ed/0x200
[2966799.415081]  [<ffffffff81239925>] do_sys_open+0x125/0x1c0
[2966799.415096]  [<ffffffff812399fc>] sys_open+0x1c/0x20
[2966799.415108]  [<ffffffff837d3f39>] system_call_fastpath+0x16/0x1b
[2966799.415108] 1 lock held by trinity/7230:
[2966799.415117]  #0:  (lp_mutex){+.+.+.}, at: [<ffffffff81b99366>] lp_open+0x36/0x280

This appears to be happening since we can block on port open, which is done within the mutex lock, so that any further lp_open calls with appear to be "hung" on that mutex.

That mutex was added there as part of BKL cleanup.

I'm not sure whether the solution here is to get the lock just on the parts which need locking, or add it as an exception to the hung task monitor.

Re: lp: hung task in lp_open

[Arnd Bergmann]

On Thursday 07 June 2012, Sasha Levin wrote:
> This appears to be happening since we can block on port open, which
> is done within the mutex lock, so that any further lp_open calls with
> appear to be "hung" on that mutex.
> 
> That mutex was added there as part of BKL cleanup.
> 
> I'm not sure whether the solution here is to get the lock just on the
> parts which need locking, or add it as an exception to the hung task monitor.

Hmm, does the hung task detector only trigger because this is an
uninterruptible sleep? Does this fix it?

8<------
lp: use only one per-port mutex

Different stages of the BKL removal in the lp driver have taken different
approaches: the earlier read/write conversion used a new per-port mutex,
while the later open and ioctl conversion used a global mutex and
did an uninterruptible sleep, which causes tasks to hang when multiple
ones try to open any device. Using mutex_lock_interruptible lets the
user stop waiting for a device that is already open and decouples the
devices from one another.

Reported-by: Sasha Levin <levinsasha928@gmail.com>
Signed-off-by: Arnd Bergmann <arnd@arndb.de>

diff --git a/drivers/char/lp.c b/drivers/char/lp.c
index a741e41..0fcb197 100644
--- a/drivers/char/lp.c
+++ b/drivers/char/lp.c
@@ -493,11 +493,12 @@ static int lp_open(struct inode * inode, struct file * file)
 	unsigned int minor = iminor(inode);
 	int ret = 0;
 
-	mutex_lock(&lp_mutex);
-	if (minor >= LP_NO) {
-		ret = -ENXIO;
-		goto out;
-	}
+	if (minor >= LP_NO)
+		return -ENXIO;
+
+	if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
+		return -ERESTARTSYS;
+
 	if ((LP_F(minor) & LP_EXIST) == 0) {
 		ret = -ENXIO;
 		goto out;
@@ -554,7 +555,7 @@ static int lp_open(struct inode * inode, struct file * file)
 	lp_release_parport (&lp_table[minor]);
 	lp_table[minor].current_mode = IEEE1284_MODE_COMPAT;
 out:
-	mutex_unlock(&lp_mutex);
+	mutex_unlock(&lp_table[minor].port_mutex);
 	return ret;
 }
 
@@ -680,7 +681,8 @@ static long lp_ioctl(struct file *file, unsigned int cmd,
 	int ret;
 
 	minor = iminor(file->f_path.dentry->d_inode);
-	mutex_lock(&lp_mutex);
+	if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
+		return -ERESTARTSYS;
 	switch (cmd) {
 	case LPSETTIMEOUT:
 		if (copy_from_user(&par_timeout, (void __user *)arg,
@@ -694,7 +696,7 @@ static long lp_ioctl(struct file *file, unsigned int cmd,
 		ret = lp_do_ioctl(minor, cmd, arg, (void __user *)arg);
 		break;
 	}
-	mutex_unlock(&lp_mutex);
+	mutex_unlock(&lp_table[minor].port_mutex);
 
 	return ret;
 }
@@ -708,7 +710,8 @@ static long lp_compat_ioctl(struct file *file, unsigned int cmd,
 	int ret;
 
 	minor = iminor(file->f_path.dentry->d_inode);
-	mutex_lock(&lp_mutex);
+	if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
+		return -ERESTARTSYS;
 	switch (cmd) {
 	case LPSETTIMEOUT:
 		if (compat_get_timeval(&par_timeout, compat_ptr(arg))) {
@@ -727,7 +730,7 @@ static long lp_compat_ioctl(struct file *file, unsigned int cmd,
 		ret = lp_do_ioctl(minor, cmd, arg, compat_ptr(arg));
 		break;
 	}
-	mutex_unlock(&lp_mutex);
+	mutex_unlock(&lp_table[minor].port_mutex);
 
 	return ret;
 }

Re: lp: hung task in lp_open

[Sasha Levin]

This seems to be doing the trick, thanks!

Sorry for the delay.

On Fri, Jun 8, 2012 at 1:59 AM, Arnd Bergmann <arnd@arndb.de> wrote:
> On Thursday 07 June 2012, Sasha Levin wrote:
>> This appears to be happening since we can block on port open, which
>> is done within the mutex lock, so that any further lp_open calls with
>> appear to be "hung" on that mutex.
>>
>> That mutex was added there as part of BKL cleanup.
>>
>> I'm not sure whether the solution here is to get the lock just on the
>> parts which need locking, or add it as an exception to the hung task monitor.
>
> Hmm, does the hung task detector only trigger because this is an
> uninterruptible sleep? Does this fix it?
>
> 8<------
> lp: use only one per-port mutex
>
> Different stages of the BKL removal in the lp driver have taken different
> approaches: the earlier read/write conversion used a new per-port mutex,
> while the later open and ioctl conversion used a global mutex and
> did an uninterruptible sleep, which causes tasks to hang when multiple
> ones try to open any device. Using mutex_lock_interruptible lets the
> user stop waiting for a device that is already open and decouples the
> devices from one another.
>
> Reported-by: Sasha Levin <levinsasha928@gmail.com>
> Signed-off-by: Arnd Bergmann <arnd@arndb.de>
>
> diff --git a/drivers/char/lp.c b/drivers/char/lp.c
> index a741e41..0fcb197 100644
> --- a/drivers/char/lp.c
> +++ b/drivers/char/lp.c
> @@ -493,11 +493,12 @@ static int lp_open(struct inode * inode, struct file * file)
>        unsigned int minor = iminor(inode);
>        int ret = 0;
>
> -       mutex_lock(&lp_mutex);
> -       if (minor >= LP_NO) {
> -               ret = -ENXIO;
> -               goto out;
> -       }
> +       if (minor >= LP_NO)
> +               return -ENXIO;
> +
> +       if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
> +               return -ERESTARTSYS;
> +
>        if ((LP_F(minor) & LP_EXIST) == 0) {
>                ret = -ENXIO;
>                goto out;
> @@ -554,7 +555,7 @@ static int lp_open(struct inode * inode, struct file * file)
>        lp_release_parport (&lp_table[minor]);
>        lp_table[minor].current_mode = IEEE1284_MODE_COMPAT;
>  out:
> -       mutex_unlock(&lp_mutex);
> +       mutex_unlock(&lp_table[minor].port_mutex);
>        return ret;
>  }
>
> @@ -680,7 +681,8 @@ static long lp_ioctl(struct file *file, unsigned int cmd,
>        int ret;
>
>        minor = iminor(file->f_path.dentry->d_inode);
> -       mutex_lock(&lp_mutex);
> +       if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
> +               return -ERESTARTSYS;
>        switch (cmd) {
>        case LPSETTIMEOUT:
>                if (copy_from_user(&par_timeout, (void __user *)arg,
> @@ -694,7 +696,7 @@ static long lp_ioctl(struct file *file, unsigned int cmd,
>                ret = lp_do_ioctl(minor, cmd, arg, (void __user *)arg);
>                break;
>        }
> -       mutex_unlock(&lp_mutex);
> +       mutex_unlock(&lp_table[minor].port_mutex);
>
>        return ret;
>  }
> @@ -708,7 +710,8 @@ static long lp_compat_ioctl(struct file *file, unsigned int cmd,
>        int ret;
>
>        minor = iminor(file->f_path.dentry->d_inode);
> -       mutex_lock(&lp_mutex);
> +       if (mutex_lock_interruptible(&lp_table[minor].port_mutex))
> +               return -ERESTARTSYS;
>        switch (cmd) {
>        case LPSETTIMEOUT:
>                if (compat_get_timeval(&par_timeout, compat_ptr(arg))) {
> @@ -727,7 +730,7 @@ static long lp_compat_ioctl(struct file *file, unsigned int cmd,
>                ret = lp_do_ioctl(minor, cmd, arg, compat_ptr(arg));
>                break;
>        }
> -       mutex_unlock(&lp_mutex);
> +       mutex_unlock(&lp_table[minor].port_mutex);
>
>        return ret;
>  }