Skip to contentSkip to conversation

locking/mutexes: Revert "locking/mutexes: Add extra reschedule point"

PATCH In review Ilya Dryomov 4 participants 14 messages Jul 31, 2014 – Aug 2, 2014

Subsystems (6)
Scheduler TTY layer and serial drivers Locking primitives CPU hotplug +2 more subsystems
lore
Share & tools
lore

Ilya Dryomov

author
#0 lore raw

PATCH 1/1 locking/mutexes: Revert "locking/mutexes: Add extra reschedule point"

This reverts commit 34c6bc2c919a55e5ad4e698510a2f35ee13ab900.

This commit can lead to deadlocks by way of what at a high level appears to look like a missing wakeup on mutex_unlock() when CONFIG_MUTEX_SPIN_ON_OWNER is set, which is how most distributions ship their kernels. In particular, it causes reproducible deadlocks in libceph/rbd code under higher than moderate loads with the evidence actually pointing to the bowels of mutex_lock().

kernel/locking/mutex.c, __mutex_lock_common():
476 osq_unlock(&lock->osq);
477 slowpath:
478 /*

479          * If we fell out of the spin path because of need_resched(),
480          * reschedule now, before we try-lock the mutex. This avoids getting
481          * scheduled out right after we obtained the mutex.
482          */

483 if (need_resched())
484 schedule_preempt_disabled(); <-- never returns
485 #endif
486 spin_lock_mutex(&lock->wait_lock, flags);

We started bumping into deadlocks in QA the day our branch has been rebased onto 3.15 (the release this commit went in) but then as part of debugging effort I enabled all locking debug options, which also disabled CONFIG_MUTEX_SPIN_ON_OWNER and made everything disappear, which is why it hasn't been looked into until now. Revert makes the problem go away, confirmed by our users.

Cc Peter Zijlstra <[email protected]>
Cc [email protected] # 3.15
Signed-off-by Ilya Dryomov <[email protected]>
---
 kernel/locking/mutex.c |    7 -------
 1 file changed, 7 deletions(-)
kernel/locking/mutex.c +0 -7
index acca2c1a3c5e..746ff280a2fc 100644
@@ -475,13 +475,6 @@ __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass,
 	}
 	osq_unlock(&lock->osq);
 slowpath:
-	/*
-	 * If we fell out of the spin path because of need_resched(),
-	 * reschedule now, before we try-lock the mutex. This avoids getting
-	 * scheduled out right after we obtained the mutex.
-	 */
-	if (need_resched())
-		schedule_preempt_disabled();
 #endif
 	spin_lock_mutex(&lock->wait_lock, flags);
Signature · 1 line
1.7.10.4
maintainer
#1 lore raw
Quoted 22 lines · Ilya Dryomov

This reverts commit 34c6bc2c919a55e5ad4e698510a2f35ee13ab900.

This commit can lead to deadlocks by way of what at a high level appears to look like a missing wakeup on mutex_unlock() when CONFIG_MUTEX_SPIN_ON_OWNER is set, which is how most distributions ship their kernels. In particular, it causes reproducible deadlocks in libceph/rbd code under higher than moderate loads with the evidence actually pointing to the bowels of mutex_lock().

kernel/locking/mutex.c, __mutex_lock_common():
476 osq_unlock(&lock->osq);
477 slowpath:
478 /*

479          * If we fell out of the spin path because of need_resched(),
480          * reschedule now, before we try-lock the mutex. This avoids getting
481          * scheduled out right after we obtained the mutex.
482          */

483 if (need_resched())
484 schedule_preempt_disabled(); <-- never returns
485 #endif
486 spin_lock_mutex(&lock->wait_lock, flags);

Quoted 6 lines

We started bumping into deadlocks in QA the day our branch has been rebased onto 3.15 (the release this commit went in) but then as part of debugging effort I enabled all locking debug options, which also disabled CONFIG_MUTEX_SPIN_ON_OWNER and made everything disappear, which is why it hasn't been looked into until now. Revert makes the problem go away, confirmed by our users.

This doesn't make sense and you fail to explain how this can possibly deadlock.

author
#2 lore raw
Quoted 30 lines · Peter Zijlstra
Quoted 22 lines · Ilya Dryomov

This reverts commit 34c6bc2c919a55e5ad4e698510a2f35ee13ab900.

This commit can lead to deadlocks by way of what at a high level appears to look like a missing wakeup on mutex_unlock() when CONFIG_MUTEX_SPIN_ON_OWNER is set, which is how most distributions ship their kernels. In particular, it causes reproducible deadlocks in libceph/rbd code under higher than moderate loads with the evidence actually pointing to the bowels of mutex_lock().

kernel/locking/mutex.c, __mutex_lock_common():
476 osq_unlock(&lock->osq);
477 slowpath:
478 /*

479          * If we fell out of the spin path because of need_resched(),
480          * reschedule now, before we try-lock the mutex. This avoids getting
481          * scheduled out right after we obtained the mutex.
482          */

483 if (need_resched())
484 schedule_preempt_disabled(); <-- never returns
485 #endif
486 spin_lock_mutex(&lock->wait_lock, flags);

Quoted 6 lines

We started bumping into deadlocks in QA the day our branch has been rebased onto 3.15 (the release this commit went in) but then as part of debugging effort I enabled all locking debug options, which also disabled CONFIG_MUTEX_SPIN_ON_OWNER and made everything disappear, which is why it hasn't been looked into until now. Revert makes the problem go away, confirmed by our users.

Quoted 2 lines

This doesn't make sense and you fail to explain how this can possibly deadlock.

This didn't make sense to me at first too, and I'll be happy to be proven wrong, but we can reproduce this with rbd very reliably under higher than usual load, and the revert makes it go away. What we are seeing in the rbd scenario is the following.

Suppose foo needs mutexes A and B, bar needs mutex B. foo acquires A and then wants to acquire B, but B is held by bar. foo spins a little and ends up calling schedule_preempt_disabled() on line 484 above, but that call never returns, even though a hundred usecs later bar releases B. foo ends up stuck in mutex_lock() indefinitely, but still holds A and everybody else who needs A gets behind A. Given that this A happens to be a central libceph mutex all rbd activity halts. Deadlock may not be the best term for this, but never returning from mutex_lock(&B) even though B has been unlocked is *a* problem.

This obviously doesn't happen every time schedule_preempt_disabled() on line 484 is called, so there must be some sort of race here. I'll send along the actual rbd stack traces shortly.

Thanks,

Ilya

maintainer
#3 lore raw
Quoted 4 lines · Ilya Dryomov

This didn't make sense to me at first too, and I'll be happy to be proven wrong, but we can reproduce this with rbd very reliably under higher than usual load, and the revert makes it go away. What we are seeing in the rbd scenario is the following.

This is drivers/block/rbd.c ? I can find but a single mutex_lock() in there.

Quoted 10 lines

Suppose foo needs mutexes A and B, bar needs mutex B. foo acquires A and then wants to acquire B, but B is held by bar. foo spins a little and ends up calling schedule_preempt_disabled() on line 484 above, but that call never returns, even though a hundred usecs later bar releases B. foo ends up stuck in mutex_lock() indefinitely, but still holds A and everybody else who needs A gets behind A. Given that this A happens to be a central libceph mutex all rbd activity halts. Deadlock may not be the best term for this, but never returning from mutex_lock(&B) even though B has been unlocked is *a* problem.

Quoted 3 lines

This obviously doesn't happen every time schedule_preempt_disabled() on line 484 is called, so there must be some sort of race here. I'll send along the actual rbd stack traces shortly.

Smells like maybe current->state != TASK_RUNNING, does the below trigger?

If so, you've wrecked something in whatever...

---
 kernel/locking/mutex.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)
kernel/locking/mutex.c +5 -1
index ae712b25e492..3d726fdaa764 100644
@@ -473,8 +473,12 @@ __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass,
 	 * reschedule now, before we try-lock the mutex. This avoids getting
 	 * scheduled out right after we obtained the mutex.
 	 */
-	if (need_resched())
+	if (need_resched()) {
+		if (WARN_ON_ONCE(current->state != TASK_RUNNING))
+			__set_current_state(TASK_RUNNING);
+
 		schedule_preempt_disabled();
+	}
 #endif
 	spin_lock_mutex(&lock->wait_lock, flags);
author
#4 lore raw
Quoted 9 lines · Peter Zijlstra
Quoted 4 lines · Ilya Dryomov

This didn't make sense to me at first too, and I'll be happy to be proven wrong, but we can reproduce this with rbd very reliably under higher than usual load, and the revert makes it go away. What we are seeing in the rbd scenario is the following.

This is drivers/block/rbd.c ? I can find but a single mutex_lock() in there.

This is in net/ceph, include/linux/ceph.

Mutex A - struct ceph_osd_client::request_mutex, taken in alloc_msg(), handle_timeout(), handle_osds_timeout(), ceph_osdc_start_request().

Mutex B - struct ceph_connection::mutex, taken in ceph_con_send().

dmesg with a sample dump of blocked tasks attached.

Basically everybody except kjournald:4398 is waiting for request_mutex, which kjournald acquired in ceph_osdc_start_request(). kjournald however itself sits waiting for ceph_connection::mutex, even though it has been released.

Quoted 10 lines
Quoted 10 lines

Suppose foo needs mutexes A and B, bar needs mutex B. foo acquires A and then wants to acquire B, but B is held by bar. foo spins a little and ends up calling schedule_preempt_disabled() on line 484 above, but that call never returns, even though a hundred usecs later bar releases B. foo ends up stuck in mutex_lock() indefinitely, but still holds A and everybody else who needs A gets behind A. Given that this A happens to be a central libceph mutex all rbd activity halts. Deadlock may not be the best term for this, but never returning from mutex_lock(&B) even though B has been unlocked is *a* problem.

Quoted 8 lines
Quoted 3 lines

This obviously doesn't happen every time schedule_preempt_disabled() on line 484 is called, so there must be some sort of race here. I'll send along the actual rbd stack traces shortly.

Smells like maybe current->state != TASK_RUNNING, does the below trigger?

If so, you've wrecked something in whatever...

Trying it now.

Thanks,

Ilya

#5 lore raw
In reply to Peter Zijlstra
Quoted 38 lines · Peter Zijlstra
Quoted 4 lines · Ilya Dryomov

This didn't make sense to me at first too, and I'll be happy to be proven wrong, but we can reproduce this with rbd very reliably under higher than usual load, and the revert makes it go away. What we are seeing in the rbd scenario is the following.

This is drivers/block/rbd.c ? I can find but a single mutex_lock() in there.

Quoted 10 lines

Suppose foo needs mutexes A and B, bar needs mutex B. foo acquires A and then wants to acquire B, but B is held by bar. foo spins a little and ends up calling schedule_preempt_disabled() on line 484 above, but that call never returns, even though a hundred usecs later bar releases B. foo ends up stuck in mutex_lock() indefinitely, but still holds A and everybody else who needs A gets behind A. Given that this A happens to be a central libceph mutex all rbd activity halts. Deadlock may not be the best term for this, but never returning from mutex_lock(&B) even though B has been unlocked is *a* problem.

Quoted 3 lines

This obviously doesn't happen every time schedule_preempt_disabled() on line 484 is called, so there must be some sort of race here. I'll send along the actual rbd stack traces shortly.

Smells like maybe current->state != TASK_RUNNING, does the below trigger?

If so, you've wrecked something in whatever...

---
 kernel/locking/mutex.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)
kernel/locking/mutex.c +0 -0
index ae712b25e492..3d726fdaa764 100644

kernel/locking/mutex.c __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass, · line 481

Quoted 10 lines
kernel/locking/mutex.c +5 -1
@@ -473,8 +473,12 @@ __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass,
 	 * reschedule now, before we try-lock the mutex. This avoids getting
 	 * scheduled out right after we obtained the mutex.
 	 */
-	if (need_resched())
+	if (need_resched()) {
+		if (WARN_ON_ONCE(current->state != TASK_RUNNING))
+			__set_current_state(TASK_RUNNING);
+
 		schedule_preempt_disabled();
+	}

Might make sense to add that debug check under mutex debugging or so, with a sensible kernel message printed.

Thanks,

Ingo

maintainer
#6 lore raw
Quoted 11 lines · Ingo Molnar
Quoted 11 lines
kernel/locking/mutex.c +1 -1
index ae712b25e492..3d726fdaa764 100644
@@ -473,8 +473,12 @@ __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass,
 	 * reschedule now, before we try-lock the mutex. This avoids getting
 	 * scheduled out right after we obtained the mutex.
 	 */
-	if (need_resched())
+	if (need_resched()) {
Quoted 8 lines

kernel/locking/mutex.c __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass, · line 481

Quoted 5 lines
kernel/locking/mutex.c +4 -0
+		if (WARN_ON_ONCE(current->state != TASK_RUNNING))
+			__set_current_state(TASK_RUNNING);
+
 		schedule_preempt_disabled();
+	}

Might make sense to add that debug check under mutex debugging or so, with a sensible kernel message printed.

Something like so? I suppose we should do a similar one for rwsem, semaphores and possibly wait_event*() too.

---
Subject: locking/mutex: Add debug check for task state

Calling blocking locks with current->state != TASK_RUNNING is a bug.

Signed-off-by Peter Zijlstra <[email protected]>
---
 kernel/locking/mutex.c | 11 +++++++++++
 1 file changed, 11 insertions(+)
kernel/locking/mutex.c +11 -0
index ae712b25e492..d5daf8c38899 100644
@@ -375,6 +375,17 @@ __mutex_lock_common(struct mutex *lock, long state, unsigned int subclass,
 	unsigned long flags;
 	int ret;
 
+#ifdef CONFIG_DEBUG_MUTEXES
+	/*
+	 * Blocking primitives (including this one) will set (and therefore
+	 * destroy) current->state, since we will exit with TASK_RUNNING
+	 * make sure we enter with it, otherwise we will destroy state.
+	 */
+	if (WARN_ONCE(current->state != TASK_RUNNING,
+			"do not call blocking locks when !TASK_RUNNING\n"))
+		__set_current_state(TASK_RUNNING);
+#endif
+
 	preempt_disable();
 	mutex_acquire_nest(&lock->dep_map, subclass, 0, nest_lock, ip);
maintainer
#7 lore raw

RFC PATCH 1/1 locking: Debug nested wait/locking primitives

This should cover most cases I think.

I'll have to break this out into different patches, and maybe clean up things a bit (there's certainly comments missing and some repetition).

But this boots on my test box and builds a kernel without generating a single WARN -- big improvement over not booting (partly due to excessive warn output) with just the sched/core.c bit.

---
 drivers/tty/n_tty.c              | 71 +++++++++++++++++++++++++++++++++-------
 fs/notify/inotify/inotify_user.c | 34 +++++++++++++++++--
 fs/notify/notification.c         |  2 +-
 include/linux/kernel.h           |  4 +--
 include/linux/sched.h            | 46 ++++++++++++++++++++++++--
 include/linux/wait.h             |  2 ++
 kernel/exit.c                    |  6 ++++
 kernel/sched/core.c              | 14 ++++++++
 kernel/smpboot.c                 | 15 +++++----
 9 files changed, 168 insertions(+), 26 deletions(-)
drivers/tty/n_tty.c +60 -11
index f44f1ba762c3..5e4830979937 100644
@@ -2098,6 +2098,36 @@ static int job_control(struct tty_struct *tty, struct file *file)
 	return 0;
 }
 
+/*
+ * n_tty_{read,write} use blocking primitives (mutex_lock, down_read, etc.)
+ * inside an open-coded wait loop.
+ *
+ * The wait loop relies on current->state to record wakeups; these will change
+ * it back to TASK_RUNNING. However blocking primitives themselves also change
+ * current->state. Therefore we must implement another means of recording
+ * wakeups.
+ *
+ * We do this by setting an alternative waitqueue wake function which changes
+ * an additional variable.
+ */
+
+struct n_tty_wakeup_state {
+	struct task_struct *task;
+	bool woken;
+};
+
+static int n_tty_wake(wait_queue_t *wait, unsigned mode,
+			    int wake_flags, void *key)
+{
+	struct n_tty_wakeup_state *s = wait->private;
+	DECLARE_WAITQUEUE(dummy_wait, s->task);
+
+	smp_wmb();
+	s->woken = true;
+
+	return default_wake_function(&dummy_wait, mode, wake_flags, key);
+}
+
 
 /**
  *	n_tty_read		-	read function for tty

@@ -2123,7 +2153,11 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
 {
 	struct n_tty_data *ldata = tty->disc_data;
 	unsigned char __user *b = buf;
-	DECLARE_WAITQUEUE(wait, current);
+	struct n_tty_wakeup_state s = {
+		.task = current,
+		.woken = false,
+	};
+	wait_queue_t wait;
 	int c;
 	int minimum, time;
 	ssize_t retval = 0;

@@ -2167,6 +2201,9 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
 
 	packet = tty->packet;
 
+	init_waitqueue_func_entry(&wait, n_tty_wake);
+	wait.private = &s;
+
 	add_wait_queue(&tty->read_wait, &wait);
 	while (nr) {
 		/* First test for status change. */

@@ -2186,10 +2223,11 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
 			nr--;
 			break;
 		}
-		/* This statement must be first before checking for input
-		   so that any interrupt will set the state back to
-		   TASK_RUNNING. */
-		set_current_state(TASK_INTERRUPTIBLE);
+		/*
+		 * This statement must be first before checking for input so
+		 * that any interrupt will set it to true.
+		 */
+		s.woken = false;
 
 		if (((minimum - (b - buf)) < ldata->minimum_to_wake) &&
 		    ((minimum - (b - buf)) >= 1))

@@ -2220,13 +2258,15 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
 				n_tty_set_room(tty);
 				up_read(&tty->termios_rwsem);
 
-				timeout = schedule_timeout(timeout);
+				set_current_state(TASK_INTERRUPTIBLE);
+				if (!s.woken)
+					timeout = schedule_timeout(timeout);
+				__set_current_state(TASK_RUNNING);
 
 				down_read(&tty->termios_rwsem);
 				continue;
 			}
 		}
-		__set_current_state(TASK_RUNNING);
 
 		/* Deal with packet mode. */
 		if (packet && b == buf) {

@@ -2273,7 +2313,6 @@ static ssize_t n_tty_read(struct tty_struct *tty, struct file *file,
 
 	mutex_unlock(&ldata->atomic_read_lock);
 
-	__set_current_state(TASK_RUNNING);
 	if (b - buf)
 		retval = b - buf;
 

@@ -2306,7 +2345,11 @@ static ssize_t n_tty_write(struct tty_struct *tty, struct file *file,
 			   const unsigned char *buf, size_t nr)
 {
 	const unsigned char *b = buf;
-	DECLARE_WAITQUEUE(wait, current);
+	struct n_tty_wakeup_state s = {
+		.task = current,
+		.woken = false,
+	};
+	wait_queue_t wait;
 	int c;
 	ssize_t retval = 0;
 

@@ -2322,9 +2365,12 @@ static ssize_t n_tty_write(struct tty_struct *tty, struct file *file,
 	/* Write out any echoed characters that are still pending */
 	process_echoes(tty);
 
+	init_waitqueue_func_entry(&wait, n_tty_wake);
+	wait.private = &s;
+
 	add_wait_queue(&tty->write_wait, &wait);
 	while (1) {
-		set_current_state(TASK_INTERRUPTIBLE);
+		s.woken = false;
 		if (signal_pending(current)) {
 			retval = -ERESTARTSYS;
 			break;

@@ -2378,7 +2424,10 @@ static ssize_t n_tty_write(struct tty_struct *tty, struct file *file,
 		}
 		up_read(&tty->termios_rwsem);
 
-		schedule();
+		set_current_state(TASK_INTERRUPTIBLE);
+		if (!s.woken)
+			schedule();
+		__set_current_state(TASK_RUNNING);
 
 		down_read(&tty->termios_rwsem);
 	}
fs/notify/inotify/inotify_user.c +31 -3
index cc423a30a0c8..e3b65ce6b312 100644
@@ -220,6 +220,23 @@ static ssize_t copy_event_to_user(struct fsnotify_group *group,
 	return event_size;
 }
 
+struct inotify_wakeup_state {
+	struct task_struct *task;
+	bool woken;
+};
+
+static int inotify_wake(wait_queue_t *wait, unsigned mode,
+			int wake_flags, void *key)
+{
+	struct inotify_wakeup_state *s = wait->private;
+	DECLARE_WAITQUEUE(dummy_wait, s->task);
+
+	smp_wmb();
+	s->woken = true;
+
+	return autoremove_wake_function(&dummy_wait, mode, wake_flags, key);
+}
+
 static ssize_t inotify_read(struct file *file, char __user *buf,
 			    size_t count, loff_t *pos)
 {

@@ -227,13 +244,21 @@ static ssize_t inotify_read(struct file *file, char __user *buf,
 	struct fsnotify_event *kevent;
 	char __user *start;
 	int ret;
-	DEFINE_WAIT(wait);
+	struct inotify_wakeup_state s = {
+		.task = current,
+		.woken = false,
+	};
+	wait_queue_t wait;
+
+	init_waitqueue_func_entry(&wait, inotify_wake);
+	wait.private = &s;
 
 	start = buf;
 	group = file->private_data;
 
+	add_wait_queue(&group->notification_waitq, &wait);
 	while (1) {
-		prepare_to_wait(&group->notification_waitq, &wait, TASK_INTERRUPTIBLE);
+		s.woken = false;
 
 		mutex_lock(&group->notification_mutex);
 		kevent = get_one_event(group, count);

@@ -264,7 +289,10 @@ static ssize_t inotify_read(struct file *file, char __user *buf,
 		if (start != buf)
 			break;
 
-		schedule();
+		set_current_state(TASK_INTERRUPTIBLE);
+		if (!s.woken)
+			schedule();
+		__set_current_state(TASK_RUNNING);
 	}
 
 	finish_wait(&group->notification_waitq, &wait);
fs/notify/notification.c +1 -1
index 1e58402171a5..dcfcdd69d1de 100644
@@ -63,7 +63,7 @@ EXPORT_SYMBOL_GPL(fsnotify_get_cookie);
 /* return true if the notify queue is empty, false otherwise */
 bool fsnotify_notify_queue_is_empty(struct fsnotify_group *group)
 {
-	BUG_ON(!mutex_is_locked(&group->notification_mutex));
+	lockdep_assert_held(&group->notification_mutex);
 	return list_empty(&group->notification_list) ? true : false;
 }
include/linux/kernel.h +2 -2
index 4c52907a6d8b..aac1dc9da2d0 100644
@@ -162,7 +162,7 @@ extern int _cond_resched(void);
 #endif
 
 #ifdef CONFIG_DEBUG_ATOMIC_SLEEP
-  void __might_sleep(const char *file, int line, int preempt_offset);
+extern  void __might_sleep(const char *file, int line, int preempt_offset);
 /**
  * might_sleep - annotation for functions that can sleep
  *

@@ -174,7 +174,7 @@ extern int _cond_resched(void);
  * supposed to.
  */
 # define might_sleep() \
-	do { __might_sleep(__FILE__, __LINE__, 0); might_resched(); } while (0)
+	  do { __might_sleep(__FILE__, __LINE__, 0); might_resched(); } while (0)
 #else
   static inline void __might_sleep(const char *file, int line,
 				   int preempt_offset) { }
include/linux/sched.h +44 -2

67 lines not on this page · raw message

include/linux/wait.h +2 -0
index 6fb1ba5f9b2f..041b744e99b4 100644
@@ -211,6 +211,8 @@ wait_queue_head_t *bit_waitqueue(void *, int);
 	wait_queue_t __wait;						\
 	long __ret = ret;	/* explicit shadow */			\
 									\
+	might_sleep();							\
+									\
 	INIT_LIST_HEAD(&__wait.task_list);				\
 	if (exclusive)							\
 		__wait.flags = WQ_FLAG_EXCLUSIVE;			\
kernel/exit.c +6 -0
index e5c4668f1799..44cbc8791fca 100644
@@ -1067,6 +1067,12 @@ static int wait_task_zombie(struct wait_opts *wo, struct task_struct *p)
 	}
 
 	/*
+	 * Since we're going to terminate the wait loop from do_wait(),
+	 * reset task state.
+	 */
+	__set_current_state(TASK_RUNNING);
+
+	/*
 	 * Now we are sure this task is interesting, and no other
 	 * thread can reap it because we its state == DEAD/TRACE.
 	 */
kernel/sched/core.c +14 -0
index 2676866b4394..0577c12c9cf8 100644
@@ -7077,6 +7077,19 @@ void __might_sleep(const char *file, int line, int preempt_offset)
 {
 	static unsigned long prev_jiffy;	/* ratelimiting */
 
+	/*
+	 * Blocking primitives will set (and therefore destroy) current->state,
+	 * since we will exit with TASK_RUNNING make sure we enter with it,
+	 * otherwise we will destroy state.
+	 */
+	if (WARN(current->state != TASK_RUNNING,
+			"do not call blocking ops when !TASK_RUNNING; "
+			"state=%lx set at [<%p>] %pS\n",
+			current->state,
+			current->task_state_change,
+			current->task_state_change))
+		__set_current_state(TASK_RUNNING);
+
 	rcu_sleep_check(); /* WARN_ON_ONCE() by default, no rate limit reqd. */
 	if ((preempt_count_equals(preempt_offset) && !irqs_disabled() &&
 	     !is_idle_task(current)) ||

@@ -7107,6 +7120,7 @@ void __might_sleep(const char *file, int line, int preempt_offset)
 	dump_stack();
 }
 EXPORT_SYMBOL(__might_sleep);
+
 #endif
 
 #ifdef CONFIG_MAGIC_SYSRQ
kernel/smpboot.c +8 -7
index eb89e1807408..f032fb5284e3 100644
@@ -110,7 +110,7 @@ static int smpboot_thread_fn(void *data)
 		set_current_state(TASK_INTERRUPTIBLE);
 		preempt_disable();
 		if (kthread_should_stop()) {
-			set_current_state(TASK_RUNNING);
+			__set_current_state(TASK_RUNNING);
 			preempt_enable();
 			if (ht->cleanup)
 				ht->cleanup(td->cpu, cpu_online(td->cpu));

@@ -136,26 +136,27 @@ static int smpboot_thread_fn(void *data)
 		/* Check for state change setup */
 		switch (td->status) {
 		case HP_THREAD_NONE:
+			__set_current_state(TASK_RUNNING);
 			preempt_enable();
 			if (ht->setup)
 				ht->setup(td->cpu);
 			td->status = HP_THREAD_ACTIVE;
-			preempt_disable();
-			break;
+			continue;
+
 		case HP_THREAD_PARKED:
+			__set_current_state(TASK_RUNNING);
 			preempt_enable();
 			if (ht->unpark)
 				ht->unpark(td->cpu);
 			td->status = HP_THREAD_ACTIVE;
-			preempt_disable();
-			break;
+			continue;
 		}
 
 		if (!ht->thread_should_run(td->cpu)) {
-			preempt_enable();
+			preempt_enable_no_resched();
 			schedule();
 		} else {
-			set_current_state(TASK_RUNNING);
+			__set_current_state(TASK_RUNNING);
 			preempt_enable();
 			ht->thread_fn(td->cpu);
 		}
#8 lore raw
In reply to Peter Zijlstra
Quoted 1 line · Peter Zijlstra

Smells like maybe current->state != TASK_RUNNING

Bingo

[ 1200.851004] kjournald       D 0000000000000002     0  4398      2 0x00000000
[ 1200.858283]  ffff8803537bb788 0000000000000046 ffff8803537bb7a8 0000000000000000
[ 1200.865914]  ffff880423324b60 0000000000012f80 ffff8803537bbfd8 0000000000012f80
[ 1200.873590]  ffff88042937cb60 ffff880423324b60 ffff880428ceb240 ffff8804231e59b8
[ 1200.881256] Call Trace:
[ 1200.883724]  [<ffffffff816981c9>] schedule+0x29/0x70
[ 1200.888798]  [<ffffffff8169849e>] schedule_preempt_disabled+0xe/0x10
[ 1200.895239]  [<ffffffff81699fe5>] __mutex_lock_slowpath+0x1b5/0x1c0
[ 1200.901673]  [<ffffffffa0479826>] ? ceph_str_hash+0x26/0x80 [libceph]
[ 1200.908198]  [<ffffffff8169a013>] mutex_lock+0x23/0x37
[ 1200.913430]  [<ffffffffa046751d>] ceph_con_send+0x4d/0x130 [libceph]
[ 1200.919912]  [<ffffffffa046c540>] __send_queued+0x120/0x150 [libceph]
[ 1200.926444]  [<ffffffffa046ec5b>] __ceph_osdc_start_request+0x5b/0xd0 [libceph]
[ 1200.933855]  [<ffffffffa046ed21>] ceph_osdc_start_request+0x51/0x80 [libceph]
[ 1200.941126]  [<ffffffffa042bf60>] rbd_obj_request_submit.isra.25+0x10/0x20 [rbd]
[ 1200.948622]  [<ffffffffa042e8ee>] rbd_img_obj_request_submit+0x1ce/0x460 [rbd]
[ 1200.956040]  [<ffffffffa042ebcc>] rbd_img_request_submit+0x4c/0x60 [rbd]
[ 1200.962845]  [<ffffffffa042f2a8>] rbd_request_fn+0x238/0x290 [rbd]
[ 1200.969108]  [<ffffffff8133a397>] __blk_run_queue+0x37/0x50
[ 1200.974764]  [<ffffffff8133affd>] queue_unplugged+0x3d/0xc0
[ 1200.980424]  [<ffffffff8133fddb>] blk_flush_plug_list+0x1db/0x210
[ 1200.986635]  [<ffffffff81698288>] io_schedule+0x78/0xd0
[ 1200.991954]  [<ffffffff8133b864>] get_request+0x414/0x800
[ 1200.997440]  [<ffffffff8133f477>] ? bio_attempt_back_merge+0x37/0x100
[ 1201.004013]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.009782]  [<ffffffff8133ff2c>] blk_queue_bio+0xcc/0x360
[ 1201.015353]  [<ffffffff8133c2d0>] generic_make_request+0xc0/0x100
[ 1201.021605]  [<ffffffff8133c385>] submit_bio+0x75/0x140
[ 1201.026921]  [<ffffffff811de4e6>] _submit_bh+0x136/0x1f0
[ 1201.032390]  [<ffffffff81290081>] journal_do_submit_data+0x41/0x50
[ 1201.038662]  [<ffffffff81291380>] journal_commit_transaction+0x1150/0x1350
[ 1201.045683]  [<ffffffff81063aff>] ? try_to_del_timer_sync+0x4f/0x70
[ 1201.052043]  [<ffffffff81293e01>] kjournald+0xe1/0x260
[ 1201.057324]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.063072]  [<ffffffff81293d20>] ? commit_timeout+0x10/0x10
[ 1201.068855]  [<ffffffff81078829>] kthread+0xc9/0xe0
[ 1201.073819]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0
[ 1201.080084]  [<ffffffff8169bb6c>] ret_from_fork+0x7c/0xb0
[ 1201.085573]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0
author
#9 lore raw
Quoted 3 lines · Mike Galbraith
Quoted 1 line · Peter Zijlstra

Smells like maybe current->state != TASK_RUNNING

It just triggered for me too, took longer than usual. Sorry for the churn Peter, this was really confusing. Onto finding the real bug..

Thanks,

Ilya

maintainer
#10 lore raw
In reply to Mike Galbraith
Quoted 37 lines · Mike Galbraith
Quoted 1 line · Peter Zijlstra

Smells like maybe current->state != TASK_RUNNING

Bingo

[ 1200.851004] kjournald       D 0000000000000002     0  4398      2 0x00000000
[ 1200.858283]  ffff8803537bb788 0000000000000046 ffff8803537bb7a8 0000000000000000
[ 1200.865914]  ffff880423324b60 0000000000012f80 ffff8803537bbfd8 0000000000012f80
[ 1200.873590]  ffff88042937cb60 ffff880423324b60 ffff880428ceb240 ffff8804231e59b8
[ 1200.881256] Call Trace:
[ 1200.883724]  [<ffffffff816981c9>] schedule+0x29/0x70
[ 1200.888798]  [<ffffffff8169849e>] schedule_preempt_disabled+0xe/0x10
[ 1200.895239]  [<ffffffff81699fe5>] __mutex_lock_slowpath+0x1b5/0x1c0
[ 1200.901673]  [<ffffffffa0479826>] ? ceph_str_hash+0x26/0x80 [libceph]
[ 1200.908198]  [<ffffffff8169a013>] mutex_lock+0x23/0x37
[ 1200.913430]  [<ffffffffa046751d>] ceph_con_send+0x4d/0x130 [libceph]
[ 1200.919912]  [<ffffffffa046c540>] __send_queued+0x120/0x150 [libceph]
[ 1200.926444]  [<ffffffffa046ec5b>] __ceph_osdc_start_request+0x5b/0xd0 [libceph]
[ 1200.933855]  [<ffffffffa046ed21>] ceph_osdc_start_request+0x51/0x80 [libceph]
[ 1200.941126]  [<ffffffffa042bf60>] rbd_obj_request_submit.isra.25+0x10/0x20 [rbd]
[ 1200.948622]  [<ffffffffa042e8ee>] rbd_img_obj_request_submit+0x1ce/0x460 [rbd]
[ 1200.956040]  [<ffffffffa042ebcc>] rbd_img_request_submit+0x4c/0x60 [rbd]
[ 1200.962845]  [<ffffffffa042f2a8>] rbd_request_fn+0x238/0x290 [rbd]
[ 1200.969108]  [<ffffffff8133a397>] __blk_run_queue+0x37/0x50
[ 1200.974764]  [<ffffffff8133affd>] queue_unplugged+0x3d/0xc0
[ 1200.980424]  [<ffffffff8133fddb>] blk_flush_plug_list+0x1db/0x210
[ 1200.986635]  [<ffffffff81698288>] io_schedule+0x78/0xd0
[ 1200.991954]  [<ffffffff8133b864>] get_request+0x414/0x800
[ 1200.997440]  [<ffffffff8133f477>] ? bio_attempt_back_merge+0x37/0x100
[ 1201.004013]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.009782]  [<ffffffff8133ff2c>] blk_queue_bio+0xcc/0x360
[ 1201.015353]  [<ffffffff8133c2d0>] generic_make_request+0xc0/0x100
[ 1201.021605]  [<ffffffff8133c385>] submit_bio+0x75/0x140
[ 1201.026921]  [<ffffffff811de4e6>] _submit_bh+0x136/0x1f0
[ 1201.032390]  [<ffffffff81290081>] journal_do_submit_data+0x41/0x50
[ 1201.038662]  [<ffffffff81291380>] journal_commit_transaction+0x1150/0x1350
Quoted 8 lines
[ 1201.045683]  [<ffffffff81063aff>] ? try_to_del_timer_sync+0x4f/0x70
[ 1201.052043]  [<ffffffff81293e01>] kjournald+0xe1/0x260
[ 1201.057324]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.063072]  [<ffffffff81293d20>] ? commit_timeout+0x10/0x10
[ 1201.068855]  [<ffffffff81078829>] kthread+0xc9/0xe0
[ 1201.073819]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0
[ 1201.080084]  [<ffffffff8169bb6c>] ret_from_fork+0x7c/0xb0
[ 1201.085573]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0

Ohh. that's properly broken indeed.

You can't just call blocking primitives on the way to schedule(), that's fail.

Also, if I look at blk_flush_plug_list(), it calls queue_unplugged() with IRQs disabled, so _who_ is enabling them again and calling blocking stuff?

/me stares more..

rbd_request_fn() does.. *argh*

Someone needs to go fix, this cannot work right.

author
#11 lore raw
Quoted 56 lines · Peter Zijlstra
Quoted 37 lines · Mike Galbraith
Quoted 1 line · Peter Zijlstra

Smells like maybe current->state != TASK_RUNNING

Bingo

[ 1200.851004] kjournald       D 0000000000000002     0  4398      2 0x00000000
[ 1200.858283]  ffff8803537bb788 0000000000000046 ffff8803537bb7a8 0000000000000000
[ 1200.865914]  ffff880423324b60 0000000000012f80 ffff8803537bbfd8 0000000000012f80
[ 1200.873590]  ffff88042937cb60 ffff880423324b60 ffff880428ceb240 ffff8804231e59b8
[ 1200.881256] Call Trace:
[ 1200.883724]  [<ffffffff816981c9>] schedule+0x29/0x70
[ 1200.888798]  [<ffffffff8169849e>] schedule_preempt_disabled+0xe/0x10
[ 1200.895239]  [<ffffffff81699fe5>] __mutex_lock_slowpath+0x1b5/0x1c0
[ 1200.901673]  [<ffffffffa0479826>] ? ceph_str_hash+0x26/0x80 [libceph]
[ 1200.908198]  [<ffffffff8169a013>] mutex_lock+0x23/0x37
[ 1200.913430]  [<ffffffffa046751d>] ceph_con_send+0x4d/0x130 [libceph]
[ 1200.919912]  [<ffffffffa046c540>] __send_queued+0x120/0x150 [libceph]
[ 1200.926444]  [<ffffffffa046ec5b>] __ceph_osdc_start_request+0x5b/0xd0 [libceph]
[ 1200.933855]  [<ffffffffa046ed21>] ceph_osdc_start_request+0x51/0x80 [libceph]
[ 1200.941126]  [<ffffffffa042bf60>] rbd_obj_request_submit.isra.25+0x10/0x20 [rbd]
[ 1200.948622]  [<ffffffffa042e8ee>] rbd_img_obj_request_submit+0x1ce/0x460 [rbd]
[ 1200.956040]  [<ffffffffa042ebcc>] rbd_img_request_submit+0x4c/0x60 [rbd]
[ 1200.962845]  [<ffffffffa042f2a8>] rbd_request_fn+0x238/0x290 [rbd]
[ 1200.969108]  [<ffffffff8133a397>] __blk_run_queue+0x37/0x50
[ 1200.974764]  [<ffffffff8133affd>] queue_unplugged+0x3d/0xc0
[ 1200.980424]  [<ffffffff8133fddb>] blk_flush_plug_list+0x1db/0x210
[ 1200.986635]  [<ffffffff81698288>] io_schedule+0x78/0xd0
[ 1200.991954]  [<ffffffff8133b864>] get_request+0x414/0x800
[ 1200.997440]  [<ffffffff8133f477>] ? bio_attempt_back_merge+0x37/0x100
[ 1201.004013]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.009782]  [<ffffffff8133ff2c>] blk_queue_bio+0xcc/0x360
[ 1201.015353]  [<ffffffff8133c2d0>] generic_make_request+0xc0/0x100
[ 1201.021605]  [<ffffffff8133c385>] submit_bio+0x75/0x140
[ 1201.026921]  [<ffffffff811de4e6>] _submit_bh+0x136/0x1f0
[ 1201.032390]  [<ffffffff81290081>] journal_do_submit_data+0x41/0x50
[ 1201.038662]  [<ffffffff81291380>] journal_commit_transaction+0x1150/0x1350
Quoted 8 lines
[ 1201.045683]  [<ffffffff81063aff>] ? try_to_del_timer_sync+0x4f/0x70
[ 1201.052043]  [<ffffffff81293e01>] kjournald+0xe1/0x260
[ 1201.057324]  [<ffffffff8109b9e0>] ? __wake_up_sync+0x20/0x20
[ 1201.063072]  [<ffffffff81293d20>] ? commit_timeout+0x10/0x10
[ 1201.068855]  [<ffffffff81078829>] kthread+0xc9/0xe0
[ 1201.073819]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0
[ 1201.080084]  [<ffffffff8169bb6c>] ret_from_fork+0x7c/0xb0
[ 1201.085573]  [<ffffffff81078760>] ? flush_kthread_worker+0xb0/0xb0

Ohh. that's properly broken indeed.

You can't just call blocking primitives on the way to schedule(), that's fail.

Also, if I look at blk_flush_plug_list(), it calls queue_unplugged() with IRQs disabled, so _who_ is enabling them again and calling blocking stuff?

Quoted 5 lines

/me stares more..

rbd_request_fn() does.. *argh*

Someone needs to go fix, this cannot work right.

I'm going to fix up rbd_request_fn(), but I want to make sure I understand this in full.

- Previously the danger of calling blocking primitives on the way to schedule(), i.e. with task->state != TASK_RUNNING, was that if the blocking primitive was indeed to block the task state would be set back to TASK_RUNNING and the schedule() that that task was on the way to wouldn't have any effect. Your "Add extra reschedule point" patch essentially made calling mutex_lock() and probably others much more wrong that it used to be, because mutex_lock() may now reschedule when the task is not on the mutex wait queue.

- There is nothing wrong with releasing queue_lock and reenabling IRQs in rbd_request_fn() as long as it doesn't block and I remember to disable IRQs and take queue_lock back on return.

I'm asking because rbd_request_fn() is probably not the only broken in this way code path. I poked around and found read_events() in aio.c, it seems to have been written with the "danger" assumption that I outlined above and there is even a comment to it.

Does that above make sense or am I missing something?

Thanks,

Ilya

maintainer
#12 lore raw
Quoted 11 lines · Ilya Dryomov

I'm going to fix up rbd_request_fn(), but I want to make sure I understand this in full.

- Previously the danger of calling blocking primitives on the way to schedule(), i.e. with task->state != TASK_RUNNING, was that if the blocking primitive was indeed to block the task state would be set back to TASK_RUNNING and the schedule() that that task was on the way to wouldn't have any effect. Your "Add extra reschedule point" patch essentially made calling mutex_lock() and probably others much more wrong that it used to be, because mutex_lock() may now reschedule when the task is not on the mutex wait queue.

Right and in general we cannot allow spurious wakeups (although we try very hard to deal with them in generic code, which is why things more or less worked).

But if you do a patch that 'randomly' ignores ->state on schedule (I did one) stuff comes apart _real_ quick.

Therefore you should very much not destroy ->state on the way to schedule.

Quoted 3 lines

- There is nothing wrong with releasing queue_lock and reenabling IRQs in rbd_request_fn() as long as it doesn't block and I remember to disable IRQs and take queue_lock back on return.

Releasing queue_lock might be ok, dunno about the blk locking, however reenabling IRQs it is actually wrong as per blk_flush_plug_list() since that uses local_irq_save()/restore() which means it can be called from contexts which cannot deal with enabling IRQs, and then your ->request_fn() goes and does that.

Now maybe blk_flush_plug_list() is overly paranoid and it could use local_irq_disable()/enable() instead, I don't know. But until it does, a request_fn() should never reenable IRQs.

Quoted 4 lines

I'm asking because rbd_request_fn() is probably not the only broken in this way code path. I poked around and found read_events() in aio.c, it seems to have been written with the "danger" assumption that I outlined above and there is even a comment to it.

I'm fairly sure there's more broken stuff, I didn't dare looking.

Quoted 1 line

Does that above make sense or am I missing something?

I think that's about it.

author
#13 lore raw
Quoted 42 lines · Peter Zijlstra
Quoted 11 lines · Ilya Dryomov

I'm going to fix up rbd_request_fn(), but I want to make sure I understand this in full.

- Previously the danger of calling blocking primitives on the way to schedule(), i.e. with task->state != TASK_RUNNING, was that if the blocking primitive was indeed to block the task state would be set back to TASK_RUNNING and the schedule() that that task was on the way to wouldn't have any effect. Your "Add extra reschedule point" patch essentially made calling mutex_lock() and probably others much more wrong that it used to be, because mutex_lock() may now reschedule when the task is not on the mutex wait queue.

Right and in general we cannot allow spurious wakeups (although we try very hard to deal with them in generic code, which is why things more or less worked).

But if you do a patch that 'randomly' ignores ->state on schedule (I did one) stuff comes apart _real_ quick.

Therefore you should very much not destroy ->state on the way to schedule.

Quoted 3 lines

- There is nothing wrong with releasing queue_lock and reenabling IRQs in rbd_request_fn() as long as it doesn't block and I remember to disable IRQs and take queue_lock back on return.

Releasing queue_lock might be ok, dunno about the blk locking, however reenabling IRQs it is actually wrong as per blk_flush_plug_list() since that uses local_irq_save()/restore() which means it can be called from contexts which cannot deal with enabling IRQs, and then your ->request_fn() goes and does that.

Now maybe blk_flush_plug_list() is overly paranoid and it could use local_irq_disable()/enable() instead, I don't know. But until it does, a request_fn() should never reenable IRQs.

Quoted 4 lines

I'm asking because rbd_request_fn() is probably not the only broken in this way code path. I poked around and found read_events() in aio.c, it seems to have been written with the "danger" assumption that I outlined above and there is even a comment to it.

Quoted 5 lines

I'm fairly sure there's more broken stuff, I didn't dare looking.

Quoted 1 line

Does that above make sense or am I missing something?

I think that's about it.

Thanks for clarifying things. CC'ing Kent to draw attention to read_events().

Ilya