Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1670383

Re: [ANNOUNCE] v4.11.5-rt1

From Mike Galbraith <efault@gmx.de>
Newsgroups linux.kernel
Subject Re: [ANNOUNCE] v4.11.5-rt1
Date 2017-06-20 09:50 +0200
Message-ID <tUm5b-5ID-17@gated-at.bofh.it> (permalink)
References (3 earlier) <tU1WN-1kn-17@gated-at.bofh.it> <tU5xo-3FC-35@gated-at.bofh.it> <tU5H4-3IR-13@gated-at.bofh.it> <tU6a7-3UW-33@gated-at.bofh.it> <tU7Sx-56t-1@gated-at.bofh.it>
Organization linux.* mail to news gateway

Show all headers | View raw

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

Back to linux.kernel | Previous | Next — Previous in thread | Next in thread | Find similar | Unroll thread

Thread

[ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-16 13:00 +0200
  Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-17 10:20 +0200
    Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-18 08:50 +0200
    Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 11:00 +0200
      Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 12:20 +0200
        Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 12:50 +0200
          Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 13:40 +0200
            Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 14:00 +0200
              Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 15:00 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 16:10 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 16:40 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 17:10 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 18:20 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 18:30 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 18:50 +0200
        Re: [ANNOUNCE] v4.11.5-rt1 Steven Rostedt <rostedt@goodmis.org> - 2017-06-19 16:10 +0200
          Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-19 16:20 +0200
            Re: [ANNOUNCE] v4.11.5-rt1 Steven Rostedt <rostedt@goodmis.org> - 2017-06-19 16:50 +0200
              Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-19 18:40 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-20 09:50 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-22 18:40 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-22 19:40 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Thomas Gleixner <tglx@linutronix.de> - 2017-06-22 23:40 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Mike Galbraith <efault@gmx.de> - 2017-06-23 04:10 +0200
                Re: [ANNOUNCE] v4.11.5-rt1 Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-23 14:50 +0200
  [patch-rt] rtmutex: Fix lock stealing logic Mike Galbraith <efault@gmx.de> - 2017-06-18 19:10 +0200
    [patch-rt v2] rtmutex: Fix lock stealing logic Mike Galbraith <efault@gmx.de> - 2017-06-23 09:40 +0200
      Re: [patch-rt v2] rtmutex: Fix lock stealing logic Mike Galbraith <efault@gmx.de> - 2017-06-23 12:10 +0200
        Re: [patch-rt v2] rtmutex: Fix lock stealing logic Sebastian Andrzej Siewior <bigeasy@linutronix.de> - 2017-06-26 15:50 +0200
      Re: [patch-rt v2] rtmutex: Fix lock stealing logic Steven Rostedt <rostedt@goodmis.org> - 2017-06-23 15:40 +0200
        Re: [patch-rt v2] rtmutex: Fix lock stealing logic Mike Galbraith <efault@gmx.de> - 2017-06-23 16:10 +0200
          Re: [patch-rt v2] rtmutex: Fix lock stealing logic Steven Rostedt <rostedt@goodmis.org> - 2017-06-23 16:20 +0200

csiph-web