Bug 14859 - System timer firing too much without cause
Summary: System timer firing too much without cause
Status: CLOSED INVALID
Alias: None
Product: Timers
Classification: Unclassified
Component: Other (show other bugs)
Hardware: x86-64 Linux
: P1 high
Assignee: john stultz
URL:
Keywords:
Depends on:
Blocks: 14885
  Show dependency tree
 
Reported: 2009-12-21 19:16 UTC by Shawn Starr
Modified: 2010-01-25 20:59 UTC (History)
2 users (show)

See Also:
Kernel Version: 2.6.33-rc1
Subsystem:
Regression: Yes
Bisected commit-id:


Attachments
dmesg (60.73 KB, text/plain)
2009-12-21 21:42 UTC, Shawn Starr
Details

Description Shawn Starr 2009-12-21 19:16:18 UTC
I am noticing a serious problem with the system timer flooding the bus with 
many interrupts for no reason. I have compiled the kernel with tickless 
enabled.

Can someone provide me some debugging to find out why this is happening?

As a comparsion my quad core box has no such issue: (Running 2.6.32-rc7) 
x86_64
  0:         42          4          1          1   IO-APIC-edge      timer

my Lenovo ThinkPad W500 (latest BIOS 3.11) laptop shows the system timer 
flooding the bus (Running 2.6.33-rc1) x86_64
 0:      66775      70429   IO-APIC-edge      timer <-- keeps rising, rapidly 

and  afew minutes ...

 0:     119849     124505   IO-APIC-edge      timer

Same for Rescheduling interrupts rising just as fast with the timer.

This does not look right, powertop shows:

40.0% ( 62.1)      <kernel IPI> : Rescheduling interrupts
22.9% ( 35.6)       <interrupt> : extra timer interrupt
17.0% ( 26.4)       <interrupt> : iwlagn

and another sample...

  54.6% (144.8)      <kernel IPI> : Rescheduling interrupts
  14.6% ( 38.8)       <interrupt> : extra timer interrupt
   8.5% ( 22.6)       <interrupt> : iwlagn
   6.5% ( 17.2)       <interrupt> : uhci_hcd:usb6, radeon@pci:0000:01:00.0
   6.5% ( 17.2)   USB device  6-1 : Microsoft Basic Optical Mouse v2.0  
(Microsoft )

There is no cause for the rescheduling interrupts and extra timer interrupt to 
wakeup the CPUs so much? Are there any timer issues?

cpuinfo:

processor       : 0                
vendor_id       : GenuineIntel     
cpu family      : 6                
model           : 23               
model name      : Intel(R) Core(TM)2 Duo CPU     T9400  @ 2.53GHz
stepping        : 10                                             
cpu MHz         : 800.000                                        
cache size      : 6144 KB                                        
physical id     : 0                                              
siblings        : 2                                              
core id         : 0                                              
cpu cores       : 2                                              
apicid          : 0                                              
initial apicid  : 0                                              
fpu             : yes                                            
fpu_exception   : yes                                            
cpuid level     : 13                                             
wp              : yes                                            
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca 
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm 
constant_tsc arch_perfmon pebs bts rep_good aperfmperf pni dtes64 monitor 
ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm sse4_1 xsave lahf_lm ida 
tpr_shadow vnmi flexpriority
bogomips        : 5054.98
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

Tried: Disabling tsc, hpet, msi, pat, even going as far as turning off Local APIC to fallback to 1 CPU. No difference, the system timer (irq 0) keeps rising w/o reason. Due to the this, using KMS shows noticeable stalls in system due to high timer firing.
Comment 1 john stultz 2009-12-21 21:30:14 UTC
Does disabling dynticks do anything? Using the boot time option of nohz=off, or disabling it in the kernel config?

Also, is this a new box that shows this issue with all recent kernels, or is this a regression in the kernel and the box use to work fine?

Also please attach a full dmesg and the output of /proc/timer_list.
Comment 2 Shawn Starr 2009-12-21 21:42:50 UTC
Created attachment 24249 [details]
dmesg

kernel bootup info
Comment 3 Shawn Starr 2009-12-21 21:43:39 UTC
Output of /proc/timer_list:

Right now, I have KDE running and such, but w/o all of that the timer still fires off too much:


Timer List Version: v0.5                                
HRTIMER_MAX_CLOCK_BASES: 2                              
now at 9220004049306 nsecs                              

cpu: 0
 clock 0:
  .base:       ffff88002820e9f8
  .index:      0               
  .resolution: 1 nsecs         
  .get_time:   ktime_get_real  
  .offset:     1261422556933110749 nsecs
active timers:                          
 clock 1:                               
  .base:       ffff88002820ea38         
  .index:      1                        
  .resolution: 1 nsecs                  
  .get_time:   ktime_get                
  .offset:     0 nsecs                  
active timers:                          
 #0: <ffff880128cf6a98>, posix_timer_fn, S:01, sys_timer_settime, VirtualBox/3580
 # expires at 9220005064135-9220005064135 nsecs [in 1014829 to 1014829 nsecs]    
 #1: <ffff88002820eae0>, tick_sched_timer, S:01, tick_nohz_restart_sched_tick, swapper/0
 # expires at 9220008000000-9220008000000 nsecs [in 3950694 to 3950694 nsecs]           
 #2: <ffff88011008daa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, VirtualBox/3571
 # expires at 9220011953554-9220012003554 nsecs [in 7904248 to 7954248 nsecs]           
 #3: <ffff88009fa71d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/3599    
 # expires at 9220026552927-9220026602927 nsecs [in 22503621 to 22553621 nsecs]         
 #4: <ffff8800972cfaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, devkit-disks-da/4203
 # expires at 9220067415779-9220069411777 nsecs [in 63366473 to 65362471 nsecs]              
 #5: <ffff880121101aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kwalletd/3235       
 # expires at 9220162597191-9220165218188 nsecs [in 158547885 to 161168882 nsecs]            
 #6: <ffff8801298cfaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_control/3461
 # expires at 9220195209504-9220205199501 nsecs [in 191160198 to 201150195 nsecs]            
 #7: <ffff880130549a68>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, pulseaudio/3270     
 # expires at 9220240136589-9220240136589 nsecs [in 236087283 to 236087283 nsecs]            
 #8: <ffff880138aeb988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, Xorg/3032           
 # expires at 9220248361914-9220248609911 nsecs [in 244312608 to 244560605 nsecs]            
 #9: <ffff880130613d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, VBoxSVC/3549             
 # expires at 9220301279537-9220301329537 nsecs [in 297230231 to 297280231 nsecs]            
 #10: <ffff880137e17988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, mysqld/2309        
 # expires at 9220465528677-9220466528674 nsecs [in 461479371 to 462479368 nsecs]            
 #11: <ffff88012985daa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, konsole/3556       
 # expires at 9220498561101-9220499059099 nsecs [in 494511795 to 495009793 nsecs]            
 #12: <ffff88013894f988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, mysqld/2308        
 # expires at 9220579721054-9220580721052 nsecs [in 575671748 to 576671746 nsecs]            
 #13: <ffff88010e0a5aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, VBoxSVC/3550       
 # expires at 9220702120789-9220704120787 nsecs [in 698071483 to 700071481 nsecs]            
 #14: <ffff8801298c1988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, mysqld/3474        
 # expires at 9220935420179-9220936420177 nsecs [in 931370873 to 932370871 nsecs]            
 #15: <ffff88013bb5faa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, hald-addon-stor/2769
 # expires at 9221067126132-9221069125129 nsecs [in 1063076826 to 1065075823 nsecs]           
 #16: <ffff8801389a3aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, NetworkManager/2826 
 # expires at 9221067861801-9221072858799 nsecs [in 1063812495 to 1068809493 nsecs]           
 #17: <ffff880139233988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, gpm/2157            
 # expires at 9221166690551-9221168690548 nsecs [in 1162641245 to 1164641242 nsecs]           
 #18: <ffff88008ecbdd48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/4212         
 # expires at 9221218873857-9221218923857 nsecs [in 1214824551 to 1214874551 nsecs]           
 #19: <ffff88011b9a5aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, xscreensaver/3259   
 # expires at 9221472007280-9221473480278 nsecs [in 1467957974 to 1469430972 nsecs]           
 #20: <ffff88013ba73988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, init/1              
 # expires at 9222405164108-9222410164105 nsecs [in 2401114802 to 2406114799 nsecs]           
 #21: <ffff880139e57aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, krunner/3249        
 # expires at 9222940761841-9222943702839 nsecs [in 2936712535 to 2939653533 nsecs]           
 #22: <ffff88013a645988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, ssh-agent/3104      
 # expires at 9223080074729-9223090074727 nsecs [in 3076025423 to 3086025421 nsecs]           
 #23: <ffff880124eebaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, plasma-desktop/3223 
 # expires at 9223104666857-9223107771855 nsecs [in 3100617551 to 3103722549 nsecs]           
 #24: <ffff880129a1baa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_maildis/3490
 # expires at 9223105065544-9223115064541 nsecs [in 3101016238 to 3111015235 nsecs]           
 #25: <ffff8801299fbaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_maildir/3488
 # expires at 9223105167023-9223115166021 nsecs [in 3101117717 to 3111116715 nsecs]           
 #26: <ffff880139d29aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_nepomuk/3491
 # expires at 9223212615524-9223216412522 nsecs [in 3208566218 to 3212363216 nsecs]           
 #27: <ffff8801387b3eb8>, hrtimer_wakeup, S:01, do_nanosleep, cron/2137                       
 # expires at 9224485829482-9224485879482 nsecs [in 4481780176 to 4481830176 nsecs]           
 #28: <ffff880128d1daa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kwalletmanager/3334 
 # expires at 9226546278385-9226556276382 nsecs [in 6542229079 to 6552227076 nsecs]           
 #29: <ffff8801304fbaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, knotify4/3354       
 # expires at 9228280037678-9228288883676 nsecs [in 8275988372 to 8284834370 nsecs]           
 #30: <ffff88012131baa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kaccess/3238        
 # expires at 9228815129134-9228825124132 nsecs [in 8811079828 to 8821074826 nsecs]           
 #31: <ffff880139f3daa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, klauncher/3163      
 # expires at 9229238173693-9229248163690 nsecs [in 9234124387 to 9244114384 nsecs]           
 #32: <ffff880130547aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, gconfd-2/3274       
 # expires at 9232893142823-9232923115820 nsecs [in 12889093517 to 12919066514 nsecs]         
 #33: <ffff88013853faa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, hald/2709           
 # expires at 9239067125119-9239090122117 nsecs [in 19063075813 to 19086072811 nsecs]         
 #34: <ffff880139c83aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, console-kit-dae/2903
 # expires at 9244392725576-9244422725574 nsecs [in 24388676270 to 24418676268 nsecs]         
 #35: <ffff8800970a9d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/4163         
 # expires at 9416462103207-9416462153207 nsecs [in 196458053901 to 196458103901 nsecs]       
 #36: <ffff88013a7bf988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, dhclient3/3277      
 # expires at 9420066891594-9420166891594 nsecs [in 200062842288 to 200162842288 nsecs]       
 #37: <ffff880097205d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/4158         
 # expires at 9476700133438-9476700183438 nsecs [in 256696084132 to 256696134132 nsecs]       
 #38: <ffff88010bc3faa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, VBoxXPCOMIPCD/3537  
 # expires at 9518847320237-9518947320237 nsecs [in 298843270931 to 298943270931 nsecs]       
 #39: <ffff880138ac6868>, it_real_fn, S:01, do_setitimer, exim4/2697                          
 # expires at 10827683578299-10827683578299 nsecs [in 1607679528993 to 1607679528993 nsecs]   
  .expires_next   : 9220005064135 nsecs                                                       
  .hres_active    : 1                                                                         
  .nr_events      : 3108036                                                                   
  .nr_retries     : 3511                                                                      
  .nr_hangs       : 0                                                                         
  .max_hang_time  : 0 nsecs                                                                   
  .nohz_mode      : 2                                                                         
  .idle_tick      : 9219116000000 nsecs                                                       
  .tick_stopped   : 0                                                                         
  .idle_jiffies   : 4297197074                                                                
  .idle_calls     : 6014739                                                                   
  .idle_sleeps    : 75859                                                                     
  .idle_entrytime : 9220000576117 nsecs                                                       
  .idle_waketime  : 9219033617655 nsecs                                                       
  .idle_exittime  : 9219114101652 nsecs                                                       
  .idle_sleeptime : 7878829517085 nsecs                                                       
  .last_jiffies   : 4297197296                                                                
  .next_jiffies   : 4297197296                                                                
  .idle_expires   : 9219124000000 nsecs                                                       
jiffies: 4297197297                                                                           

cpu: 1
 clock 0:
  .base:       ffff88002828e9f8
  .index:      0               
  .resolution: 1 nsecs         
  .get_time:   ktime_get_real  
  .offset:     1261422556933110749 nsecs
active timers:                          
 clock 1:                               
  .base:       ffff88002828ea38         
  .index:      1                        
  .resolution: 1 nsecs                  
  .get_time:   ktime_get                
  .offset:     0 nsecs                  
active timers:                          
 #0: <ffff880139e21a68>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, pulseaudio/3269
 # expires at 9220008329838-9220008329838 nsecs [in 4280532 to 4280532 nsecs]           
 #1: <ffff88002828eae0>, tick_sched_timer, S:01, tick_nohz_restart_sched_tick, swapper/0
 # expires at 9220008500000-9220008500000 nsecs [in 4450694 to 4450694 nsecs]           
 #2: <ffff8801306e9aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, firefox-bin/3596
 # expires at 9220101269009-9220101389007 nsecs [in 97219703 to 97339701 nsecs]          
 #3: <ffff88010bc27d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, VBoxSVC/3554         
 # expires at 9220224792903-9220224842903 nsecs [in 220743597 to 220793597 nsecs]        
 #4: <ffff8801211dfaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kmail/3458      
 # expires at 9220233305710-9220234123708 nsecs [in 229256404 to 230074402 nsecs]        
 #5: <ffff88011009dd48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/3598     
 # expires at 9220249120858-9220249170858 nsecs [in 245071552 to 245121552 nsecs]        
 #6: <ffff880124c61aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kded4/3165      
 # expires at 9220269758506-9220270613504 nsecs [in 265709200 to 266564198 nsecs]        
 #7: <ffff880129881aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadiserver/3463
 # expires at 9220317627659-9220327620656 nsecs [in 313578353 to 323571350 nsecs]          
 #8: <ffff8800b9463aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, VirtualBox/3593   
 # expires at 9220334274299-9220335202297 nsecs [in 330224993 to 331152991 nsecs]          
 #9: <ffff880129901988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, mysqld/3473       
 # expires at 9220992330835-9220993330833 nsecs [in 988281529 to 989281527 nsecs]          
 #10: <ffff880139fbdaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, ksmserver/3215   
 # expires at 9221551593315-9221553729313 nsecs [in 1547544009 to 1549680007 nsecs]        
 #11: <ffff880139e79d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, knotify4/3335         
 # expires at 9221783073067-9221783123067 nsecs [in 1779023761 to 1779073761 nsecs]        
 #12: <ffff88011bae3aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kmix/3261        
 # expires at 9222355210971-9222364524969 nsecs [in 2351161665 to 2360475663 nsecs]        
 #13: <ffff880124e37aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kglobalaccel/3219
 # expires at 9222625003648-9222628213646 nsecs [in 2620954342 to 2624164340 nsecs]        
 #14: <ffff88013052faa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kxkb/3246        
 # expires at 9222787432646-9222795810644 nsecs [in 2783383340 to 2791761338 nsecs]        
 #15: <ffff88009703fd48>, hrtimer_wakeup, S:01, futex_wait_queue_me, knotify4/4221         
 # expires at 9222919641438-9222919691438 nsecs [in 2915592132 to 2915642132 nsecs]        
 #16: <ffff880129a19aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_maildir/3489
 # expires at 9223211568015-9223221567013 nsecs [in 3207518709 to 3217517707 nsecs]           
 #17: <ffff8801299cfaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, akonadi_maildir/3487
 # expires at 9223217654792-9223227653790 nsecs [in 3213605486 to 3223604484 nsecs]           
 #18: <ffff880139e7baa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, knotify4/3222       
 # expires at 9224160196863-9224164927861 nsecs [in 4156147557 to 4160878555 nsecs]           
 #19: <ffff880095f35d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, rsyslogd/4150            
 # expires at 9226137850993-9226137900993 nsecs [in 6133801687 to 6133851687 nsecs]           
 #20: <ffff880124d17aa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, kwin/3217           
 # expires at 9232153416041-9232165569039 nsecs [in 12149366735 to 12161519733 nsecs]         
 #21: <ffff880095eddd48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/4195         
 # expires at 9274059808509-9274059858509 nsecs [in 54055759203 to 54055809203 nsecs]         
 #22: <ffff880095c71d48>, hrtimer_wakeup, S:01, futex_wait_queue_me, firefox-bin/4162         
 # expires at 9415683187277-9415683237277 nsecs [in 195679137971 to 195679187971 nsecs]       
 #23: <ffff8801387abeb8>, hrtimer_wakeup, S:01, do_nanosleep, atd/2109                        
 # expires at 10822081802523-10822081852523 nsecs [in 1602077753217 to 1602077803217 nsecs]   
 #24: <ffff88009739faa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, devkit-disks-da/4202
 # expires at 10996067228099-10996167228099 nsecs [in 1776063178793 to 1776163178793 nsecs]   
 #25: <ffff8801375efaa8>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, avahi-daemon/2448   
 # expires at 11376416212909-11376516212909 nsecs [in 2156412163603 to 2156512163603 nsecs]   
 #26: <ffff8801392fe868>, it_real_fn, S:01, do_setitimer, mysqld/3476                         
 # expires at 28902634533740-28902634533740 nsecs [in 19682630484434 to 19682630484434 nsecs] 
 #27: <ffff88013a6e7988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, rsyslogd/2062       
 # expires at 86420779237100-86420879237100 nsecs [in 77200775187794 to 77200875187794 nsecs] 
 #28: <ffff880137fdf988>, hrtimer_wakeup, S:01, schedule_hrtimeout_range, dhclient/3346       
 # expires at 86493066892424-86493166892424 nsecs [in 77273062843118 to 77273162843118 nsecs] 
  .expires_next   : 9220008329838 nsecs                                                       
  .hres_active    : 1                                                                         
  .nr_events      : 2889001                                                                   
  .nr_retries     : 4061                                                                      
  .nr_hangs       : 0                                                                         
  .max_hang_time  : 0 nsecs                                                                   
  .nohz_mode      : 2                                                                         
  .idle_tick      : 9219808500000 nsecs                                                       
  .tick_stopped   : 0
  .idle_jiffies   : 4297197247
  .idle_calls     : 5537250
  .idle_sleeps    : 84416
  .idle_entrytime : 9220002269340 nsecs
  .idle_waketime  : 9219812024164 nsecs
  .idle_exittime  : 9219812035897 nsecs
  .idle_sleeptime : 7022154076459 nsecs
  .last_jiffies   : 4297197296
  .next_jiffies   : 4297197297
  .idle_expires   : 9220048000000 nsecs
jiffies: 4297197297


Tick Device: mode:     1
Broadcast device
Clock Event Device: hpet
 max_delta_ns:   149983005959
 min_delta_ns:   5000
 mult:           61496114
 shift:          32
 mode:           3
 next_event:     9223372036854775807 nsecs
 set_next_event: hpet_legacy_next_event
 set_mode:       hpet_legacy_set_mode
 event_handler:  tick_handle_oneshot_broadcast
tick_broadcast_mask: 00000003
tick_broadcast_oneshot_mask: 00000000


Tick Device: mode:     1
Per CPU device: 0
Clock Event Device: lapic
 max_delta_ns:   504615477
 min_delta_ns:   1000
 mult:           71398509
 shift:          32
 mode:           3
 next_event:     9220005064135 nsecs
 set_next_event: lapic_next_event
 set_mode:       lapic_timer_setup
 event_handler:  hrtimer_interrupt

Tick Device: mode:     1
Per CPU device: 1
Clock Event Device: lapic
 max_delta_ns:   504615477
 min_delta_ns:   1000
 mult:           71398509
 shift:          32
 mode:           3
 next_event:     9220008329838 nsecs
 set_next_event: lapic_next_event
 set_mode:       lapic_timer_setup
 event_handler:  hrtimer_interrupt
Comment 4 Shawn Starr 2009-12-21 21:43:52 UTC
I am trying with nohz option now
Comment 5 Shawn Starr 2009-12-21 21:52:03 UTC
Turning off dynticks with kernel option stops the system timer from firing and the rescheduled interrupts is lower (i expect some interrupts may not always be processed in time)           

CPU0       CPU1
  0:         47          0   IO-APIC-edge      timer
  1:        589        608   IO-APIC-edge      i8042
  8:          0          1   IO-APIC-edge      rtc0
  9:        213        219   IO-APIC-fasteoi   acpi
 12:       1528       1524   IO-APIC-edge      i8042
 16:       1825       1770   IO-APIC-fasteoi   uhci_hcd:usb6, yenta
 17:          3          1   IO-APIC-fasteoi   firewire_ohci, uhci_hcd:usb7
 18:          0          0   IO-APIC-fasteoi   mmc0, uhci_hcd:usb8
 19:       6531       6434   IO-APIC-fasteoi   ehci_hcd:usb2
 20:          0          0   IO-APIC-fasteoi   uhci_hcd:usb3
 21:          0          0   IO-APIC-fasteoi   uhci_hcd:usb4
 22:          0          0   IO-APIC-fasteoi   uhci_hcd:usb5
 23:          0          0   IO-APIC-fasteoi   ehci_hcd:usb1
 29:         54         48   PCI-MSI-edge      eth0
 30:       4726       4835   PCI-MSI-edge      ahci
 31:        388        407   PCI-MSI-edge      HDA Intel
 32:       4275       4356   PCI-MSI-edge      iwlagn
 33:       3088       3074   PCI-MSI-edge      radeon
NMI:          0          0   Non-maskable interrupts
LOC:      56196      55154   Local timer interrupts
SPU:          0          0   Spurious interrupts
PMI:          0          0   Performance monitoring interrupts
PND:          0          0   Performance pending work
RES:       1998       1857   Rescheduling interrupts
CAL:         53         79   Function call interrupts
TLB:        752        614   TLB shootdowns
TRM:          0          0   Thermal event interrupts
THR:          0          0   Threshold APIC interrupts
MCE:          0          0   Machine check exceptions
MCP:          1          1   Machine check polls
ERR:          1
MIS:          0
Comment 6 Shawn Starr 2009-12-21 21:55:12 UTC
I still see IRQ stalls though when using keyboard and using something simple like glxgears with Radeon KMS.

           CPU0       CPU1
  0:         48          0   IO-APIC-edge      timer
  1:       1289       1297   IO-APIC-edge      i8042
  8:          0          1   IO-APIC-edge      rtc0
  9:        264        270   IO-APIC-fasteoi   acpi
 12:       1610       1604   IO-APIC-edge      i8042
 16:       3068       3033   IO-APIC-fasteoi   uhci_hcd:usb6, yenta
 17:          5          2   IO-APIC-fasteoi   firewire_ohci, uhci_hcd:usb7
 18:          0          0   IO-APIC-fasteoi   mmc0, uhci_hcd:usb8
 19:       6531       6434   IO-APIC-fasteoi   ehci_hcd:usb2
 20:          0          0   IO-APIC-fasteoi   uhci_hcd:usb3
 21:          0          0   IO-APIC-fasteoi   uhci_hcd:usb4
 22:          0          0   IO-APIC-fasteoi   uhci_hcd:usb5
 23:          0          0   IO-APIC-fasteoi   ehci_hcd:usb1
 29:        103         95   PCI-MSI-edge      eth0
 30:       4990       5086   PCI-MSI-edge      ahci
 31:        429        441   PCI-MSI-edge      HDA Intel
 32:       8134       8256   PCI-MSI-edge      iwlagn
 33:      13283      13231   PCI-MSI-edge      radeon
NMI:          0          0   Non-maskable interrupts
LOC:     106406     104467   Local timer interrupts
SPU:          0          0   Spurious interrupts
PMI:          0          0   Performance monitoring interrupts
PND:          0          0   Performance pending work
RES:       2582       2849   Rescheduling interrupts
CAL:         55         79   Function call interrupts
TLB:        807        658   TLB shootdowns
TRM:          0          0   Thermal event interrupts
THR:          0          0   Threshold APIC interrupts
MCE:          0          0   Machine check exceptions
MCP:          2          2   Machine check polls
ERR:          1
MIS:          0
Comment 7 Shawn Starr 2009-12-21 22:07:05 UTC
There still seems like a general irq problem on my system. It seems dynticks was magnifying the problem, but when off, I'm still seeing IRQ stalls.
Comment 8 Rafael J. Wysocki 2010-01-11 19:58:35 UTC
On Monday 11 January 2010, Shawn Starr wrote:
> On Sunday 10 January 2010 17:32:53 Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of recent regressions.
> > 
> > The following bug entry is on the current list of known regressions
> > from 2.6.32.  Please verify if it still should be listed and let me know
> > (either way).
> > 
> > 
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=14859
> > Subject             : System timer firing too much without cause
> > Submitter   : Shawn Starr <shawn.starr@rogers.com>
> > Date                : 2009-12-21 19:16 (21 days old)
> 
> Yes please keep on regression list.
Comment 9 Rafael J. Wysocki 2010-01-24 23:06:15 UTC
On Sunday 24 January 2010, Shawn Starr wrote:
> On Sunday 24 January 2010 17:04:33 Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of recent regressions.
> > 
> > The following bug entry is on the current list of known regressions
> > from 2.6.32.  Please verify if it still should be listed and let me know
> > (either way).
> > 
> > 
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=14859
> > Subject             : System timer firing too much without cause
> > Submitter   : Shawn Starr <shawn.starr@rogers.com>
> > Date                : 2009-12-21 19:16 (35 days old)
> 
> Continues with -rc5, I  really cannot use Dynamic ticks at all, it has to be 
> disabled.
> 
> I should probably mention this CPU info:
> 
> processor       : 0                                                         
> vendor_id       : GenuineIntel                                              
> cpu family      : 6                                                         
> model           : 23                                                        
> model name      : Intel(R) Core(TM)2 Duo CPU     T9400  @ 2.53GHz           
> stepping        : 10                                                        
> cpu MHz         : 800.000                                                   
> cache size      : 6144 KB                                                   
> physical id     : 0                                                         
> siblings        : 2                                                         
> core id         : 0                                                         
> cpu cores       : 2                                                         
> apicid          : 0                                                         
> initial apicid  : 0                                                         
> fpu             : yes                                                       
> fpu_exception   : yes                                                       
> cpuid level     : 13                                                        
> wp              : yes                                                       
> flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca
> cmov 
> pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm 
> constant_tsc arch_perfmon pebs bts rep_good aperfmperf pni dtes64 monitor 
> ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm sse4_1 xsave lahf_lm ida 
> tpr_shadow vnmi flexpriority                                                  
> bogomips        : 5053.40                                                     
> clflush size    : 64                                                          
> cache_alignment : 64                                                          
> address sizes   : 36 bits physical, 48 bits virtual                           
> power management:
Comment 10 Rafael J. Wysocki 2010-01-25 20:58:38 UTC
On Monday 25 January 2010, Shawn Starr wrote:
> On Monday 25 January 2010 12:20:38 Thomas Gleixner wrote:
> > On Mon, 25 Jan 2010, Shawn Starr wrote:
> > > On Monday 25 January 2010 05:35:50 Thomas Gleixner wrote:
> > > > Shawn, why can't you use dynamic ticks ? In the bugzilla I just see
> > > > that you worry about the IRQ0 interrupts (which are correct and
> > > > necessary when the system is in nohz mode) and the extra rescheduling
> > > > interrupts. How is the system misbehaving ?
> > > 
> > > Well, this all stems from trying to use Radeon KMS with IRQs
> > > on. Doing so I see system stalls and this is quite noticeable
> > > however, I am able to show this same stall on the quad core with the
> > 
> > x> same GPU.  Right now, it is unclear to me if there is a underlying
> > 
> > > irq issue or a bug in the radeon driver code that is showing these
> > > stalls. Since the radeon folks - at the moment - do not think it is
> > > a coding problem in their driver
> > 
> > Does the stall go away, when you disable dynticks ?
> > 
> 
> It does not, no. 
> 
> > > My impression was using dynamic ticks meant ticks were on demand and
> > 
> > Dynamic ticks are providing a continuous tick long as the machine is
> > busy. When a core becomes idle, we programm the timer to go off at the
> > next scheduled timer event, if the event is longer away than the next
> > tick. When the core goes out of idle (due to the timer or some other
> > event) we restart the tick.
> > 
> > So you see less timer interrupts (IRQ0 + Local timer interrupts)
> 
> With dynamic ticks on or off, LOC increments rapidly, but I assume that is 
> normal behavour.
> 
> So if none of this really is a kernel issue, I defer it to the radeon folks
> to 
> comment further.
> 
> Please remove from regression list, I'll close the original bug.

Note You need to log in before you can comment on or make changes to this bug.