From: Mike Galbraith <efault@gmx.de>
To: Steven Rostedt <rostedt@goodmis.org>,
Sebastian Andrzej Siewior <bigeasy@linutronix.de>
Cc: Thomas Gleixner <tglx@linutronix.de>,
LKML <linux-kernel@vger.kernel.org>,
linux-rt-users <linux-rt-users@vger.kernel.org>
Subject: Re: [ANNOUNCE] v4.11.5-rt1
Date: Tue, 20 Jun 2017 09:45:06 +0200 [thread overview]
Message-ID: <1497944706.5454.7.camel@gmx.de> (raw)
In-Reply-To: <1497889784.15817.17.camel@gmx.de>
On Mon, 2017-06-19 at 18:29 +0200, Mike Galbraith wrote:
> On Mon, 2017-06-19 at 10:41 -0400, Steven Rostedt wrote:
> > On Mon, 19 Jun 2017 16:13:41 +0200
> > Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> >
> >
> > > > Hmm, it shouldn't affect futexes, as it's only called by rtmutex when
> > > > waiter->savestate is true. And that should always be false for futex.
> > >
> > > you still have sleeping locks like the hb-lock (which might matter in
> > > case the task blocks on the lock and does not continue for some reason).
> >
> > But then I'd expect this to be an issue with any spinlock in the kernel.
>
> Thing to do is set a trap for the bugger.
See ! and ?
vogelweide:~/:[1]# grep MIKE trace
MIKE 913.728104: start
MIKE futex_wait-7496 [031] ....... 913.729160: sched_process_fork: comm=futex_wait pid=7496 child_comm=futex_wait child_pid=7497
MIKE futex_wait-7496 [031] ....... 913.729253: sched_process_fork: comm=futex_wait pid=7496 child_comm=futex_wait child_pid=7499
MIKE futex_wait-7496 [031] ....... 913.729307: sched_process_fork: comm=futex_wait pid=7496 child_comm=futex_wait child_pid=7500
MIKE futex_wait-7496 [031] ....... 913.729348: sched_process_fork: comm=futex_wait pid=7496 child_comm=futex_wait child_pid=7501
MIKE futex_wait-7496 [031] d...2.. 913.729430: sched_switch: prev_comm=futex_wait prev_pid=7496 prev_prio=120 prev_state=S ==> next_comm=swapper/31 next_pid=0 next_prio=120
MIKE--futex_wait-7500 [005] d...2.. 920.040320: sched_switch: prev_comm=futex_wait prev_pid=7500 prev_prio=120 prev_state=S ==> next_comm=swapper/5 next_pid=0 next_prio=120
MIKE futex_wait-7497 [058] d...211 920.060009: sched_waking: comm=futex_wait pid=7501 prio=120 target_cpu=044
MIKE futex_wait-7497 [058] d...311 920.060012: sched_wake_idle_without_ipi: cpu=44
MIKE futex_wait-7497 [058] d...311 920.060012: sched_wakeup: comm=futex_wait pid=7501 prio=120 target_cpu=044
MIKE--futex_wait-7497 [058] d...2.. 920.060035: sched_switch: prev_comm=futex_wait prev_pid=7497 prev_prio=120 prev_state=S ==> next_comm=swapper/58 next_pid=0 next_prio=120
MIKE futex_wait-7499 [043] dN..411 920.060035: sched_wakeup: comm=ktimersoftd/43 pid=438 prio=0 target_cpu=043
MIKE! futex_wait-7499 [043] .N..111 920.060037: wake_up_lock_sleeper: futex_wait:7497 state:1 saved_state:0
MIKE! futex_wait-7499 [043] dN..211 920.060037: try_to_wake_up: futex_wait:7497 WF_LOCK_SLEEPER !(p->state:1 & state:2) bailing
MIKE 920.060037: futex_wait-7497 is never awakened again until ^C cleanup, 7499/7501 still standing
MIKE futex_wait-7499 [043] ....111 920.060066: wake_up_lock_sleeper: futex_wait:7501 state:2 saved_state:0
MIKE futex_wait-7499 [043] d...211 920.060066: try_to_wake_up: futex_wait:7501 WF_LOCK_SLEEPER !(p->state:0 & state:2) bailing
MIKE futex_wait-7499 [043] ....111 920.060606: wake_up_lock_sleeper: futex_wait:7501 state:2 saved_state:0
MIKE 920.355048: huh? wake_up_lock_sleeper sees state=2 but try_to_wake_up then sees state=0 and bails ?!?
MIKE futex_wait-7501 [044] ....111 920.355048: wake_up_lock_sleeper: futex_wait:7499 state:2 saved_state:0
MIKE futex_wait-7501 [044] d...211 920.355049: try_to_wake_up: futex_wait:7499 WF_LOCK_SLEEPER !(p->state:0 & state:2) bailing
MIKE futex_wait-7499 [048] d..h311 920.355060: sched_stat_runtime: comm=futex_wait pid=7499 runtime=168537 [ns] vruntime=4850005377 [ns]
MIKE futex_wait-7499 [048] d...311 920.355061: sched_waking: comm=ksoftirqd/48 pid=489 prio=120 target_cpu=048
MIKE futex_wait-7499 [048] d...411 920.355062: sched_stat_runtime: comm=futex_wait pid=7499 runtime=2972 [ns] vruntime=4850008349 [ns]
MIKE futex_wait-7499 [048] d.L.411 920.355063: sched_wakeup: comm=ksoftirqd/48 pid=489 prio=120 target_cpu=048
MIKE futex_wait-7499 [048] d.L.311 920.355064: sched_waking: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] dNL.411 920.355065: sched_wakeup: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] .NL.111 920.355066: wake_up_lock_sleeper: futex_wait:7501 state:0 saved_state:0
MIKE futex_wait-7499 [048] dNL.211 920.355067: try_to_wake_up: futex_wait:7501 WF_LOCK_SLEEPER !(p->state:0 & state:2) bailing
MIKE futex_wait-7499 [048] dNL.211 920.355067: sched_stat_runtime: comm=futex_wait pid=7499 runtime=2011 [ns] vruntime=4850010360 [ns]
MIKE futex_wait-7499 [048] d...211 920.355068: sched_switch: prev_comm=futex_wait prev_pid=7499 prev_prio=120 prev_state=R+ ==> next_comm=ktimersoftd/48 next_pid=488 next_prio=0
MIKE <...>-488 [048] d...2.. 920.355070: sched_switch: prev_comm=ktimersoftd/48 prev_pid=488 prev_prio=0 prev_state=S ==> next_comm=ksoftirqd/48 next_pid=489 next_prio=120
MIKE <...>-489 [048] d...2.. 920.355071: sched_stat_runtime: comm=ksoftirqd/48 pid=489 runtime=1925 [ns] vruntime=4838010274 [ns]
MIKE <...>-489 [048] d...2.. 920.355072: sched_switch: prev_comm=ksoftirqd/48 prev_pid=489 prev_prio=120 prev_state=S ==> next_comm=futex_wait next_pid=7499 next_prio=120
MIKE futex_wait-7501 [044] d...2.. 920.355072: sched_stat_runtime: comm=futex_wait pid=7501 runtime=32398 [ns] vruntime=6632181410 [ns]
MIKE--futex_wait-7501 [044] d...2.. 920.355074: sched_switch: prev_comm=futex_wait prev_pid=7501 prev_prio=120 prev_state=S ==> next_comm=swapper/44 next_pid=0 next_prio=120
MIKE 920.355074: 7499 is last man standing, but bored, just waking ktimersoftd
MIKE futex_wait-7499 [048] d..h1.. 920.356060: sched_stat_runtime: comm=futex_wait pid=7499 runtime=988793 [ns] vruntime=4850999153 [ns]
MIKE futex_wait-7499 [048] d...1.. 920.356061: sched_waking: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] dN..2.. 920.356063: sched_wakeup: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] dN..2.. 920.356063: sched_stat_runtime: comm=futex_wait pid=7499 runtime=1854 [ns] vruntime=4851001007 [ns]
MIKE futex_wait-7499 [048] d...2.. 920.356064: sched_switch: prev_comm=futex_wait prev_pid=7499 prev_prio=120 prev_state=R ==> next_comm=ktimersoftd/48 next_pid=488 next_prio=0
MIKE <...>-488 [048] d...2.. 920.356065: sched_switch: prev_comm=ktimersoftd/48 prev_pid=488 prev_prio=0 prev_state=S ==> next_comm=futex_wait next_pid=7499 next_prio=120
MIKE futex_wait-7499 [048] d..h1.. 920.384055: sched_stat_runtime: comm=futex_wait pid=7499 runtime=997267 [ns] vruntime=4878950744 [ns]
MIKE futex_wait-7499 [048] d...1.. 920.384056: sched_waking: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] dN..2.. 920.384056: sched_wakeup: comm=ktimersoftd/48 pid=488 prio=0 target_cpu=048
MIKE futex_wait-7499 [048] dN..2.. 920.384057: sched_stat_runtime: comm=futex_wait pid=7499 runtime=1161 [ns] vruntime=4878951905 [ns]
MIKE futex_wait-7499 [048] d...2.. 920.384057: sched_switch: prev_comm=futex_wait prev_pid=7499 prev_prio=120 prev_state=R ==> next_comm=ktimersoftd/48 next_pid=488 next_prio=0
MIKE <...>-488 [048] d...2.. 920.384058: sched_switch: prev_comm=ktimersoftd/48 prev_pid=488 prev_prio=0 prev_state=S ==> next_comm=futex_wait next_pid=7499 next_prio=120
MIKE futex_wait-7499 [048] d...2.. 920.384271: sched_stat_runtime: comm=futex_wait pid=7499 runtime=213243 [ns] vruntime=4879165148 [ns]
MIKE futex_wait-7499 [048] d...2.. 920.384271: sched_switch: prev_comm=futex_wait prev_pid=7499 prev_prio=120 prev_state=S ==> next_comm=swapper/48 next_pid=0 next_prio=120
MIKE 920.384271: we're stalled, all futex_wait have scheduled off, elide gap
MIKE 981.447247: nothing to see above /me poking ^C, elide to EOF
next prev parent reply other threads:[~2017-06-20 7:45 UTC|newest]
Thread overview: 32+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-06-16 10:56 [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior
2017-06-17 8:14 ` Mike Galbraith
2017-06-18 6:46 ` Mike Galbraith
2017-06-19 8:52 ` Sebastian Andrzej Siewior
2017-06-19 10:14 ` Mike Galbraith
2017-06-19 10:44 ` Sebastian Andrzej Siewior
2017-06-19 11:31 ` Mike Galbraith
2017-06-19 11:50 ` Sebastian Andrzej Siewior
2017-06-19 12:55 ` Mike Galbraith
2017-06-19 14:06 ` Sebastian Andrzej Siewior
2017-06-19 14:36 ` Mike Galbraith
2017-06-19 15:03 ` Sebastian Andrzej Siewior
2017-06-19 16:14 ` Mike Galbraith
2017-06-19 16:27 ` Sebastian Andrzej Siewior
2017-06-19 16:46 ` Mike Galbraith
2017-06-19 14:08 ` Steven Rostedt
2017-06-19 14:13 ` Sebastian Andrzej Siewior
2017-06-19 14:41 ` Steven Rostedt
2017-06-19 16:29 ` Mike Galbraith
2017-06-20 7:45 ` Mike Galbraith [this message]
2017-06-22 16:34 ` Sebastian Andrzej Siewior
2017-06-22 17:30 ` Mike Galbraith
2017-06-22 21:36 ` Thomas Gleixner
2017-06-23 2:00 ` Mike Galbraith
2017-06-23 12:48 ` Sebastian Andrzej Siewior
2017-06-18 17:01 ` [patch-rt] rtmutex: Fix lock stealing logic Mike Galbraith
2017-06-23 7:37 ` [patch-rt v2] " Mike Galbraith
2017-06-23 10:07 ` Mike Galbraith
2017-06-26 13:47 ` Sebastian Andrzej Siewior
2017-06-23 13:33 ` Steven Rostedt
2017-06-23 14:07 ` Mike Galbraith
2017-06-23 14:14 ` Steven Rostedt
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=1497944706.5454.7.camel@gmx.de \
--to=efault@gmx.de \
--cc=bigeasy@linutronix.de \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-rt-users@vger.kernel.org \
--cc=rostedt@goodmis.org \
--cc=tglx@linutronix.de \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.