Re: [-next] !irqd_can_balance() WARNINGs at irq_move_masked_irq()

From: Sergey Senozhatsky
Date: Sat Jun 20 2015 - 00:31:17 EST


On (06/19/15 14:21), Thomas Gleixner wrote:
[..]
> Can you please collect the output of /proc/timer_list for the previous
> patch and then replace the previous patch with the one below and
> gather all the data again?
>

attached.

-ss
Timer List Version: v0.8
HRTIMER_MAX_CLOCK_BASES: 4
now at 698220511384 nsecs

cpu: 0
clock 0:
.base: ffff880137c0f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137c0fc20>, tick_sched_timer, S:01
# expires at 698223263511-698223263511 nsecs [in 2752127 to 2752127 nsecs]
#1: <ffff88013155bdd0>, hrtimer_wakeup, S:01
# expires at 698225438024-698225488024 nsecs [in 4926640 to 4976640 nsecs]
#2: <ffff880137c0fde0>, watchdog_timer_fn, S:01
# expires at 700076666666-700076666666 nsecs [in 1856155282 to 1856155282 nsecs]
#3: <ffff880037959000>, timerfd_tmrproc, S:01
# expires at 734170666000-734170666000 nsecs [in 35950154616 to 35950154616 nsecs]
clock 1:
.base: ffff880137c0f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434770569648520050 nsecs
active timers:
#0: <ffff8800be844200>, timerfd_tmrproc, S:01
# expires at 9223372036854775807-9223372036854775807 nsecs [in 9223371338634264423 to 9223371338634264423 nsecs]
#1: <ffff880037959a00>, timerfd_tmrproc, S:01
# expires at 9223372036854775807-9223372036854775807 nsecs [in 9223371338634264423 to 9223371338634264423 nsecs]
clock 2:
.base: ffff880137c0f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137c0f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434770569648520050 nsecs
active timers:
.expires_next : 698223263511 nsecs
.hres_active : 1
.nr_events : 4403
.nr_retries : 1
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 698219930178 nsecs
.tick_stopped : 0
.idle_jiffies : 4295086762
.idle_calls : 23735
.idle_sleeps : 16673
.idle_entrytime : 698219983378 nsecs
.idle_waketime : 698219983378 nsecs
.idle_exittime : 698220081595 nsecs
.idle_sleeptime : 681209400800 nsecs
.iowait_sleeptime: 14185863103 nsecs
.last_jiffies : 4295086762
.next_timer : 698346596832
.idle_expires : 698346596832 nsecs
jiffies: 4295086763

cpu: 1
clock 0:
.base: ffff880137c8f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137c8fc20>, tick_sched_timer, S:01
# expires at 698286596838-698286596838 nsecs [in 66085454 to 66085454 nsecs]
#1: <ffff880132bab920>, hrtimer_wakeup, S:01
# expires at 699054012688-699055012683 nsecs [in 833501304 to 834501299 nsecs]
#2: <ffff880137c8fde0>, watchdog_timer_fn, S:01
# expires at 700076666666-700076666666 nsecs [in 1856155282 to 1856155282 nsecs]
#3: <ffff8800bec2feb0>, hrtimer_wakeup, S:01
# expires at 731392340674-731392390674 nsecs [in 33171829290 to 33171879290 nsecs]
clock 1:
.base: ffff880137c8f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434770569648520050 nsecs
active timers:
clock 2:
.base: ffff880137c8f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137c8f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434770569648520050 nsecs
active timers:
.expires_next : 698286596838 nsecs
.hres_active : 1
.nr_events : 18063
.nr_retries : 6
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 698056596861 nsecs
.tick_stopped : 1
.idle_jiffies : 4295086713
.idle_calls : 11644
.idle_sleeps : 6945
.idle_entrytime : 698054026984 nsecs
.idle_waketime : 698053973763 nsecs
.idle_exittime : 698053989802 nsecs
.idle_sleeptime : 689075624844 nsecs
.iowait_sleeptime: 5998615173 nsecs
.last_jiffies : 4295086713
.next_timer : 698286596838
.idle_expires : 698286596838 nsecs
jiffies: 4295086763

cpu: 2
clock 0:
.base: ffff880137d0f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137d0fc20>, tick_sched_timer, S:01
# expires at 698223263511-698223263511 nsecs [in 2752127 to 2752127 nsecs]
#1: <ffff88013329f920>, hrtimer_wakeup, S:01
# expires at 698868699222-698869359220 nsecs [in 648187838 to 648847836 nsecs]
#2: <ffff880137d0fde0>, watchdog_timer_fn, S:01
# expires at 700083333332-700083333332 nsecs [in 1862821948 to 1862821948 nsecs]
#3: <ffff8800be844400>, timerfd_tmrproc, S:01
# expires at 732420666000-732420666000 nsecs [in 34200154616 to 34200154616 nsecs]
#4: <ffff88013254fc00>, timerfd_tmrproc, S:01
# expires at 972670666000-972670666000 nsecs [in 274450154616 to 274450154616 nsecs]
clock 1:
.base: ffff880137d0f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434770569648520050 nsecs
active timers:
clock 2:
.base: ffff880137d0f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137d0f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434770569648520050 nsecs
active timers:
.expires_next : 698223263511 nsecs
.hres_active : 1
.nr_events : 3057
.nr_retries : 0
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 698209930179 nsecs
.tick_stopped : 0
.idle_jiffies : 4295086759
.idle_calls : 6987
.idle_sleeps : 2579
.idle_entrytime : 698220089947 nsecs
.idle_waketime : 698142802784 nsecs
.idle_exittime : 698208923781 nsecs
.idle_sleeptime : 691989011091 nsecs
.iowait_sleeptime: 5284181049 nsecs
.last_jiffies : 4295086763
.next_timer : 698223263511
.idle_expires : 698326596834 nsecs
jiffies: 4295086763

cpu: 3
clock 0:
.base: ffff880137d8f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137d8fde0>, watchdog_timer_fn, S:01
# expires at 700089999999-700089999999 nsecs [in 1869488615 to 1869488615 nsecs]
#1: <ffff880137d8fc20>, tick_sched_timer, S:01
# expires at 700133263320-700133263320 nsecs [in 1912751936 to 1912751936 nsecs]
#2: <ffff8800be843600>, timerfd_tmrproc, S:01
# expires at 714170666000-714170666000 nsecs [in 15950154616 to 15950154616 nsecs]
clock 1:
.base: ffff880137d8f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434770569648520050 nsecs
active timers:
#0: <ffff880037959200>, timerfd_tmrproc, S:01
# expires at 1434855594170666000-1434855594170666000 nsecs [in 1434854895950154616 to 1434854895950154616 nsecs]
clock 2:
.base: ffff880137d8f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137d8f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434770569648520050 nsecs
active timers:
.expires_next : 700089999999 nsecs
.hres_active : 1
.nr_events : 2550
.nr_retries : 0
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 698209930179 nsecs
.tick_stopped : 1
.idle_jiffies : 4295086759
.idle_calls : 5908
.idle_sleeps : 2584
.idle_entrytime : 698209599039 nsecs
.idle_waketime : 698208457079 nsecs
.idle_exittime : 698209316366 nsecs
.idle_sleeptime : 692416744779 nsecs
.iowait_sleeptime: 4996913408 nsecs
.last_jiffies : 4295086759
.next_timer : 700133263320
.idle_expires : 700133263320 nsecs
jiffies: 4295086763

Tick Device: mode: 1
Broadcast device
Clock Event Device: hpet
max_delta_ns: 149983013277
min_delta_ns: 13410
mult: 61496111
shift: 32
mode: 3
next_event: 698223263511 nsecs
set_next_event: hpet_legacy_next_event
set_mode: hpet_legacy_set_mode
event_handler: tick_handle_oneshot_broadcast
retries: 4

tick_broadcast_mask: e
tick_broadcast_oneshot_mask: e

Tick Device: mode: 1
Per CPU device: 0
Clock Event Device: hpet2
max_delta_ns: 149983013277
min_delta_ns: 13410
mult: 61496111
shift: 32
mode: 3
next_event: 698223263511 nsecs
set_next_event: hpet_msi_next_event
set_mode: hpet_msi_set_mode
event_handler: hrtimer_interrupt
retries: 10

Tick Device: mode: 1
Per CPU device: 1
Clock Event Device: lapic
max_delta_ns: 258347607028
min_delta_ns: 1805
mult: 35701403
shift: 32
mode: 1
next_event: 698286596838 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 43

Tick Device: mode: 1
Per CPU device: 2
Clock Event Device: lapic
max_delta_ns: 258347607028
min_delta_ns: 1805
mult: 35701403
shift: 32
mode: 1
next_event: 698223263511 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 8

Tick Device: mode: 1
Per CPU device: 3
Clock Event Device: lapic
max_delta_ns: 258347607028
min_delta_ns: 1805
mult: 35701403
shift: 32
mode: 1
next_event: 700089999999 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 26

Timer List Version: v0.8
HRTIMER_MAX_CLOCK_BASES: 4
now at 125702806237 nsecs

cpu: 0
clock 0:
.base: ffff880137c0f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137c0fc20>, tick_sched_timer, S:01
# expires at 125703320763-125703320763 nsecs [in 514526 to 514526 nsecs]
#1: <ffff8800baa97920>, hrtimer_wakeup, S:01
# expires at 125924908486-125925908481 nsecs [in 222102249 to 223102244 nsecs]
#2: <ffff8800be45f920>, hrtimer_wakeup, S:01
# expires at 126351772381-126352432379 nsecs [in 648966144 to 649626142 nsecs]
#3: <ffff880137c0fde0>, watchdog_timer_fn, S:01
# expires at 128076666666-128076666666 nsecs [in 2373860429 to 2373860429 nsecs]
#4: <ffff880037912c00>, timerfd_tmrproc, S:01
# expires at 174322638000-174322638000 nsecs [in 48619831763 to 48619831763 nsecs]
clock 1:
.base: ffff880137c0f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434773282081928390 nsecs
active timers:
#0: <ffff8800bea17e00>, timerfd_tmrproc, S:01
# expires at 9223372036854775807-9223372036854775807 nsecs [in 9223371911151969570 to 9223371911151969570 nsecs]
#1: <ffff880132969600>, timerfd_tmrproc, S:01
# expires at 9223372036854775807-9223372036854775807 nsecs [in 9223371911151969570 to 9223371911151969570 nsecs]
clock 2:
.base: ffff880137c0f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137c0f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434773282081928390 nsecs
active timers:
.expires_next : 125703320763 nsecs
.hres_active : 1
.nr_events : 2843
.nr_retries : 0
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 125703320763 nsecs
.tick_stopped : 0
.idle_jiffies : 4294915007
.idle_calls : 17636
.idle_sleeps : 10408
.idle_entrytime : 125702344163 nsecs
.idle_waketime : 125702344163 nsecs
.idle_exittime : 125702384582 nsecs
.idle_sleeptime : 113915144061 nsecs
.iowait_sleeptime: 9572532762 nsecs
.last_jiffies : 4294915007
.next_timer : 125786654088
.idle_expires : 125786654088 nsecs
jiffies: 4294915007

cpu: 1
clock 0:
.base: ffff880137c8f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137c8fc20>, tick_sched_timer, S:01
# expires at 126336654033-126336654033 nsecs [in 633847796 to 633847796 nsecs]
#1: <ffff880137c8fde0>, watchdog_timer_fn, S:01
# expires at 128076666666-128076666666 nsecs [in 2373860429 to 2373860429 nsecs]
#2: <ffff8800be473eb0>, hrtimer_wakeup, S:01
# expires at 179655212926-179655262926 nsecs [in 53952406689 to 53952456689 nsecs]
clock 1:
.base: ffff880137c8f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434773282081928390 nsecs
active timers:
#0: <ffff8800be93c000>, timerfd_tmrproc, S:01
# expires at 1434855594072638000-1434855594072638000 nsecs [in 1434855468369831763 to 1434855468369831763 nsecs]
clock 2:
.base: ffff880137c8f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137c8f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434773282081928390 nsecs
active timers:
.expires_next : 126336654033 nsecs
.hres_active : 1
.nr_events : 15852
.nr_retries : 8
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 125693320764 nsecs
.tick_stopped : 1
.idle_jiffies : 4294915004
.idle_calls : 7451
.idle_sleeps : 3081
.idle_entrytime : 125692765865 nsecs
.idle_waketime : 125419564269 nsecs
.idle_exittime : 125692657549 nsecs
.idle_sleeptime : 116640564313 nsecs
.iowait_sleeptime: 5727684794 nsecs
.last_jiffies : 4294915004
.next_timer : 126336654033
.idle_expires : 126336654033 nsecs
jiffies: 4294915007

cpu: 2
clock 0:
.base: ffff880137d0f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff88013298fdd0>, hrtimer_wakeup, S:01
# expires at 125708172241-125708222241 nsecs [in 5366004 to 5416004 nsecs]
#1: <ffff880137d0fde0>, watchdog_timer_fn, S:01
# expires at 128083333332-128083333332 nsecs [in 2380527095 to 2380527095 nsecs]
#2: <ffff880137d0fc20>, tick_sched_timer, S:01
# expires at 134516653215-134516653215 nsecs [in 8813846978 to 8813846978 nsecs]
#3: <ffff880037ab8600>, timerfd_tmrproc, S:01
# expires at 154072638000-154072638000 nsecs [in 28369831763 to 28369831763 nsecs]
#4: <ffff8801332ade00>, timerfd_tmrproc, S:01
# expires at 312572638000-312572638000 nsecs [in 186869831763 to 186869831763 nsecs]
clock 1:
.base: ffff880137d0f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434773282081928390 nsecs
active timers:
clock 2:
.base: ffff880137d0f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137d0f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434773282081928390 nsecs
active timers:
.expires_next : 125708222241 nsecs
.hres_active : 1
.nr_events : 1966
.nr_retries : 0
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 125693320764 nsecs
.tick_stopped : 1
.idle_jiffies : 4294915004
.idle_calls : 5371
.idle_sleeps : 1655
.idle_entrytime : 125692180494 nsecs
.idle_waketime : 125241152699 nsecs
.idle_exittime : 125692109739 nsecs
.idle_sleeptime : 119764838196 nsecs
.iowait_sleeptime: 5049374049 nsecs
.last_jiffies : 4294915004
.next_timer : 134516653215
.idle_expires : 134516653215 nsecs
jiffies: 4294915007

cpu: 3
clock 0:
.base: ffff880137d8f700
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff880137d8fc20>, tick_sched_timer, S:01
# expires at 125703320763-125703320763 nsecs [in 514526 to 514526 nsecs]
#1: <ffff880137d8fde0>, watchdog_timer_fn, S:01
# expires at 128089999999-128089999999 nsecs [in 2387193762 to 2387193762 nsecs]
#2: <ffff8801332ac600>, timerfd_tmrproc, S:01
# expires at 164072638000-164072638000 nsecs [in 38369831763 to 38369831763 nsecs]
clock 1:
.base: ffff880137d8f740
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1434773282081928390 nsecs
active timers:
clock 2:
.base: ffff880137d8f780
.index: 2
.resolution: 1 nsecs
.get_time: ktime_get_boottime
.offset: 0 nsecs
active timers:
clock 3:
.base: ffff880137d8f7c0
.index: 3
.resolution: 1 nsecs
.get_time: ktime_get_clocktai
.offset: 1434773282081928390 nsecs
active timers:
.expires_next : 125703320763 nsecs
.hres_active : 1
.nr_events : 2000
.nr_retries : 0
.nr_hangs : 0
.max_hang_time : 0
.nohz_mode : 2
.last_tick : 125693320764 nsecs
.tick_stopped : 0
.idle_jiffies : 4294915004
.idle_calls : 5851
.idle_sleeps : 2550
.idle_entrytime : 125700216671 nsecs
.idle_waketime : 125691472714 nsecs
.idle_exittime : 125691999648 nsecs
.idle_sleeptime : 120189745438 nsecs
.iowait_sleeptime: 4272319623 nsecs
.last_jiffies : 4294915007
.next_timer : 126316654035
.idle_expires : 126316654035 nsecs
jiffies: 4294915007

Tick Device: mode: 1
Broadcast device
Clock Event Device: hpet
max_delta_ns: 149983013277
min_delta_ns: 13410
mult: 61496111
shift: 32
mode: 3
next_event: 125703320763 nsecs
set_next_event: hpet_legacy_next_event
set_mode: hpet_legacy_set_mode
event_handler: tick_handle_oneshot_broadcast
retries: 1

tick_broadcast_mask: e
tick_broadcast_oneshot_mask: e

Tick Device: mode: 1
Per CPU device: 0
Clock Event Device: hpet2
max_delta_ns: 149983013277
min_delta_ns: 13410
mult: 61496111
shift: 32
mode: 3
next_event: 125703320763 nsecs
set_next_event: hpet_msi_next_event
set_mode: hpet_msi_set_mode
event_handler: hrtimer_interrupt
retries: 10

Tick Device: mode: 1
Per CPU device: 1
Clock Event Device: lapic
max_delta_ns: 258347918191
min_delta_ns: 1805
mult: 35701360
shift: 32
mode: 1
next_event: 126336654033 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 13

Tick Device: mode: 1
Per CPU device: 2
Clock Event Device: lapic
max_delta_ns: 258347918191
min_delta_ns: 1805
mult: 35701360
shift: 32
mode: 1
next_event: 125708222241 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 40

Tick Device: mode: 1
Per CPU device: 3
Clock Event Device: lapic
max_delta_ns: 258347918191
min_delta_ns: 1805
mult: 35701360
shift: 32
mode: 1
next_event: 125703320763 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
retries: 19