* clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown
@ 2007-07-09 14:27 Alessandro Suardi
2007-07-10 7:29 ` Andrew Morton
0 siblings, 1 reply; 9+ messages in thread
From: Alessandro Suardi @ 2007-07-09 14:27 UTC (permalink / raw)
To: Linux Kernel Mailing List
My oldish AMD K7-800's clock began falling behind after
rebooting from 2.6.20 (and 109 days uptime with a spotless
clock) into 2.6.22; time lost is about four minutes each hour.
Turns out that 2.6.22 marks my TSC as unstable and starts
using PIT instead. Rebooting 2.6.22 with clocksource=tsc
gets the original stable system time back.
Not sure whether this is supposed to be the default way of
fixing the issue on older machines, though; if anyone sees
a problem with this, I'm up for providing more information.
[root@donkey ~]# cd /sys/devices/system/clocksource/clocksource0/
[root@donkey clocksource0]# cat available_clocksource
pit jiffies tsc
[root@donkey clocksource0]# cat current_clocksource
tsc
[root@donkey clocksource0]# uname -a
Linux donkey 2.6.22 #1 PREEMPT Mon Jul 9 13:26:38 CEST 2007 i686
athlon i386 GNU/Linux
[root@donkey clocksource0]# cat /proc/cpuinfo
processor : 0
vendor_id : AuthenticAMD
cpu family : 6
model : 4
model name : AMD Athlon(tm) Processor
stepping : 2
cpu MHz : 800.068
cache size : 256 KB
fdiv_bug : no
hlt_bug : no
f00f_bug : no
coma_bug : no
fpu : yes
fpu_exception : yes
cpuid level : 1
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 sep mtrr pge mca
cmov pat pse36 mmx fxsr syscall mmxext 3dnowext 3dnow
bogomips : 1603.17
clflush size : 32
thanks, ciao,
--alessandro
"Did you get married but forgot to get divorced ?"
(Danny and Dusty, 'The Good Old Days')
^ permalink raw reply [flat|nested] 9+ messages in thread* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-09 14:27 clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown Alessandro Suardi @ 2007-07-10 7:29 ` Andrew Morton 2007-07-10 17:28 ` john stultz 0 siblings, 1 reply; 9+ messages in thread From: Andrew Morton @ 2007-07-10 7:29 UTC (permalink / raw) To: Alessandro Suardi; +Cc: Linux Kernel Mailing List, Thomas Gleixner, john stultz On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > My oldish AMD K7-800's clock began falling behind after > rebooting from 2.6.20 (and 109 days uptime with a spotless > clock) into 2.6.22; time lost is about four minutes each hour. > > Turns out that 2.6.22 marks my TSC as unstable and starts > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > gets the original stable system time back. > > Not sure whether this is supposed to be the default way of > fixing the issue on older machines, though; if anyone sees > a problem with this, I'm up for providing more information. > > [root@donkey ~]# cd /sys/devices/system/clocksource/clocksource0/ > [root@donkey clocksource0]# cat available_clocksource > pit jiffies tsc > [root@donkey clocksource0]# cat current_clocksource > tsc > [root@donkey clocksource0]# uname -a > Linux donkey 2.6.22 #1 PREEMPT Mon Jul 9 13:26:38 CEST 2007 i686 > athlon i386 GNU/Linux > [root@donkey clocksource0]# cat /proc/cpuinfo > processor : 0 > vendor_id : AuthenticAMD > cpu family : 6 > model : 4 > model name : AMD Athlon(tm) Processor > stepping : 2 > cpu MHz : 800.068 > cache size : 256 KB > fdiv_bug : no > hlt_bug : no > f00f_bug : no > coma_bug : no > fpu : yes > fpu_exception : yes > cpuid level : 1 > wp : yes > flags : fpu vme de pse tsc msr pae mce cx8 sep mtrr pge mca > cmov pat pse36 mmx fxsr syscall mmxext 3dnowext 3dnow > bogomips : 1603.17 > clflush size : 32 > (cc's added) ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-10 7:29 ` Andrew Morton @ 2007-07-10 17:28 ` john stultz 2007-07-10 23:31 ` Alessandro Suardi 0 siblings, 1 reply; 9+ messages in thread From: john stultz @ 2007-07-10 17:28 UTC (permalink / raw) To: Andrew Morton Cc: Alessandro Suardi, Linux Kernel Mailing List, Thomas Gleixner On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > My oldish AMD K7-800's clock began falling behind after > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > gets the original stable system time back. Alessandro, Can you send me dmesg output for 2.6.20 and 2.6.22 (without clocksource=tsc)? thanks -john ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-10 17:28 ` john stultz @ 2007-07-10 23:31 ` Alessandro Suardi 2007-07-11 21:06 ` john stultz 0 siblings, 1 reply; 9+ messages in thread From: Alessandro Suardi @ 2007-07-10 23:31 UTC (permalink / raw) To: john stultz; +Cc: Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner [-- Attachment #1: Type: text/plain, Size: 1415 bytes --] On 7/10/07, john stultz <johnstul@us.ibm.com> wrote: > On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > > > My oldish AMD K7-800's clock began falling behind after > > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > > gets the original stable system time back. > > Alessandro, > Can you send me dmesg output for 2.6.20 and 2.6.22 (without > clocksource=tsc)? Actually, I lied a little bit - it was 2.6.22 with clock=tsc (which warns on boot about clock= being deprecated in favor of clocksource= ). I assume behavior is identical for now. Please find attached the dmesg ring (incomplete, as the kernel ring size I have seems too small to hold the full buffer, but it seems to have all the interesting stuff) of 2.6.20, 2.6.22, 2.6.22 with clock=tsc. If you need more info, just ask. I'll be out of the country from July 12 to the morning of July 16, and again from July 17 to July 20, so if you'd rather get at this later on, it's okay for me ;) thanks, ciao, --alessandro "Did you get married but forgot to get divorced ?" (Danny and Dusty, 'The Good Old Days') [-- Attachment #2: dmesg-2620 --] [-- Type: application/octet-stream, Size: 15595 bytes --] 000 (ACPI NVS) [ 0.000000] BIOS-e820: 00000000ffff0000 - 0000000100000000 (reserved) [ 0.000000] 511MB LOWMEM available. [ 0.000000] Entering add_active_range(0, 0, 131056) 0 entries of 256 used [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0 -> 4096 [ 0.000000] Normal 4096 -> 131056 [ 0.000000] early_node_map[1] active PFN ranges [ 0.000000] 0: 0 -> 131056 [ 0.000000] On node 0 totalpages: 131056 [ 0.000000] DMA zone: 32 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 [ 0.000000] Normal zone: 991 pages used for memmap [ 0.000000] Normal zone: 125969 pages, LIFO batch:31 [ 0.000000] DMI 2.3 present. [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dfff0000) [ 0.000000] Detected 800.068 MHz processor. [ 29.957749] Built 1 zonelists. Total pages: 130033 [ 29.957756] Kernel command line: ro root=/dev/hdb3 rhgb [ 29.958223] Enabling fast FPU save and restore... done. [ 29.958250] Initializing CPU#0 [ 29.958378] CPU 0 irqstacks, hard=c0443000 soft=c0442000 [ 29.958389] PID hash table entries: 2048 (order: 11, 8192 bytes) [ 29.960038] Console: colour VGA+ 80x25 [ 29.962894] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 29.963017] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 29.963101] ... MAX_LOCK_DEPTH: 30 [ 29.963183] ... MAX_LOCKDEP_KEYS: 2048 [ 29.963265] ... CLASSHASH_SIZE: 1024 [ 29.963347] ... MAX_LOCKDEP_ENTRIES: 8192 [ 29.963430] ... MAX_LOCKDEP_CHAINS: 16384 [ 29.963513] ... CHAINHASH_SIZE: 8192 [ 29.963595] memory used by lock dependency info: 1064 kB [ 29.963680] per task-struct memory footprint: 1200 bytes [ 29.964564] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) [ 29.965480] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) [ 30.008423] Memory: 512156k/524224k available (2162k kernel code, 11512k reserved, 1007k data, 140k init, 0k highmem) [ 30.008579] virtual kernel memory layout: [ 30.008583] fixmap : 0xffffd000 - 0xfffff000 ( 8 kB) [ 30.008587] vmalloc : 0xe0800000 - 0xffffb000 ( 503 MB) [ 30.008592] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB) [ 30.008596] .init : 0xc041a000 - 0xc043d000 ( 140 kB) [ 30.008601] .data : 0xc031cb3e - 0xc0418a0c (1007 kB) [ 30.008605] .text : 0xc0100000 - 0xc031cb3e (2162 kB) [ 30.009164] Checking if this processor honours the WP bit even in supervisor mode... Ok. [ 30.086302] Calibrating delay using timer specific routine.. 1603.22 BogoMIPS (lpj=3206441) [ 30.086694] Mount-cache hash table entries: 512 [ 30.087504] CPU: After generic identify, caps: 0183f9ff c1c7f9ff 00000000 00000000 00000000 00000000 00000000 [ 30.087535] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line) [ 30.087629] CPU: L2 Cache: 256K (64 bytes/line) [ 30.087713] CPU: After all inits, caps: 0183f9ff c1c7f9ff 00000000 00000420 00000000 00000000 00000000 [ 30.087737] Intel machine check architecture supported. [ 30.087824] Intel machine check reporting enabled on CPU#0. [ 30.087931] CPU: AMD Athlon(tm) Processor stepping 02 [ 30.088096] Checking 'hlt' instruction... OK. [ 30.104040] NET: Registered protocol family 16 [ 30.130073] PCI: PCI BIOS revision 2.10 entry at 0xfdb71, last bus=1 [ 30.130165] PCI: Using configuration type 1 [ 30.130249] Setting up standard PCI resources [ 30.145022] usbcore: registered new interface driver usbfs [ 30.145371] usbcore: registered new interface driver hub [ 30.145700] usbcore: registered new device driver usb [ 30.146072] PCI: Probing PCI hardware [ 30.146176] PCI: Probing PCI hardware (bus 00) [ 30.147319] PCI quirk: region 0800-08ff claimed by vt82c586 ACPI [ 30.147415] PCI quirk: region 0c00-0c7f claimed by vt82c686 HW-mon [ 30.147508] PCI quirk: region 0400-040f claimed by vt82c686 SMB [ 30.148665] Boot video device is 0000:01:00.0 [ 30.152058] PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0 [ 30.156544] PCI: Bridge: 0000:00:01.0 [ 30.156632] IO window: 8000-8fff [ 30.156722] MEM window: d7e00000-dfefffff [ 30.156812] PREFETCH window: c7c00000-d7cfffff [ 30.156927] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 30.157034] NET: Registered protocol family 2 [ 30.194465] IP route cache hash table entries: 4096 (order: 2, 16384 bytes) [ 30.195116] TCP established hash table entries: 16384 (order: 7, 655360 bytes) [ 30.201780] TCP bind hash table entries: 8192 (order: 6, 360448 bytes) [ 30.206281] TCP: Hash tables configured (established 16384 bind 8192) [ 30.206426] TCP reno registered [ 30.218887] Unpacking initramfs... done [ 30.353851] Freeing initrd memory: 1254k freed [ 30.355567] Machine check exception polling timer started. [ 30.355705] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac) [ 30.396907] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 30.398284] io scheduler noop registered [ 30.398410] io scheduler anticipatory registered (default) [ 30.398574] io scheduler deadline registered [ 30.398734] io scheduler cfq registered [ 30.400654] fb: 3Dfx Voodoo5 memory = 32768K [ 30.416243] Console: switching to colour frame buffer device 80x30 [ 30.448645] Real Time Clock Driver v1.12ac [ 30.455550] Linux agpgart interface v0.101 (c) Dave Jones [ 30.462746] agpgart: Detected VIA Twister-K/KT133x/KM133 chipset [ 30.477180] agpgart: AGP aperture is 64M @ 0xe0000000 [ 30.484396] [drm] Initialized drm 1.1.0 20060810 [ 30.491809] [drm] Initialized tdfx 1.0.0 20010216 on minor 0 [ 30.499425] PCI: setting IRQ 10 as level-triggered [ 30.499436] PCI: Found IRQ 10 for device 0000:00:0a.0 [ 30.506586] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 30.513547] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 30.520259] skge 1.9 addr 0xdfff8000 irq 10 chip Yukon rev 1 [ 30.527356] skge eth0: addr 00:30:bd:b8:31:55 [ 30.534497] 8139too Fast Ethernet driver 0.9.28 [ 30.540868] PCI: setting IRQ 12 as level-triggered [ 30.540877] PCI: Found IRQ 12 for device 0000:00:0f.0 [ 30.547164] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 30.553449] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 30.559573] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 30.566095] eth1: RealTek RTL8139 at 0xe480ce00, 00:c0:49:a7:33:fe, IRQ 12 [ 30.572172] eth1: Identified 8139 chip type 'RTL-8100B/8139D' [ 30.572203] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 30.578251] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 30.590504] VP_IDE: IDE controller at PCI slot 0000:00:07.1 [ 30.596920] VP_IDE: chipset revision 16 [ 30.603318] VP_IDE: not 100% native mode: will probe irqs later [ 30.609921] VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1 [ 30.622895] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 30.636330] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio [ 30.650206] Probing IDE interface ide0... [ 31.065731] hda: SAMSUNG SP1604N, ATA DISK drive [ 31.349533] hdb: Maxtor 6Y160P0, ATA DISK drive [ 31.409879] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 31.417392] Probing IDE interface ide1... [ 32.280918] hdc: TSSTcorpCD/DVDW TS-H552B, ATAPI CD/DVD-ROM drive [ 32.956635] ide1 at 0x170-0x177,0x376 on irq 15 [ 32.964997] hda: max request size: 512KiB [ 32.976792] hda: 312581808 sectors (160041 MB) w/2048KiB Cache, CHS=19457/255/63, UDMA(66) [ 32.992187] hda: cache flushes supported [ 33.000004] hda: hda1 hda2 hda3 hda4 < hda5 hda6 > [ 33.034947] hdb: max request size: 512KiB [ 33.043606] hdb: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(66) [ 33.059984] hdb: cache flushes supported [ 33.068031] hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 > [ 33.108855] hdc: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 33.124849] Uniform CD-ROM driver Revision: 3.20 [ 33.134549] usbmon: debugfs is not available [ 33.142599] usbcore: registered new interface driver usbhid [ 33.150399] drivers/usb/input/hid-core.c: v2.6:USB HID core driver [ 33.408135] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 33.416465] mice: PS/2 mouse device common for all mice [ 33.424304] EDAC MC: Ver: 2.0.1 Feb 5 2007 [ 33.432351] Advanced Linux Sound Architecture Driver Version 1.0.14rc1 (Tue Jan 09 09:56:17 2007 UTC). [ 33.448594] PCI: Found IRQ 10 for device 0000:00:07.5 [ 33.456397] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 33.464124] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 33.471656] PCI: Setting latency timer of device 0000:00:07.5 to 64 [ 33.986970] ALSA device list: [ 33.994340] #0: VIA 82C686A/B rev20 with AD1881A at 0xdc00, irq 10 [ 34.001983] TCP cubic registered [ 34.009184] NET: Registered protocol family 1 [ 34.016443] NET: Registered protocol family 17 [ 34.023649] Using IPI Shortcut mode [ 34.031116] Freeing unused kernel memory: 140k freed [ 34.038017] Time: tsc clocksource has been installed. [ 34.044955] Write protecting the kernel read-only data: 814k [ 34.398856] USB Universal Host Controller Interface driver v3.0 [ 34.405073] PCI: Found IRQ 12 for device 0000:00:07.2 [ 34.411021] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 34.416769] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.422386] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.427562] uhci_hcd 0000:00:07.2: UHCI Host Controller [ 34.433261] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 [ 34.444055] uhci_hcd 0000:00:07.2: irq 12, io base 0x0000cc00 [ 34.450469] usb usb1: configuration #1 chosen from 1 choice [ 34.456253] hub 1-0:1.0: USB hub found [ 34.461829] hub 1-0:1.0: 2 ports detected [ 34.571809] PCI: Found IRQ 12 for device 0000:00:07.3 [ 34.577564] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 34.583248] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.588726] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.593975] uhci_hcd 0000:00:07.3: UHCI Host Controller [ 34.599324] uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 [ 34.609874] uhci_hcd 0000:00:07.3: irq 12, io base 0x0000d000 [ 34.616253] usb usb2: configuration #1 chosen from 1 choice [ 34.622405] hub 2-0:1.0: USB hub found [ 34.628423] hub 2-0:1.0: 2 ports detected [ 34.735550] PCI: setting IRQ 9 as level-triggered [ 34.735560] PCI: Found IRQ 9 for device 0000:00:09.0 [ 34.741709] uhci_hcd 0000:00:09.0: UHCI Host Controller [ 34.747830] uhci_hcd 0000:00:09.0: new USB bus registered, assigned bus number 3 [ 34.759725] uhci_hcd 0000:00:09.0: irq 9, io base 0x0000c400 [ 34.766759] usb usb3: configuration #1 chosen from 1 choice [ 34.773605] hub 3-0:1.0: USB hub found [ 34.780189] hub 3-0:1.0: 2 ports detected [ 34.887434] PCI: Found IRQ 10 for device 0000:00:09.1 [ 34.893823] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 34.900044] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 34.906048] uhci_hcd 0000:00:09.1: UHCI Host Controller [ 34.912182] uhci_hcd 0000:00:09.1: new USB bus registered, assigned bus number 4 [ 34.924428] uhci_hcd 0000:00:09.1: irq 10, io base 0x0000c800 [ 34.931589] usb usb4: configuration #1 chosen from 1 choice [ 34.938463] hub 4-0:1.0: USB hub found [ 34.945287] hub 4-0:1.0: 2 ports detected [ 35.062964] usb 1-2: new low speed USB device using uhci_hcd and address 2 [ 35.072775] PCI: Found IRQ 12 for device 0000:00:09.2 [ 35.079678] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 35.086421] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.092872] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.099259] ehci_hcd 0000:00:09.2: EHCI Host Controller [ 35.105821] ehci_hcd 0000:00:09.2: new USB bus registered, assigned bus number 5 [ 35.118672] ehci_hcd 0000:00:09.2: irq 12, io mem 0xdfffff00 [ 35.125176] ehci_hcd 0000:00:09.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 35.138490] usb usb5: configuration #1 chosen from 1 choice [ 35.145277] hub 5-0:1.0: USB hub found [ 35.151947] hub 5-0:1.0: 4 ports detected [ 35.288432] usb 1-2: configuration #1 chosen from 1 choice [ 35.318403] input: 4D Mouse USB Mouse as /class/input/input0 [ 35.325687] input: USB HID v1.00 Mouse [4D Mouse USB Mouse] on usb-0000:00:07.2-2 [ 35.748349] kjournald starting. Commit interval 5 seconds [ 35.755389] EXT3-fs: mounted filesystem with ordered data mode. [ 36.358014] usb 5-3: new high speed USB device using ehci_hcd and address 2 [ 36.495248] usb 5-3: configuration #1 chosen from 1 choice [ 43.771450] SCSI subsystem initialized [ 43.963102] parport_pc: VIA 686A/8231 detected [ 43.963115] parport_pc: probing current configuration [ 43.963154] parport_pc: Current parallel port base: 0x378 [ 43.963633] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP(,...)] [ 43.963761] parport_pc: VIA parallel port: io=0x378, irq=7 [ 44.340323] Initializing USB Mass Storage driver... [ 44.340994] scsi0 : SCSI emulation for USB Mass Storage devices [ 44.341213] usb-storage: device found at 2 [ 44.341221] usb-storage: waiting for device to settle before scanning [ 44.341266] usbcore: registered new interface driver usb-storage [ 44.341279] USB Mass Storage support registered. [ 47.390327] Floppy drive(s): fd0 is 1.44M [ 47.410373] FDC 0 is a post-1991 82077 [ 49.338707] scsi 0:0:0:0: Direct-Access ST325082 3A PQ: 0 ANSI: 0 [ 49.341619] usb-storage: device scan complete [ 49.465082] SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB) [ 49.466657] sda: Write Protect is off [ 49.466668] sda: Mode Sense: 33 00 00 00 [ 49.466675] sda: assuming drive cache: write through [ 49.467851] SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB) [ 49.468848] sda: Write Protect is off [ 49.468858] sda: Mode Sense: 33 00 00 00 [ 49.468865] sda: assuming drive cache: write through [ 49.468875] sda: sda1 [ 49.489137] sd 0:0:0:0: Attached scsi disk sda [ 51.041463] EXT3 FS on hdb3, internal journal [ 51.241750] kjournald starting. Commit interval 5 seconds [ 51.242013] EXT3 FS on hda2, internal journal [ 51.242042] EXT3-fs: mounted filesystem with ordered data mode. [ 51.267569] kjournald starting. Commit interval 5 seconds [ 51.267971] EXT3 FS on hdb1, internal journal [ 51.268001] EXT3-fs: mounted filesystem with ordered data mode. [ 51.296138] kjournald starting. Commit interval 5 seconds [ 51.296581] EXT3 FS on hda3, internal journal [ 51.296611] EXT3-fs: mounted filesystem with ordered data mode. [ 51.324809] kjournald starting. Commit interval 5 seconds [ 51.325316] EXT3 FS on hda6, internal journal [ 51.325346] EXT3-fs: mounted filesystem with ordered data mode. [ 51.344713] kjournald starting. Commit interval 5 seconds [ 51.345304] EXT3 FS on hdb2, internal journal [ 51.345334] EXT3-fs: mounted filesystem with ordered data mode. [ 51.372807] kjournald starting. Commit interval 5 seconds [ 51.373209] EXT3 FS on hdb5, internal journal [ 51.373262] EXT3-fs: mounted filesystem with ordered data mode. [ 51.419511] kjournald starting. Commit interval 5 seconds [ 51.420532] EXT3 FS on sda1, internal journal [ 51.420561] EXT3-fs: mounted filesystem with ordered data mode. [ 52.201798] Adding 248968k swap on /dev/hda5. Priority:-1 extents:1 across:248968k [ 52.223187] Adding 240932k swap on /dev/hdb6. Priority:-2 extents:1 across:240932k [-- Attachment #3: dmesg-2622 --] [-- Type: application/octet-stream, Size: 15601 bytes --] ctive PFN ranges [ 0.000000] 0: 0 -> 131056 [ 0.000000] On node 0 totalpages: 131056 [ 0.000000] DMA zone: 32 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 [ 0.000000] Normal zone: 991 pages used for memmap [ 0.000000] Normal zone: 125969 pages, LIFO batch:31 [ 0.000000] DMI 2.3 present. [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dfff0000) [ 0.000000] Built 1 zonelists. Total pages: 130033 [ 0.000000] Kernel command line: ro root=/dev/hdb3 rhgb [ 0.000000] Enabling fast FPU save and restore... done. [ 0.000000] Initializing CPU#0 [ 0.000000] CPU 0 irqstacks, hard=c045f000 soft=c045e000 [ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes) [ 0.000000] Detected 800.073 MHz processor. [ 30.463913] Console: colour VGA+ 80x25 [ 30.465596] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 30.465721] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 30.465803] ... MAX_LOCK_DEPTH: 30 [ 30.465885] ... MAX_LOCKDEP_KEYS: 2048 [ 30.465967] ... CLASSHASH_SIZE: 1024 [ 30.466049] ... MAX_LOCKDEP_ENTRIES: 8192 [ 30.466131] ... MAX_LOCKDEP_CHAINS: 16384 [ 30.466213] ... CHAINHASH_SIZE: 8192 [ 30.466296] memory used by lock dependency info: 992 kB [ 30.466381] per task-struct memory footprint: 1200 bytes [ 30.467274] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) [ 30.468049] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) [ 30.509971] Memory: 512104k/524224k available (2217k kernel code, 11564k reserved, 1050k data, 152k init, 0k highmem) [ 30.510125] virtual kernel memory layout: [ 30.510129] fixmap : 0xffffd000 - 0xfffff000 ( 8 kB) [ 30.510133] vmalloc : 0xe0800000 - 0xffffb000 ( 503 MB) [ 30.510137] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB) [ 30.510141] .init : 0xc0433000 - 0xc0459000 ( 152 kB) [ 30.510145] .data : 0xc032a68a - 0xc043125c (1050 kB) [ 30.510149] .text : 0xc0100000 - 0xc032a68a (2217 kB) [ 30.510711] Checking if this processor honours the WP bit even in supervisor mode... Ok. [ 30.591531] Calibrating delay using timer specific routine.. 1603.21 BogoMIPS (lpj=3206437) [ 30.591912] Mount-cache hash table entries: 512 [ 30.592737] CPU: After generic identify, caps: 0183f9ff c1c7f9ff 00000000 00000000 00000000 00000000 00000000 [ 30.592764] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line) [ 30.592858] CPU: L2 Cache: 256K (64 bytes/line) [ 30.592942] CPU: After all inits, caps: 0183f9ff c1c7f9ff 00000000 00000420 00000000 00000000 00000000 [ 30.592965] Intel machine check architecture supported. [ 30.593051] Intel machine check reporting enabled on CPU#0. [ 30.593143] Compat vDSO mapped to ffffe000. [ 30.593245] CPU: AMD Athlon(tm) Processor stepping 02 [ 30.593408] Checking 'hlt' instruction... OK. [ 30.608662] NET: Registered protocol family 16 [ 30.634666] PCI: PCI BIOS revision 2.10 entry at 0xfdb71, last bus=1 [ 30.634759] PCI: Using configuration type 1 [ 30.634842] Setting up standard PCI resources [ 30.649350] usbcore: registered new interface driver usbfs [ 30.649682] usbcore: registered new interface driver hub [ 30.650011] usbcore: registered new device driver usb [ 30.650373] PCI: Probing PCI hardware [ 30.650492] PCI: Probing PCI hardware (bus 00) [ 30.651636] PCI quirk: region 0800-08ff claimed by vt82c586 ACPI [ 30.651732] PCI quirk: region 0c00-0c7f claimed by vt82c686 HW-mon [ 30.651826] PCI quirk: region 0400-040f claimed by vt82c686 SMB [ 30.656574] PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0 [ 30.659486] Time: tsc clocksource has been installed. [ 30.661490] PCI: Bridge: 0000:00:01.0 [ 30.661578] IO window: 8000-8fff [ 30.661668] MEM window: d7e00000-dfefffff [ 30.661757] PREFETCH window: c7c00000-d7cfffff [ 30.661872] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 30.661958] NET: Registered protocol family 2 [ 30.699607] IP route cache hash table entries: 4096 (order: 2, 16384 bytes) [ 30.700115] TCP established hash table entries: 16384 (order: 7, 720896 bytes) [ 30.707071] TCP bind hash table entries: 16384 (order: 7, 720896 bytes) [ 30.714990] TCP: Hash tables configured (established 16384 bind 16384) [ 30.715138] TCP reno registered [ 30.724125] Unpacking initramfs... done [ 30.862992] Freeing initrd memory: 1262k freed [ 30.864391] Machine check exception polling timer started. [ 30.864531] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac) [ 30.957878] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 30.959149] io scheduler noop registered [ 30.959237] io scheduler anticipatory registered (default) [ 30.959376] io scheduler deadline registered [ 30.959490] io scheduler cfq registered [ 30.959596] PCI: VIA PCI bridge detected. Disabling DAC. [ 30.959829] Boot video device is 0000:01:00.0 [ 30.961277] fb: 3Dfx Voodoo5 memory = 32768K [ 30.976975] Console: switching to colour frame buffer device 80x30 [ 31.010524] Real Time Clock Driver v1.12ac [ 31.017494] Linux agpgart interface v0.102 (c) Dave Jones [ 31.024799] agpgart: Detected VIA Twister-K/KT133x/KM133 chipset [ 31.039449] agpgart: AGP aperture is 64M @ 0xe0000000 [ 31.046863] [drm] Initialized drm 1.1.0 20060810 [ 31.054471] [drm] Initialized tdfx 1.0.0 20010216 on minor 0 [ 31.062323] PCI: setting IRQ 10 as level-triggered [ 31.062333] PCI: Found IRQ 10 for device 0000:00:0a.0 [ 31.069525] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 31.076498] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 31.083179] skge 1.11 addr 0xdfff8000 irq 10 chip Yukon rev 1 [ 31.090415] skge eth0: addr 00:30:bd:b8:31:55 [ 31.097586] 8139too Fast Ethernet driver 0.9.28 [ 31.104004] PCI: setting IRQ 12 as level-triggered [ 31.104014] PCI: Found IRQ 12 for device 0000:00:0f.0 [ 31.110485] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 31.116922] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 31.123146] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 31.129762] eth1: RealTek RTL8139 at 0xe480ce00, 00:c0:49:a7:33:fe, IRQ 12 [ 31.135850] eth1: Identified 8139 chip type 'RTL-8100B/8139D' [ 31.135916] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 31.142019] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 31.154653] VP_IDE: IDE controller at PCI slot 0000:00:07.1 [ 31.161317] VP_IDE: chipset revision 16 [ 31.167824] VP_IDE: not 100% native mode: will probe irqs later [ 31.174484] VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1 [ 31.187556] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 31.201099] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio [ 31.215120] Probing IDE interface ide0... [ 31.630920] hda: SAMSUNG SP1604N, ATA DISK drive [ 31.914722] hdb: Maxtor 6Y160P0, ATA DISK drive [ 31.975072] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 31.982739] Probing IDE interface ide1... [ 32.846085] hdc: TSSTcorpCD/DVDW TS-H552B, ATAPI CD/DVD-ROM drive [ 33.521831] ide1 at 0x170-0x177,0x376 on irq 15 [ 33.530285] hda: max request size: 512KiB [ 33.542071] hda: 312581808 sectors (160041 MB) w/2048KiB Cache, CHS=19457/255/63, UDMA(66) [ 33.557513] hda: cache flushes supported [ 33.565318] hda: hda1 hda2 hda3 hda4 < hda5 hda6 > [ 33.598146] hdb: max request size: 512KiB [ 33.606823] hdb: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(66) [ 33.623242] hdb: cache flushes supported [ 33.631282] hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 > [ 33.672563] hdc: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 33.688525] Uniform CD-ROM driver Revision: 3.20 [ 33.698209] usbmon: debugfs is not available [ 33.957334] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 33.965881] mice: PS/2 mouse device common for all mice [ 33.973883] EDAC MC: Ver: 2.0.1 Jul 9 2007 [ 33.982103] usbcore: registered new interface driver usbhid [ 33.989621] drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver [ 33.997161] Advanced Linux Sound Architecture Driver Version 1.0.14 (Thu May 31 09:03:25 2007 UTC). [ 34.013303] PCI: Found IRQ 10 for device 0000:00:07.5 [ 34.021059] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 34.028670] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 34.036161] PCI: Setting latency timer of device 0000:00:07.5 to 64 [ 34.552222] ALSA device list: [ 34.559535] #0: VIA 82C686A/B rev20 with AD1881A at 0xdc00, irq 10 [ 34.567143] TCP cubic registered [ 34.574283] NET: Registered protocol family 1 [ 34.581481] NET: Registered protocol family 17 [ 34.588596] Using IPI Shortcut mode [ 34.596309] Freeing unused kernel memory: 152k freed [ 34.603359] Write protecting the kernel text: 2220k [ 34.610076] Write protecting the kernel read-only data: 884k [ 34.964089] USB Universal Host Controller Interface driver v3.0 [ 34.970229] PCI: Found IRQ 12 for device 0000:00:07.2 [ 34.976030] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 34.981859] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.987098] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.992101] uhci_hcd 0000:00:07.2: UHCI Host Controller [ 34.997725] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 [ 35.008235] uhci_hcd 0000:00:07.2: irq 12, io base 0x0000cc00 [ 35.014563] usb usb1: configuration #1 chosen from 1 choice [ 35.020204] hub 1-0:1.0: USB hub found [ 35.025654] hub 1-0:1.0: 2 ports detected [ 35.132892] PCI: Found IRQ 12 for device 0000:00:07.3 [ 35.138512] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.144056] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 35.149385] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.154641] uhci_hcd 0000:00:07.3: UHCI Host Controller [ 35.159998] uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 [ 35.170588] uhci_hcd 0000:00:07.3: irq 12, io base 0x0000d000 [ 35.177025] usb usb2: configuration #1 chosen from 1 choice [ 35.183154] hub 2-0:1.0: USB hub found [ 35.189148] hub 2-0:1.0: 2 ports detected [ 35.296676] PCI: setting IRQ 9 as level-triggered [ 35.296686] PCI: Found IRQ 9 for device 0000:00:09.0 [ 35.302841] uhci_hcd 0000:00:09.0: UHCI Host Controller [ 35.309005] uhci_hcd 0000:00:09.0: new USB bus registered, assigned bus number 3 [ 35.320930] uhci_hcd 0000:00:09.0: irq 9, io base 0x0000c400 [ 35.328026] usb usb3: configuration #1 chosen from 1 choice [ 35.334890] hub 3-0:1.0: USB hub found [ 35.341571] hub 3-0:1.0: 2 ports detected [ 35.448559] PCI: Found IRQ 10 for device 0000:00:09.1 [ 35.454960] Clocksource tsc unstable (delta = 64005428 ns) [ 35.461341] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 35.467627] Time: pit clocksource has been installed. [ 35.473931] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 35.480495] uhci_hcd 0000:00:09.1: UHCI Host Controller [ 35.487126] uhci_hcd 0000:00:09.1: new USB bus registered, assigned bus number 4 [ 35.500280] uhci_hcd 0000:00:09.1: irq 10, io base 0x0000c800 [ 35.508119] usb usb4: configuration #1 chosen from 1 choice [ 35.515476] hub 4-0:1.0: USB hub found [ 35.522609] hub 4-0:1.0: 2 ports detected [ 35.616108] usb 1-2: new low speed USB device using uhci_hcd and address 2 [ 35.643519] PCI: Found IRQ 12 for device 0000:00:09.2 [ 35.650694] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 35.657838] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.664827] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.671617] ehci_hcd 0000:00:09.2: EHCI Host Controller [ 35.678557] ehci_hcd 0000:00:09.2: new USB bus registered, assigned bus number 5 [ 35.691694] ehci_hcd 0000:00:09.2: irq 12, io mem 0xdfffff00 [ 35.698434] ehci_hcd 0000:00:09.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 35.712575] usb usb5: configuration #1 chosen from 1 choice [ 35.719843] hub 5-0:1.0: USB hub found [ 35.726877] hub 5-0:1.0: 4 ports detected [ 35.841477] usb 1-2: configuration #1 chosen from 1 choice [ 35.871771] input: 4D Mouse USB Mouse as /class/input/input0 [ 35.879156] input: USB HID v1.00 Mouse [4D Mouse USB Mouse] on usb-0000:00:07.2-2 [ 36.320079] kjournald starting. Commit interval 5 seconds [ 36.327216] EXT3-fs: mounted filesystem with ordered data mode. [ 36.915218] usb 5-3: new high speed USB device using ehci_hcd and address 2 [ 37.052497] usb 5-3: configuration #1 chosen from 1 choice [ 44.555288] SCSI subsystem initialized [ 44.765092] parport_pc: VIA 686A/8231 detected [ 44.765104] parport_pc: probing current configuration [ 44.765143] parport_pc: Current parallel port base: 0x378 [ 44.765321] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP(,...)] [ 44.765433] parport_pc: VIA parallel port: io=0x378, irq=7 [ 44.838357] Initializing USB Mass Storage driver... [ 44.839007] scsi0 : SCSI emulation for USB Mass Storage devices [ 44.839252] usb-storage: device found at 2 [ 44.839260] usb-storage: waiting for device to settle before scanning [ 44.839320] usbcore: registered new interface driver usb-storage [ 44.839332] USB Mass Storage support registered. [ 48.126415] Floppy drive(s): fd0 is 1.44M [ 48.143468] FDC 0 is a post-1991 82077 [ 49.835860] scsi 0:0:0:0: Direct-Access ST325082 3A PQ: 0 ANSI: 0 [ 49.846429] usb-storage: device scan complete [ 49.876951] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 49.878196] sd 0:0:0:0: [sda] Write Protect is off [ 49.878207] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 49.878215] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 49.879448] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 49.880447] sd 0:0:0:0: [sda] Write Protect is off [ 49.880457] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 49.880464] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 49.880473] sda: sda1 [ 49.897518] sd 0:0:0:0: [sda] Attached SCSI disk [ 51.476789] EXT3 FS on hdb3, internal journal [ 51.663199] kjournald starting. Commit interval 5 seconds [ 51.663464] EXT3 FS on hda2, internal journal [ 51.663494] EXT3-fs: mounted filesystem with ordered data mode. [ 51.689309] kjournald starting. Commit interval 5 seconds [ 51.689703] EXT3 FS on hdb1, internal journal [ 51.689729] EXT3-fs: mounted filesystem with ordered data mode. [ 51.709284] kjournald starting. Commit interval 5 seconds [ 51.709716] EXT3 FS on hda3, internal journal [ 51.709766] EXT3-fs: mounted filesystem with ordered data mode. [ 51.729626] kjournald starting. Commit interval 5 seconds [ 51.730137] EXT3 FS on hda6, internal journal [ 51.730164] EXT3-fs: mounted filesystem with ordered data mode. [ 51.749826] kjournald starting. Commit interval 5 seconds [ 51.750397] EXT3 FS on hdb2, internal journal [ 51.750424] EXT3-fs: mounted filesystem with ordered data mode. [ 51.769609] kjournald starting. Commit interval 5 seconds [ 51.770017] EXT3 FS on hdb5, internal journal [ 51.770043] EXT3-fs: mounted filesystem with ordered data mode. [ 51.812286] kjournald starting. Commit interval 5 seconds [ 51.813261] EXT3 FS on sda1, internal journal [ 51.813290] EXT3-fs: mounted filesystem with ordered data mode. [ 52.598329] Adding 248968k swap on /dev/hda5. Priority:-1 extents:1 across:248968k [ 52.619426] Adding 240932k swap on /dev/hdb6. Priority:-2 extents:1 across:240932k [-- Attachment #4: dmesg-2622-clock.tsc --] [-- Type: application/octet-stream, Size: 15604 bytes --] 00] 0: 0 -> 131056 [ 0.000000] On node 0 totalpages: 131056 [ 0.000000] DMA zone: 32 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 [ 0.000000] Normal zone: 991 pages used for memmap [ 0.000000] Normal zone: 125969 pages, LIFO batch:31 [ 0.000000] DMI 2.3 present. [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dfff0000) [ 0.000000] Built 1 zonelists. Total pages: 130033 [ 0.000000] Kernel command line: ro root=/dev/hdb3 clock=tsc rhgb [ 0.000000] Warning! clock= boot option is deprecated. Use clocksource=xyz [ 0.000000] Enabling fast FPU save and restore... done. [ 0.000000] Initializing CPU#0 [ 0.000000] CPU 0 irqstacks, hard=c045f000 soft=c045e000 [ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes) [ 0.000000] Detected 800.068 MHz processor. [ 30.711395] Console: colour VGA+ 80x25 [ 30.713167] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 30.713289] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 30.713373] ... MAX_LOCK_DEPTH: 30 [ 30.713454] ... MAX_LOCKDEP_KEYS: 2048 [ 30.713536] ... CLASSHASH_SIZE: 1024 [ 30.713618] ... MAX_LOCKDEP_ENTRIES: 8192 [ 30.713701] ... MAX_LOCKDEP_CHAINS: 16384 [ 30.713785] ... CHAINHASH_SIZE: 8192 [ 30.713867] memory used by lock dependency info: 992 kB [ 30.713952] per task-struct memory footprint: 1200 bytes [ 30.714844] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) [ 30.715620] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) [ 30.757539] Memory: 512104k/524224k available (2217k kernel code, 11564k reserved, 1050k data, 152k init, 0k highmem) [ 30.757691] virtual kernel memory layout: [ 30.757695] fixmap : 0xffffd000 - 0xfffff000 ( 8 kB) [ 30.757699] vmalloc : 0xe0800000 - 0xffffb000 ( 503 MB) [ 30.757703] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB) [ 30.757707] .init : 0xc0433000 - 0xc0459000 ( 152 kB) [ 30.757711] .data : 0xc032a68a - 0xc043125c (1050 kB) [ 30.757715] .text : 0xc0100000 - 0xc032a68a (2217 kB) [ 30.758261] Checking if this processor honours the WP bit even in supervisor mode... Ok. [ 30.839073] Calibrating delay using timer specific routine.. 1603.17 BogoMIPS (lpj=3206340) [ 30.839451] Mount-cache hash table entries: 512 [ 30.840276] CPU: After generic identify, caps: 0183f9ff c1c7f9ff 00000000 00000000 00000000 00000000 00000000 [ 30.840303] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line) [ 30.840396] CPU: L2 Cache: 256K (64 bytes/line) [ 30.840480] CPU: After all inits, caps: 0183f9ff c1c7f9ff 00000000 00000420 00000000 00000000 00000000 [ 30.840503] Intel machine check architecture supported. [ 30.840589] Intel machine check reporting enabled on CPU#0. [ 30.840682] Compat vDSO mapped to ffffe000. [ 30.840783] CPU: AMD Athlon(tm) Processor stepping 02 [ 30.840947] Checking 'hlt' instruction... OK. [ 30.856204] NET: Registered protocol family 16 [ 30.882207] PCI: PCI BIOS revision 2.10 entry at 0xfdb71, last bus=1 [ 30.882299] PCI: Using configuration type 1 [ 30.882381] Setting up standard PCI resources [ 30.896974] usbcore: registered new interface driver usbfs [ 30.897303] usbcore: registered new interface driver hub [ 30.897630] usbcore: registered new device driver usb [ 30.897994] PCI: Probing PCI hardware [ 30.898111] PCI: Probing PCI hardware (bus 00) [ 30.899232] PCI quirk: region 0800-08ff claimed by vt82c586 ACPI [ 30.899327] PCI quirk: region 0c00-0c7f claimed by vt82c686 HW-mon [ 30.899420] PCI quirk: region 0400-040f claimed by vt82c686 SMB [ 30.904159] PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0 [ 30.907027] Time: tsc clocksource has been installed. [ 30.909007] PCI: Bridge: 0000:00:01.0 [ 30.909094] IO window: 8000-8fff [ 30.909184] MEM window: d7e00000-dfefffff [ 30.909273] PREFETCH window: c7c00000-d7cfffff [ 30.909389] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 30.909475] NET: Registered protocol family 2 [ 30.947147] IP route cache hash table entries: 4096 (order: 2, 16384 bytes) [ 30.947653] TCP established hash table entries: 16384 (order: 7, 720896 bytes) [ 30.954614] TCP bind hash table entries: 16384 (order: 7, 720896 bytes) [ 30.962532] TCP: Hash tables configured (established 16384 bind 16384) [ 30.962680] TCP reno registered [ 30.971667] Unpacking initramfs... done [ 31.110642] Freeing initrd memory: 1262k freed [ 31.112040] Machine check exception polling timer started. [ 31.112180] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac) [ 31.205247] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 31.206518] io scheduler noop registered [ 31.206605] io scheduler anticipatory registered (default) [ 31.206693] io scheduler deadline registered [ 31.206804] io scheduler cfq registered [ 31.206959] PCI: VIA PCI bridge detected. Disabling DAC. [ 31.207195] Boot video device is 0000:01:00.0 [ 31.208640] fb: 3Dfx Voodoo5 memory = 32768K [ 31.224356] Console: switching to colour frame buffer device 80x30 [ 31.258164] Real Time Clock Driver v1.12ac [ 31.265083] Linux agpgart interface v0.102 (c) Dave Jones [ 31.272353] agpgart: Detected VIA Twister-K/KT133x/KM133 chipset [ 31.286994] agpgart: AGP aperture is 64M @ 0xe0000000 [ 31.294382] [drm] Initialized drm 1.1.0 20060810 [ 31.301965] [drm] Initialized tdfx 1.0.0 20010216 on minor 0 [ 31.309801] PCI: setting IRQ 10 as level-triggered [ 31.309811] PCI: Found IRQ 10 for device 0000:00:0a.0 [ 31.316984] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 31.323954] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 31.330625] skge 1.11 addr 0xdfff8000 irq 10 chip Yukon rev 1 [ 31.337848] skge eth0: addr 00:30:bd:b8:31:55 [ 31.345008] 8139too Fast Ethernet driver 0.9.28 [ 31.351419] PCI: setting IRQ 12 as level-triggered [ 31.351429] PCI: Found IRQ 12 for device 0000:00:0f.0 [ 31.357887] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 31.364299] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 31.370502] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 31.377100] eth1: RealTek RTL8139 at 0xe480ce00, 00:c0:49:a7:33:fe, IRQ 12 [ 31.383166] eth1: Identified 8139 chip type 'RTL-8100B/8139D' [ 31.383234] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 31.389315] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 31.401903] VP_IDE: IDE controller at PCI slot 0000:00:07.1 [ 31.408545] VP_IDE: chipset revision 16 [ 31.415023] VP_IDE: not 100% native mode: will probe irqs later [ 31.421666] VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1 [ 31.434726] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 31.448250] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio [ 31.462221] Probing IDE interface ide0... [ 31.878461] hda: SAMSUNG SP1604N, ATA DISK drive [ 32.162264] hdb: Maxtor 6Y160P0, ATA DISK drive [ 32.222616] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 32.230288] Probing IDE interface ide1... [ 33.093648] hdc: TSSTcorpCD/DVDW TS-H552B, ATAPI CD/DVD-ROM drive [ 33.769357] ide1 at 0x170-0x177,0x376 on irq 15 [ 33.777804] hda: max request size: 512KiB [ 33.789577] hda: 312581808 sectors (160041 MB) w/2048KiB Cache, CHS=19457/255/63, UDMA(66) [ 33.805013] hda: cache flushes supported [ 33.812830] hda: hda1 hda2 hda3 hda4 < hda5 hda6 > [ 33.840568] hdb: max request size: 512KiB [ 33.849237] hdb: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(66) [ 33.865655] hdb: cache flushes supported [ 33.873704] hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 > [ 33.912847] hdc: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 33.928840] Uniform CD-ROM driver Revision: 3.20 [ 33.938567] usbmon: debugfs is not available [ 34.196880] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 34.205453] mice: PS/2 mouse device common for all mice [ 34.213477] EDAC MC: Ver: 2.0.1 Jul 9 2007 [ 34.221730] usbcore: registered new interface driver usbhid [ 34.229284] drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver [ 34.236875] Advanced Linux Sound Architecture Driver Version 1.0.14 (Thu May 31 09:03:25 2007 UTC). [ 34.253100] PCI: Found IRQ 10 for device 0000:00:07.5 [ 34.260884] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 34.268527] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 34.276049] PCI: Setting latency timer of device 0000:00:07.5 to 64 [ 34.791736] ALSA device list: [ 34.799080] #0: VIA 82C686A/B rev20 with AD1881A at 0xdc00, irq 10 [ 34.806717] TCP cubic registered [ 34.813938] NET: Registered protocol family 1 [ 34.821142] NET: Registered protocol family 17 [ 34.828298] Using IPI Shortcut mode [ 34.836047] Freeing unused kernel memory: 152k freed [ 34.843031] Write protecting the kernel text: 2220k [ 34.849924] Write protecting the kernel read-only data: 884k [ 35.203825] USB Universal Host Controller Interface driver v3.0 [ 35.210026] PCI: Found IRQ 12 for device 0000:00:07.2 [ 35.216068] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 35.221687] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 35.226922] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.231929] uhci_hcd 0000:00:07.2: UHCI Host Controller [ 35.237547] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 [ 35.248075] uhci_hcd 0000:00:07.2: irq 12, io base 0x0000cc00 [ 35.254385] usb usb1: configuration #1 chosen from 1 choice [ 35.260039] hub 1-0:1.0: USB hub found [ 35.265470] hub 1-0:1.0: 2 ports detected [ 35.372434] PCI: Found IRQ 12 for device 0000:00:07.3 [ 35.378039] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.383571] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 35.388889] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.394141] uhci_hcd 0000:00:07.3: UHCI Host Controller [ 35.399487] uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 [ 35.410065] uhci_hcd 0000:00:07.3: irq 12, io base 0x0000d000 [ 35.416496] usb usb2: configuration #1 chosen from 1 choice [ 35.422639] hub 2-0:1.0: USB hub found [ 35.428664] hub 2-0:1.0: 2 ports detected [ 35.536212] PCI: setting IRQ 9 as level-triggered [ 35.536222] PCI: Found IRQ 9 for device 0000:00:09.0 [ 35.542367] uhci_hcd 0000:00:09.0: UHCI Host Controller [ 35.548517] uhci_hcd 0000:00:09.0: new USB bus registered, assigned bus number 3 [ 35.560407] uhci_hcd 0000:00:09.0: irq 9, io base 0x0000c400 [ 35.567459] usb usb3: configuration #1 chosen from 1 choice [ 35.574315] hub 3-0:1.0: USB hub found [ 35.580981] hub 3-0:1.0: 2 ports detected [ 35.688098] PCI: Found IRQ 10 for device 0000:00:09.1 [ 35.694507] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 35.700745] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 35.706776] uhci_hcd 0000:00:09.1: UHCI Host Controller [ 35.712944] uhci_hcd 0000:00:09.1: new USB bus registered, assigned bus number 4 [ 35.725372] uhci_hcd 0000:00:09.1: irq 10, io base 0x0000c800 [ 35.732506] usb usb4: configuration #1 chosen from 1 choice [ 35.739378] hub 4-0:1.0: USB hub found [ 35.746218] hub 4-0:1.0: 2 ports detected [ 35.847647] usb 1-2: new low speed USB device using uhci_hcd and address 2 [ 35.866957] PCI: Found IRQ 12 for device 0000:00:09.2 [ 35.873903] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 35.880611] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.887152] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.893650] ehci_hcd 0000:00:09.2: EHCI Host Controller [ 35.900302] ehci_hcd 0000:00:09.2: new USB bus registered, assigned bus number 5 [ 35.913297] ehci_hcd 0000:00:09.2: irq 12, io mem 0xdfffff00 [ 35.919871] ehci_hcd 0000:00:09.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 35.933394] usb usb5: configuration #1 chosen from 1 choice [ 35.940272] hub 5-0:1.0: USB hub found [ 35.947013] hub 5-0:1.0: 4 ports detected [ 36.073322] usb 1-2: configuration #1 chosen from 1 choice [ 36.103615] input: 4D Mouse USB Mouse as /class/input/input0 [ 36.110957] input: USB HID v1.00 Mouse [4D Mouse USB Mouse] on usb-0000:00:07.2-2 [ 36.271361] Clocksource tsc unstable (delta = 88009123 ns) [ 36.543627] kjournald starting. Commit interval 5 seconds [ 36.550963] EXT3-fs: mounted filesystem with ordered data mode. [ 37.146757] usb 5-3: new high speed USB device using ehci_hcd and address 2 [ 37.284117] usb 5-3: configuration #1 chosen from 1 choice [ 44.946451] SCSI subsystem initialized [ 45.242462] parport_pc: VIA 686A/8231 detected [ 45.242475] parport_pc: probing current configuration [ 45.242510] parport_pc: Current parallel port base: 0x378 [ 45.242683] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP(,...)] [ 45.242786] parport_pc: VIA parallel port: io=0x378, irq=7 [ 45.302826] Initializing USB Mass Storage driver... [ 45.303407] scsi0 : SCSI emulation for USB Mass Storage devices [ 45.303667] usb-storage: device found at 2 [ 45.303674] usb-storage: waiting for device to settle before scanning [ 45.303735] usbcore: registered new interface driver usb-storage [ 45.303746] USB Mass Storage support registered. [ 48.307817] Floppy drive(s): fd0 is 1.44M [ 48.327051] FDC 0 is a post-1991 82077 [ 50.299414] scsi 0:0:0:0: Direct-Access ST325082 3A PQ: 0 ANSI: 0 [ 50.309860] usb-storage: device scan complete [ 50.341002] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 50.342004] sd 0:0:0:0: [sda] Write Protect is off [ 50.342015] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 50.342023] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 50.343121] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 50.344123] sd 0:0:0:0: [sda] Write Protect is off [ 50.344132] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 50.344140] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 50.344149] sda: sda1 [ 50.358202] sd 0:0:0:0: [sda] Attached SCSI disk [ 51.404971] EXT3 FS on hdb3, internal journal [ 51.580968] kjournald starting. Commit interval 5 seconds [ 51.581203] EXT3 FS on hda2, internal journal [ 51.581233] EXT3-fs: mounted filesystem with ordered data mode. [ 51.604335] kjournald starting. Commit interval 5 seconds [ 51.604712] EXT3 FS on hdb1, internal journal [ 51.604738] EXT3-fs: mounted filesystem with ordered data mode. [ 51.650208] kjournald starting. Commit interval 5 seconds [ 51.650725] EXT3 FS on hda3, internal journal [ 51.650755] EXT3-fs: mounted filesystem with ordered data mode. [ 51.672318] kjournald starting. Commit interval 5 seconds [ 51.672789] EXT3 FS on hda6, internal journal [ 51.672815] EXT3-fs: mounted filesystem with ordered data mode. [ 51.689829] kjournald starting. Commit interval 5 seconds [ 51.690360] EXT3 FS on hdb2, internal journal [ 51.690387] EXT3-fs: mounted filesystem with ordered data mode. [ 51.709586] kjournald starting. Commit interval 5 seconds [ 51.709986] EXT3 FS on hdb5, internal journal [ 51.710010] EXT3-fs: mounted filesystem with ordered data mode. [ 51.749106] kjournald starting. Commit interval 5 seconds [ 51.750098] EXT3 FS on sda1, internal journal [ 51.750125] EXT3-fs: mounted filesystem with ordered data mode. [ 52.574790] Adding 248968k swap on /dev/hda5. Priority:-1 extents:1 across:248968k [ 52.593861] Adding 240932k swap on /dev/hdb6. Priority:-2 extents:1 across:240932k ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-10 23:31 ` Alessandro Suardi @ 2007-07-11 21:06 ` john stultz 2007-07-12 11:03 ` Tilman Schmidt 2007-07-17 22:31 ` Alessandro Suardi 0 siblings, 2 replies; 9+ messages in thread From: john stultz @ 2007-07-11 21:06 UTC (permalink / raw) To: Alessandro Suardi Cc: Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner On Wed, 2007-07-11 at 01:31 +0200, Alessandro Suardi wrote: > On 7/10/07, john stultz <johnstul@us.ibm.com> wrote: > > On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > > > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > > > > > My oldish AMD K7-800's clock began falling behind after > > > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > > > gets the original stable system time back. > > > > Alessandro, > > Can you send me dmesg output for 2.6.20 and 2.6.22 (without > > clocksource=tsc)? > > Actually, I lied a little bit - it was 2.6.22 with clock=tsc (which > warns on boot about clock= being deprecated in favor of > clocksource= ). I assume behavior is identical for now. > > Please find attached the dmesg ring (incomplete, as the > kernel ring size I have seems too small to hold the full > buffer, but it seems to have all the interesting stuff) of > 2.6.20, 2.6.22, 2.6.22 with clock=tsc. > > If you need more info, just ask. I'll be out of the country > from July 12 to the morning of July 16, and again from > July 17 to July 20, so if you'd rather get at this later on, > it's okay for me ;) You're dmesg output got chopped at the top. Please increase the kernel log buffer size. Sounds like your PIT frequency is out of whack, and I'm guessing the generic clocksource watchdog blames the TSC and disqualifies it. Few things to check: 1) Make sure you're running the latest BIOS. 2) See if booting w/ noapic changes anything -john ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-11 21:06 ` john stultz @ 2007-07-12 11:03 ` Tilman Schmidt 2007-07-17 22:31 ` Alessandro Suardi 1 sibling, 0 replies; 9+ messages in thread From: Tilman Schmidt @ 2007-07-12 11:03 UTC (permalink / raw) To: john stultz Cc: Alessandro Suardi, Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner [-- Attachment #1: Type: text/plain, Size: 3106 bytes --] John, I see the same change in behaviour on my newish Pentium D 940. Here's what I posted this Monday to the "clocksource tsc unstable" thread, mistakenly thinking it belonged there: <quote> Now that you mention it - I am seeing something similar with kernel 2.6.22 on an Intel Pentium D 940 dual core processor (arbitrary selection of dmesg lines that appeared relevant): <5>[ 0.000000] Linux version 2.6.22-testing (ts@xenon) (gcc version 4.1.2 20061115 (prerelease) (SUSE Linux)) #1 SMP PREEMPT Mon Jul 9 10:57:22 CEST 2007 <6>[ 56.367608] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0 <6>[ 56.367867] hpet0: 3 64-bit timers, 14318180 Hz <4>[ 56.428897] Calibrating delay using timer specific routine.. 6399.40 BogoMIPS (lpj=3199704) <4>[ 56.438058] CPU0: Intel(R) Pentium(R) D CPU 3.20GHz stepping 04 <4>[ 56.509321] CPU1: Intel(R) Pentium(R) D CPU 3.20GHz stepping 04 <6>[ 56.510299] Total of 2 processors activated (12793.06 BogoMIPS). <4>[ 56.510527] ENABLING IO-APIC IRQs <6>[ 56.510792] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1 <6>[ 56.622869] checking TSC synchronization [CPU#0 -> CPU#1]: <4>[ 56.642971] Measured 16 cycles TSC warp between CPUs, turning off TSC clock. <4>[ 0.152000] Marking TSC unstable due to: check_tsc_sync_source failed. <6>[ 0.153000] Brought up 2 CPUs <4>[ 0.241000] migration_cost=2000 2.6.22-rc6-mm1 has it too, though without the backward jump in printk timestamps: <5>[ 0.000000] Linux version 2.6.22-rc6-mm1-testing (ts@xenon) (gcc version 4.1.2 20061115 (prerelease) (SUSE Linux)) #10 SMP PREEMPT Thu Jul 5 23:41:32 CEST 2007 <6>[ 0.160000] Total of 2 processors activated (12791.39 BogoMIPS). <4>[ 0.160000] ENABLING IO-APIC IRQs <6>[ 0.161000] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1 <6>[ 0.171000] checking TSC synchronization [CPU#0 -> CPU#1]: <4>[ 0.171005] Measured 96 cycles TSC warp between CPUs, turning off TSC clock. <4>[ 0.171005] Marking TSC unstable due to: check_tsc_sync_source failed. <6>[ 0.172000] Brought up 2 CPUs 2.6.21.6 is fine here, though: <5>[ 0.000000] Linux version 2.6.21.6-noinitrd (ts@xenon) (gcc version 4.1.2 20061115 (prerelease) (SUSE Linux)) #1 SMP PREEMPT Sat Jul 7 16:40:13 CEST 2007 <6>[ 59.776179] Total of 2 processors activated (12794.21 BogoMIPS). <4>[ 59.776403] ENABLING IO-APIC IRQs <6>[ 59.776657] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1 <6>[ 59.923347] checking TSC synchronization [CPU#0 -> CPU#1]: passed. <6>[ 59.943479] Brought up 2 CPUs <4>[ 60.198497] migration_cost=496 <6>[ 60.303586] Time: tsc clocksource has been installed. <6>[ 60.303678] Switched to high resolution mode on CPU 0 <6>[ 60.303974] Switched to high resolution mode on CPU 1 HTH </quote> Please let me know if you need the full dmesgs, or anything else. Thanks T. -- Tilman Schmidt E-Mail: tilman@imap.cc Bonn, Germany Diese Nachricht besteht zu 100% aus wiederverwerteten Bits. Ungeöffnet mindestens haltbar bis: (siehe Rückseite) [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 250 bytes --] ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-11 21:06 ` john stultz 2007-07-12 11:03 ` Tilman Schmidt @ 2007-07-17 22:31 ` Alessandro Suardi 2007-07-17 22:40 ` john stultz 1 sibling, 1 reply; 9+ messages in thread From: Alessandro Suardi @ 2007-07-17 22:31 UTC (permalink / raw) To: john stultz; +Cc: Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner [-- Attachment #1: Type: text/plain, Size: 2598 bytes --] On 7/11/07, john stultz <johnstul@us.ibm.com> wrote: > On Wed, 2007-07-11 at 01:31 +0200, Alessandro Suardi wrote: > > On 7/10/07, john stultz <johnstul@us.ibm.com> wrote: > > > On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > > > > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > > > > > > > My oldish AMD K7-800's clock began falling behind after > > > > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > > > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > > > > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > > > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > > > > gets the original stable system time back. > > > > > > Alessandro, > > > Can you send me dmesg output for 2.6.20 and 2.6.22 (without > > > clocksource=tsc)? > > > > Actually, I lied a little bit - it was 2.6.22 with clock=tsc (which > > warns on boot about clock= being deprecated in favor of > > clocksource= ). I assume behavior is identical for now. > > > > Please find attached the dmesg ring (incomplete, as the > > kernel ring size I have seems too small to hold the full > > buffer, but it seems to have all the interesting stuff) of > > 2.6.20, 2.6.22, 2.6.22 with clock=tsc. > > > > If you need more info, just ask. I'll be out of the country > > from July 12 to the morning of July 16, and again from > > July 17 to July 20, so if you'd rather get at this later on, > > it's okay for me ;) > > You're dmesg output got chopped at the top. Please increase the kernel > log buffer size. Done, please find attached both 2620 and 2622 full dmesg output, with no clock= or clocksource= parameters. > Sounds like your PIT frequency is out of whack, and I'm guessing the > generic clocksource watchdog blames the TSC and disqualifies it. > > Few things to check: > 1) Make sure you're running the latest BIOS. I'm probably not, though I'm not sure I'd flash anything on such an old machine - been running it since RedHat 9 with the current BIOS. Plus, I removed the floppy drive to make room for an extra IDE disk... it'd take me a little bit to find out whether I still have the floppy drive around. > 2) See if booting w/ noapic changes anything Nope, 2622+noapic => PIT is still used and clock very quickly lags behind. For the moment being I'll keep booting with clocksource=tsc. Let me know whether you want me to test anything more... thanks, ciao, --alessandro "Did you get married but forgot to get divorced ?" (Danny and Dusty, 'The Good Old Days') [-- Attachment #2: dmesg-2620.out --] [-- Type: application/octet-stream, Size: 17457 bytes --] [ 0.000000] Linux version 2.6.20 (asuardi@donkey) (gcc version 4.1.2 20070626 (Red Hat 4.1.2-13)) #2 PREEMPT Tue Jul 17 21:14:17 CEST 2007 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] sanitize start [ 0.000000] sanitize end [ 0.000000] copy_e820_map() start: 0000000000000000 size: 000000000009fc00 end: 000000000009fc00 type: 1 [ 0.000000] copy_e820_map() type is E820_RAM [ 0.000000] copy_e820_map() start: 000000000009fc00 size: 0000000000000400 end: 00000000000a0000 type: 2 [ 0.000000] copy_e820_map() start: 00000000000ec000 size: 0000000000014000 end: 0000000000100000 type: 2 [ 0.000000] copy_e820_map() start: 0000000000100000 size: 000000001fef0000 end: 000000001fff0000 type: 1 [ 0.000000] copy_e820_map() type is E820_RAM [ 0.000000] copy_e820_map() start: 000000001fff0000 size: 0000000000008000 end: 000000001fff8000 type: 3 [ 0.000000] copy_e820_map() start: 000000001fff8000 size: 0000000000008000 end: 0000000020000000 type: 4 [ 0.000000] copy_e820_map() start: 00000000ffff0000 size: 0000000000010000 end: 0000000100000000 type: 2 [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000ec000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000001fff0000 (usable) [ 0.000000] BIOS-e820: 000000001fff0000 - 000000001fff8000 (ACPI data) [ 0.000000] BIOS-e820: 000000001fff8000 - 0000000020000000 (ACPI NVS) [ 0.000000] BIOS-e820: 00000000ffff0000 - 0000000100000000 (reserved) [ 0.000000] 511MB LOWMEM available. [ 0.000000] Entering add_active_range(0, 0, 131056) 0 entries of 256 used [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0 -> 4096 [ 0.000000] Normal 4096 -> 131056 [ 0.000000] early_node_map[1] active PFN ranges [ 0.000000] 0: 0 -> 131056 [ 0.000000] On node 0 totalpages: 131056 [ 0.000000] DMA zone: 32 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 [ 0.000000] Normal zone: 991 pages used for memmap [ 0.000000] Normal zone: 125969 pages, LIFO batch:31 [ 0.000000] DMI 2.3 present. [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dfff0000) [ 0.000000] Detected 800.063 MHz processor. [ 29.448641] Built 1 zonelists. Total pages: 130033 [ 29.448649] Kernel command line: ro root=/dev/hdb3 rhgb [ 29.449122] Enabling fast FPU save and restore... done. [ 29.449150] Initializing CPU#0 [ 29.449280] CPU 0 irqstacks, hard=c0443000 soft=c0442000 [ 29.449290] PID hash table entries: 2048 (order: 11, 8192 bytes) [ 29.450943] Console: colour VGA+ 80x25 [ 29.453794] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 29.453912] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 29.453991] ... MAX_LOCK_DEPTH: 30 [ 29.454069] ... MAX_LOCKDEP_KEYS: 2048 [ 29.454148] ... CLASSHASH_SIZE: 1024 [ 29.454227] ... MAX_LOCKDEP_ENTRIES: 8192 [ 29.454307] ... MAX_LOCKDEP_CHAINS: 16384 [ 29.454386] ... CHAINHASH_SIZE: 8192 [ 29.454465] memory used by lock dependency info: 1064 kB [ 29.454548] per task-struct memory footprint: 1200 bytes [ 29.455429] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) [ 29.456182] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) [ 29.499230] Memory: 512108k/524224k available (2163k kernel code, 11568k reserved, 1007k data, 140k init, 0k highmem) [ 29.499384] virtual kernel memory layout: [ 29.499388] fixmap : 0xffffd000 - 0xfffff000 ( 8 kB) [ 29.499393] vmalloc : 0xe0800000 - 0xffffb000 ( 503 MB) [ 29.499398] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB) [ 29.499402] .init : 0xc041a000 - 0xc043d000 ( 140 kB) [ 29.499407] .data : 0xc031cc76 - 0xc0418a0c (1007 kB) [ 29.499412] .text : 0xc0100000 - 0xc031cc76 (2163 kB) [ 29.499967] Checking if this processor honours the WP bit even in supervisor mode... Ok. [ 29.577204] Calibrating delay using timer specific routine.. 1603.22 BogoMIPS (lpj=3206454) [ 29.577597] Mount-cache hash table entries: 512 [ 29.578398] CPU: After generic identify, caps: 0183f9ff c1c7f9ff 00000000 00000000 00000000 00000000 00000000 [ 29.578429] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line) [ 29.578524] CPU: L2 Cache: 256K (64 bytes/line) [ 29.578609] CPU: After all inits, caps: 0183f9ff c1c7f9ff 00000000 00000420 00000000 00000000 00000000 [ 29.578634] Intel machine check architecture supported. [ 29.578721] Intel machine check reporting enabled on CPU#0. [ 29.578828] CPU: AMD Athlon(tm) Processor stepping 02 [ 29.578996] Checking 'hlt' instruction... OK. [ 29.594902] NET: Registered protocol family 16 [ 29.620952] PCI: PCI BIOS revision 2.10 entry at 0xfdb71, last bus=1 [ 29.621044] PCI: Using configuration type 1 [ 29.621128] Setting up standard PCI resources [ 29.635967] usbcore: registered new interface driver usbfs [ 29.636315] usbcore: registered new interface driver hub [ 29.636649] usbcore: registered new device driver usb [ 29.637020] PCI: Probing PCI hardware [ 29.637123] PCI: Probing PCI hardware (bus 00) [ 29.638262] PCI quirk: region 0800-08ff claimed by vt82c586 ACPI [ 29.638358] PCI quirk: region 0c00-0c7f claimed by vt82c686 HW-mon [ 29.638452] PCI quirk: region 0400-040f claimed by vt82c686 SMB [ 29.639612] Boot video device is 0000:01:00.0 [ 29.643080] PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0 [ 29.647602] PCI: Bridge: 0000:00:01.0 [ 29.647690] IO window: 8000-8fff [ 29.647781] MEM window: d7e00000-dfefffff [ 29.647870] PREFETCH window: c7c00000-d7cfffff [ 29.647986] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 29.648091] NET: Registered protocol family 2 [ 29.685363] IP route cache hash table entries: 4096 (order: 2, 16384 bytes) [ 29.686005] TCP established hash table entries: 16384 (order: 7, 655360 bytes) [ 29.692581] TCP bind hash table entries: 8192 (order: 6, 360448 bytes) [ 29.696621] TCP: Hash tables configured (established 16384 bind 8192) [ 29.696766] TCP reno registered [ 29.705789] Unpacking initramfs... done [ 29.843709] Freeing initrd memory: 1261k freed [ 29.845457] Machine check exception polling timer started. [ 29.845596] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac) [ 29.889712] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 29.891042] io scheduler noop registered [ 29.891168] io scheduler anticipatory registered (default) [ 29.891331] io scheduler deadline registered [ 29.891489] io scheduler cfq registered [ 29.893519] fb: 3Dfx Voodoo5 memory = 32768K [ 29.908900] Console: switching to colour frame buffer device 80x30 [ 29.941382] Real Time Clock Driver v1.12ac [ 29.948362] Linux agpgart interface v0.101 (c) Dave Jones [ 29.955514] agpgart: Detected VIA Twister-K/KT133x/KM133 chipset [ 29.969780] agpgart: AGP aperture is 64M @ 0xe0000000 [ 29.977020] [drm] Initialized drm 1.1.0 20060810 [ 29.984407] [drm] Initialized tdfx 1.0.0 20010216 on minor 0 [ 29.992017] PCI: setting IRQ 10 as level-triggered [ 29.992028] PCI: Found IRQ 10 for device 0000:00:0a.0 [ 29.999160] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 30.006094] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 30.012811] skge 1.9 addr 0xdfff8000 irq 10 chip Yukon rev 1 [ 30.019903] skge eth0: addr 00:30:bd:b8:31:55 [ 30.027024] 8139too Fast Ethernet driver 0.9.28 [ 30.033394] PCI: setting IRQ 12 as level-triggered [ 30.033404] PCI: Found IRQ 12 for device 0000:00:0f.0 [ 30.039692] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 30.045979] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 30.052110] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 30.058624] eth1: RealTek RTL8139 at 0xe480ce00, 00:c0:49:a7:33:fe, IRQ 12 [ 30.064683] eth1: Identified 8139 chip type 'RTL-8100B/8139D' [ 30.064715] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 30.070781] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 30.083050] VP_IDE: IDE controller at PCI slot 0000:00:07.1 [ 30.089478] VP_IDE: chipset revision 16 [ 30.095868] VP_IDE: not 100% native mode: will probe irqs later [ 30.102482] VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1 [ 30.115485] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 30.128974] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio [ 30.142894] Probing IDE interface ide0... [ 30.556632] hda: SAMSUNG SP1604N, ATA DISK drive [ 30.840435] hdb: Maxtor 6Y160P0, ATA DISK drive [ 30.900786] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 30.908366] Probing IDE interface ide1... [ 31.771799] hdc: TSSTcorpCD/DVDW TS-H552B, ATAPI CD/DVD-ROM drive [ 32.447556] ide1 at 0x170-0x177,0x376 on irq 15 [ 32.455917] hda: max request size: 512KiB [ 32.467590] hda: 312581808 sectors (160041 MB) w/2048KiB Cache, CHS=19457/255/63, UDMA(66) [ 32.482952] hda: cache flushes supported [ 32.490780] hda: hda1 hda2 hda3 hda4 < hda5 hda6 > [ 32.520751] hdb: max request size: 512KiB [ 32.529380] hdb: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(66) [ 32.545741] hdb: cache flushes supported [ 32.553772] hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 > [ 32.598138] hdc: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 32.614036] Uniform CD-ROM driver Revision: 3.20 [ 32.623713] usbmon: debugfs is not available [ 32.631724] usbcore: registered new interface driver usbhid [ 32.639522] drivers/usb/input/hid-core.c: v2.6:USB HID core driver [ 32.899036] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 32.907379] mice: PS/2 mouse device common for all mice [ 32.915213] EDAC MC: Ver: 2.0.1 Jul 17 2007 [ 32.923295] Advanced Linux Sound Architecture Driver Version 1.0.14rc1 (Tue Jan 09 09:56:17 2007 UTC). [ 32.939514] PCI: Found IRQ 10 for device 0000:00:07.5 [ 32.947378] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 32.955073] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 32.962650] PCI: Setting latency timer of device 0000:00:07.5 to 64 [ 32.972521] input: AT Translated Set 2 keyboard as /class/input/input0 [ 33.485935] ALSA device list: [ 33.493386] #0: VIA 82C686A/B rev20 with AD1881A at 0xdc00, irq 10 [ 33.501068] TCP cubic registered [ 33.508490] NET: Registered protocol family 1 [ 33.515955] NET: Registered protocol family 17 [ 33.523358] Using IPI Shortcut mode [ 33.530476] Time: tsc clocksource has been installed. [ 33.537948] Freeing unused kernel memory: 140k freed [ 33.545116] Write protecting the kernel read-only data: 814k [ 33.902330] USB Universal Host Controller Interface driver v3.0 [ 33.908985] PCI: Found IRQ 12 for device 0000:00:07.2 [ 33.915004] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 33.920787] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 33.926314] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 33.931686] uhci_hcd 0000:00:07.2: UHCI Host Controller [ 33.937748] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 [ 33.948626] uhci_hcd 0000:00:07.2: irq 12, io base 0x0000cc00 [ 33.955099] usb usb1: configuration #1 chosen from 1 choice [ 33.960861] hub 1-0:1.0: USB hub found [ 33.966428] hub 1-0:1.0: 2 ports detected [ 34.074726] PCI: Found IRQ 12 for device 0000:00:07.3 [ 34.080486] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 34.086164] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.091630] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.096894] uhci_hcd 0000:00:07.3: UHCI Host Controller [ 34.102288] uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 [ 34.112876] uhci_hcd 0000:00:07.3: irq 12, io base 0x0000d000 [ 34.119256] usb usb2: configuration #1 chosen from 1 choice [ 34.125378] hub 2-0:1.0: USB hub found [ 34.131361] hub 2-0:1.0: 2 ports detected [ 34.238448] PCI: setting IRQ 9 as level-triggered [ 34.238458] PCI: Found IRQ 9 for device 0000:00:09.0 [ 34.244610] uhci_hcd 0000:00:09.0: UHCI Host Controller [ 34.250773] uhci_hcd 0000:00:09.0: new USB bus registered, assigned bus number 3 [ 34.262670] uhci_hcd 0000:00:09.0: irq 9, io base 0x0000c400 [ 34.269687] usb usb3: configuration #1 chosen from 1 choice [ 34.276518] hub 3-0:1.0: USB hub found [ 34.283166] hub 3-0:1.0: 2 ports detected [ 34.390336] PCI: Found IRQ 10 for device 0000:00:09.1 [ 34.396752] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 34.402996] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 34.409021] uhci_hcd 0000:00:09.1: UHCI Host Controller [ 34.415188] uhci_hcd 0000:00:09.1: new USB bus registered, assigned bus number 4 [ 34.427553] uhci_hcd 0000:00:09.1: irq 10, io base 0x0000c800 [ 34.434590] usb usb4: configuration #1 chosen from 1 choice [ 34.441466] hub 4-0:1.0: USB hub found [ 34.448283] hub 4-0:1.0: 2 ports detected [ 34.549802] usb 1-2: new low speed USB device using uhci_hcd and address 2 [ 34.568901] PCI: Found IRQ 12 for device 0000:00:09.2 [ 34.575816] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 34.582495] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 34.588965] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.595424] ehci_hcd 0000:00:09.2: EHCI Host Controller [ 34.602076] ehci_hcd 0000:00:09.2: new USB bus registered, assigned bus number 5 [ 34.615000] ehci_hcd 0000:00:09.2: irq 12, io mem 0xdfffff00 [ 34.621538] ehci_hcd 0000:00:09.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 34.634893] usb usb5: configuration #1 chosen from 1 choice [ 34.641779] hub 5-0:1.0: USB hub found [ 34.648487] hub 5-0:1.0: 4 ports detected [ 34.775978] usb 1-2: configuration #1 chosen from 1 choice [ 34.806123] input: 4D Mouse USB Mouse as /class/input/input1 [ 34.813373] input: USB HID v1.00 Mouse [4D Mouse USB Mouse] on usb-0000:00:07.2-2 [ 35.254018] kjournald starting. Commit interval 5 seconds [ 35.261088] EXT3-fs: mounted filesystem with ordered data mode. [ 35.848913] usb 5-3: new high speed USB device using ehci_hcd and address 2 [ 35.986184] usb 5-3: configuration #1 chosen from 1 choice [ 43.272857] parport_pc: VIA 686A/8231 detected [ 43.272870] parport_pc: probing current configuration [ 43.272906] parport_pc: Current parallel port base: 0x378 [ 43.273087] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP(,...)] [ 43.273217] parport_pc: VIA parallel port: io=0x378, irq=7 [ 43.492616] SCSI subsystem initialized [ 43.791863] Initializing USB Mass Storage driver... [ 43.792429] scsi0 : SCSI emulation for USB Mass Storage devices [ 43.792651] usb-storage: device found at 2 [ 43.792659] usb-storage: waiting for device to settle before scanning [ 43.792705] usbcore: registered new interface driver usb-storage [ 43.792718] USB Mass Storage support registered. [ 47.260976] Floppy drive(s): fd0 is 1.44M [ 47.281027] FDC 0 is a post-1991 82077 [ 48.789816] scsi 0:0:0:0: Direct-Access ST325082 3A PQ: 0 ANSI: 0 [ 48.792970] usb-storage: device scan complete [ 48.880020] SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB) [ 48.881236] sda: Write Protect is off [ 48.881246] sda: Mode Sense: 33 00 00 00 [ 48.881254] sda: assuming drive cache: write through [ 48.884124] SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB) [ 48.885409] sda: Write Protect is off [ 48.885419] sda: Mode Sense: 33 00 00 00 [ 48.885451] sda: assuming drive cache: write through [ 48.885463] sda: sda1 [ 48.913054] sd 0:0:0:0: Attached scsi disk sda [ 50.402511] EXT3 FS on hdb3, internal journal [ 50.617874] kjournald starting. Commit interval 5 seconds [ 50.618113] EXT3 FS on hda2, internal journal [ 50.618144] EXT3-fs: mounted filesystem with ordered data mode. [ 50.646857] kjournald starting. Commit interval 5 seconds [ 50.647264] EXT3 FS on hdb1, internal journal [ 50.647293] EXT3-fs: mounted filesystem with ordered data mode. [ 50.672287] kjournald starting. Commit interval 5 seconds [ 50.672688] EXT3 FS on hda3, internal journal [ 50.672717] EXT3-fs: mounted filesystem with ordered data mode. [ 50.700928] kjournald starting. Commit interval 5 seconds [ 50.701400] EXT3 FS on hda6, internal journal [ 50.701430] EXT3-fs: mounted filesystem with ordered data mode. [ 50.724005] kjournald starting. Commit interval 5 seconds [ 50.724567] EXT3 FS on hdb2, internal journal [ 50.724597] EXT3-fs: mounted filesystem with ordered data mode. [ 50.760411] kjournald starting. Commit interval 5 seconds [ 50.760803] EXT3 FS on hdb5, internal journal [ 50.760832] EXT3-fs: mounted filesystem with ordered data mode. [ 50.806609] kjournald starting. Commit interval 5 seconds [ 50.807567] EXT3 FS on sda1, internal journal [ 50.807596] EXT3-fs: mounted filesystem with ordered data mode. [ 51.544633] Adding 248968k swap on /dev/hda5. Priority:-1 extents:1 across:248968k [ 51.568987] Adding 240932k swap on /dev/hdb6. Priority:-2 extents:1 across:240932k [ 59.425867] NET: Registered protocol family 10 [ 65.108769] eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1 [ 69.956304] skge eth1: enabling interface [ 69.961577] ADDRCONF(NETDEV_UP): eth1: link is not ready [ 75.905325] eth0: no IPv6 routers present [-- Attachment #3: dmesg-2622.out --] [-- Type: application/octet-stream, Size: 16918 bytes --] [ 0.000000] Linux version 2.6.22 (asuardi@donkey) (gcc version 4.1.2 20070626 (Red Hat 4.1.2-13)) #2 PREEMPT Tue Jul 17 21:21:23 CEST 2007 [ 0.000000] BIOS-provided physical RAM map: [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009fc00 (usable) [ 0.000000] BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved) [ 0.000000] BIOS-e820: 00000000000ec000 - 0000000000100000 (reserved) [ 0.000000] BIOS-e820: 0000000000100000 - 000000001fff0000 (usable) [ 0.000000] BIOS-e820: 000000001fff0000 - 000000001fff8000 (ACPI data) [ 0.000000] BIOS-e820: 000000001fff8000 - 0000000020000000 (ACPI NVS) [ 0.000000] BIOS-e820: 00000000ffff0000 - 0000000100000000 (reserved) [ 0.000000] 511MB LOWMEM available. [ 0.000000] Entering add_active_range(0, 0, 131056) 0 entries of 256 used [ 0.000000] Zone PFN ranges: [ 0.000000] DMA 0 -> 4096 [ 0.000000] Normal 4096 -> 131056 [ 0.000000] early_node_map[1] active PFN ranges [ 0.000000] 0: 0 -> 131056 [ 0.000000] On node 0 totalpages: 131056 [ 0.000000] DMA zone: 32 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 4064 pages, LIFO batch:0 [ 0.000000] Normal zone: 991 pages used for memmap [ 0.000000] Normal zone: 125969 pages, LIFO batch:31 [ 0.000000] DMI 2.3 present. [ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dfff0000) [ 0.000000] Built 1 zonelists. Total pages: 130033 [ 0.000000] Kernel command line: ro root=/dev/hdb3 rhgb [ 0.000000] Enabling fast FPU save and restore... done. [ 0.000000] Initializing CPU#0 [ 0.000000] CPU 0 irqstacks, hard=c045f000 soft=c045e000 [ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes) [ 0.000000] Detected 800.072 MHz processor. [ 30.209034] Console: colour VGA+ 80x25 [ 30.210719] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 30.210843] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 30.210925] ... MAX_LOCK_DEPTH: 30 [ 30.211007] ... MAX_LOCKDEP_KEYS: 2048 [ 30.211089] ... CLASSHASH_SIZE: 1024 [ 30.211170] ... MAX_LOCKDEP_ENTRIES: 8192 [ 30.211253] ... MAX_LOCKDEP_CHAINS: 16384 [ 30.211335] ... CHAINHASH_SIZE: 8192 [ 30.211418] memory used by lock dependency info: 992 kB [ 30.211503] per task-struct memory footprint: 1200 bytes [ 30.212393] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes) [ 30.213148] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes) [ 30.254716] Memory: 512056k/524224k available (2217k kernel code, 11612k reserved, 1050k data, 152k init, 0k highmem) [ 30.254869] virtual kernel memory layout: [ 30.254873] fixmap : 0xffffd000 - 0xfffff000 ( 8 kB) [ 30.254877] vmalloc : 0xe0800000 - 0xffffb000 ( 503 MB) [ 30.254881] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB) [ 30.254885] .init : 0xc0433000 - 0xc0459000 ( 152 kB) [ 30.254889] .data : 0xc032a68a - 0xc043125c (1050 kB) [ 30.254893] .text : 0xc0100000 - 0xc032a68a (2217 kB) [ 30.255455] Checking if this processor honours the WP bit even in supervisor mode... Ok. [ 30.336270] Calibrating delay using timer specific routine.. 1603.21 BogoMIPS (lpj=3206420) [ 30.336649] Mount-cache hash table entries: 512 [ 30.337472] CPU: After generic identify, caps: 0183f9ff c1c7f9ff 00000000 00000000 00000000 00000000 00000000 [ 30.337499] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line) [ 30.337592] CPU: L2 Cache: 256K (64 bytes/line) [ 30.337677] CPU: After all inits, caps: 0183f9ff c1c7f9ff 00000000 00000420 00000000 00000000 00000000 [ 30.337699] Intel machine check architecture supported. [ 30.337786] Intel machine check reporting enabled on CPU#0. [ 30.337878] Compat vDSO mapped to ffffe000. [ 30.337978] CPU: AMD Athlon(tm) Processor stepping 02 [ 30.338143] Checking 'hlt' instruction... OK. [ 30.353404] NET: Registered protocol family 16 [ 30.379406] PCI: PCI BIOS revision 2.10 entry at 0xfdb71, last bus=1 [ 30.379498] PCI: Using configuration type 1 [ 30.379580] Setting up standard PCI resources [ 30.394185] usbcore: registered new interface driver usbfs [ 30.394518] usbcore: registered new interface driver hub [ 30.394846] usbcore: registered new device driver usb [ 30.395211] PCI: Probing PCI hardware [ 30.395329] PCI: Probing PCI hardware (bus 00) [ 30.396483] PCI quirk: region 0800-08ff claimed by vt82c586 ACPI [ 30.396579] PCI quirk: region 0c00-0c7f claimed by vt82c686 HW-mon [ 30.396673] PCI quirk: region 0400-040f claimed by vt82c686 SMB [ 30.401470] PCI: Using IRQ router VIA [1106/0686] at 0000:00:07.0 [ 30.404227] Time: tsc clocksource has been installed. [ 30.406391] PCI: Bridge: 0000:00:01.0 [ 30.406478] IO window: 8000-8fff [ 30.406570] MEM window: d7e00000-dfefffff [ 30.406658] PREFETCH window: c7c00000-d7cfffff [ 30.406773] PCI: Setting latency timer of device 0000:00:01.0 to 64 [ 30.406857] NET: Registered protocol family 2 [ 30.444344] IP route cache hash table entries: 4096 (order: 2, 16384 bytes) [ 30.444845] TCP established hash table entries: 16384 (order: 7, 720896 bytes) [ 30.451819] TCP bind hash table entries: 16384 (order: 7, 720896 bytes) [ 30.459737] TCP: Hash tables configured (established 16384 bind 16384) [ 30.459885] TCP reno registered [ 30.468859] Unpacking initramfs... done [ 30.607751] Freeing initrd memory: 1262k freed [ 30.609132] Machine check exception polling timer started. [ 30.609272] apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac) [ 30.700173] Installing knfsd (copyright (C) 1996 okir@monad.swb.de). [ 30.701457] io scheduler noop registered [ 30.701544] io scheduler anticipatory registered (default) [ 30.701632] io scheduler deadline registered [ 30.701742] io scheduler cfq registered [ 30.701848] PCI: VIA PCI bridge detected. Disabling DAC. [ 30.702080] Boot video device is 0000:01:00.0 [ 30.703500] fb: 3Dfx Voodoo5 memory = 32768K [ 30.719250] Console: switching to colour frame buffer device 80x30 [ 30.752959] Real Time Clock Driver v1.12ac [ 30.759999] Linux agpgart interface v0.102 (c) Dave Jones [ 30.767230] agpgart: Detected VIA Twister-K/KT133x/KM133 chipset [ 30.781753] agpgart: AGP aperture is 64M @ 0xe0000000 [ 30.789101] [drm] Initialized drm 1.1.0 20060810 [ 30.796653] [drm] Initialized tdfx 1.0.0 20010216 on minor 0 [ 30.804460] PCI: setting IRQ 10 as level-triggered [ 30.804470] PCI: Found IRQ 10 for device 0000:00:0a.0 [ 30.811598] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 30.818541] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 30.825180] skge 1.11 addr 0xdfff8000 irq 10 chip Yukon rev 1 [ 30.832398] skge eth0: addr 00:30:bd:b8:31:55 [ 30.839521] 8139too Fast Ethernet driver 0.9.28 [ 30.845894] PCI: setting IRQ 12 as level-triggered [ 30.845904] PCI: Found IRQ 12 for device 0000:00:0f.0 [ 30.852344] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 30.858743] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 30.864923] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 30.871487] eth1: RealTek RTL8139 at 0xe480ce00, 00:c0:49:a7:33:fe, IRQ 12 [ 30.877535] eth1: Identified 8139 chip type 'RTL-8100B/8139D' [ 30.877601] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2 [ 30.883655] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx [ 30.896200] VP_IDE: IDE controller at PCI slot 0000:00:07.1 [ 30.902824] VP_IDE: chipset revision 16 [ 30.909297] VP_IDE: not 100% native mode: will probe irqs later [ 30.915929] VP_IDE: VIA vt82c686a (rev 22) IDE UDMA66 controller on pci0000:00:07.1 [ 30.928980] ide0: BM-DMA at 0xffa0-0xffa7, BIOS settings: hda:DMA, hdb:DMA [ 30.942524] ide1: BM-DMA at 0xffa8-0xffaf, BIOS settings: hdc:DMA, hdd:pio [ 30.956515] Probing IDE interface ide0... [ 31.371661] hda: SAMSUNG SP1604N, ATA DISK drive [ 31.655463] hdb: Maxtor 6Y160P0, ATA DISK drive [ 31.715822] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14 [ 31.723480] Probing IDE interface ide1... [ 32.586827] hdc: TSSTcorpCD/DVDW TS-H552B, ATAPI CD/DVD-ROM drive [ 33.262572] ide1 at 0x170-0x177,0x376 on irq 15 [ 33.271029] hda: max request size: 512KiB [ 33.282788] hda: 312581808 sectors (160041 MB) w/2048KiB Cache, CHS=19457/255/63, UDMA(66) [ 33.298237] hda: cache flushes supported [ 33.306059] hda: hda1 hda2 hda3 hda4 < hda5 hda6 > [ 33.337425] hdb: max request size: 512KiB [ 33.346107] hdb: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(66) [ 33.362598] hdb: cache flushes supported [ 33.370657] hdb: hdb1 hdb2 hdb3 hdb4 < hdb5 hdb6 > [ 33.416756] hdc: ATAPI 48X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache, UDMA(33) [ 33.432752] Uniform CD-ROM driver Revision: 3.20 [ 33.442439] usbmon: debugfs is not available [ 33.702071] serio: i8042 KBD port at 0x60,0x64 irq 1 [ 33.710622] mice: PS/2 mouse device common for all mice [ 33.718629] EDAC MC: Ver: 2.0.1 Jul 9 2007 [ 33.726906] usbcore: registered new interface driver usbhid [ 33.734407] drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver [ 33.742057] Advanced Linux Sound Architecture Driver Version 1.0.14 (Thu May 31 09:03:25 2007 UTC). [ 33.758190] PCI: Found IRQ 10 for device 0000:00:07.5 [ 33.766003] PCI: Sharing IRQ 10 with 0000:00:09.1 [ 33.773681] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 33.781229] PCI: Setting latency timer of device 0000:00:07.5 to 64 [ 33.785066] input: AT Translated Set 2 keyboard as /class/input/input0 [ 34.300959] ALSA device list: [ 34.308399] #0: VIA 82C686A/B rev20 with AD1881A at 0xdc00, irq 10 [ 34.316059] TCP cubic registered [ 34.323592] NET: Registered protocol family 1 [ 34.330983] NET: Registered protocol family 17 [ 34.338332] Using IPI Shortcut mode [ 34.346164] Freeing unused kernel memory: 152k freed [ 34.353140] Write protecting the kernel text: 2220k [ 34.360092] Write protecting the kernel read-only data: 884k [ 34.713019] USB Universal Host Controller Interface driver v3.0 [ 34.719380] PCI: Found IRQ 12 for device 0000:00:07.2 [ 34.725490] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 34.731152] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.736549] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.741791] uhci_hcd 0000:00:07.2: UHCI Host Controller [ 34.747748] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1 [ 34.758357] uhci_hcd 0000:00:07.2: irq 12, io base 0x0000cc00 [ 34.764689] usb usb1: configuration #1 chosen from 1 choice [ 34.770381] hub 1-0:1.0: USB hub found [ 34.775828] hub 1-0:1.0: 2 ports detected [ 34.885588] PCI: Found IRQ 12 for device 0000:00:07.3 [ 34.891201] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 34.896749] PCI: Sharing IRQ 12 with 0000:00:09.2 [ 34.902077] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 34.907336] uhci_hcd 0000:00:07.3: UHCI Host Controller [ 34.912758] uhci_hcd 0000:00:07.3: new USB bus registered, assigned bus number 2 [ 34.923369] uhci_hcd 0000:00:07.3: irq 12, io base 0x0000d000 [ 34.929798] usb usb2: configuration #1 chosen from 1 choice [ 34.935979] hub 2-0:1.0: USB hub found [ 34.941980] hub 2-0:1.0: 2 ports detected [ 35.049361] PCI: setting IRQ 9 as level-triggered [ 35.049371] PCI: Found IRQ 9 for device 0000:00:09.0 [ 35.055538] uhci_hcd 0000:00:09.0: UHCI Host Controller [ 35.061761] uhci_hcd 0000:00:09.0: new USB bus registered, assigned bus number 3 [ 35.073726] uhci_hcd 0000:00:09.0: irq 9, io base 0x0000c400 [ 35.080842] usb usb3: configuration #1 chosen from 1 choice [ 35.087724] hub 3-0:1.0: USB hub found [ 35.094426] hub 3-0:1.0: 2 ports detected [ 35.184949] Clocksource tsc unstable (delta = 64005466 ns) [ 35.192937] Time: pit clocksource has been installed. [ 35.201338] PCI: Found IRQ 10 for device 0000:00:09.1 [ 35.207732] PCI: Sharing IRQ 10 with 0000:00:07.5 [ 35.214005] PCI: Sharing IRQ 10 with 0000:00:0a.0 [ 35.220226] uhci_hcd 0000:00:09.1: UHCI Host Controller [ 35.226627] uhci_hcd 0000:00:09.1: new USB bus registered, assigned bus number 4 [ 35.239480] uhci_hcd 0000:00:09.1: irq 10, io base 0x0000c800 [ 35.247101] usb usb4: configuration #1 chosen from 1 choice [ 35.254246] hub 4-0:1.0: USB hub found [ 35.261161] hub 4-0:1.0: 2 ports detected [ 35.360846] usb 1-2: new low speed USB device using uhci_hcd and address 2 [ 35.380201] PCI: Found IRQ 12 for device 0000:00:09.2 [ 35.387223] PCI: Sharing IRQ 12 with 0000:00:07.3 [ 35.394123] PCI: Sharing IRQ 12 with 0000:00:07.2 [ 35.400829] PCI: Sharing IRQ 12 with 0000:00:0f.0 [ 35.407389] ehci_hcd 0000:00:09.2: EHCI Host Controller [ 35.414095] ehci_hcd 0000:00:09.2: new USB bus registered, assigned bus number 5 [ 35.426770] ehci_hcd 0000:00:09.2: irq 12, io mem 0xdfffff00 [ 35.433276] ehci_hcd 0000:00:09.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004 [ 35.446937] usb usb5: configuration #1 chosen from 1 choice [ 35.453937] hub 5-0:1.0: USB hub found [ 35.460653] hub 5-0:1.0: 4 ports detected [ 35.586655] usb 1-2: configuration #1 chosen from 1 choice [ 35.616980] input: 4D Mouse USB Mouse as /class/input/input1 [ 35.624218] input: USB HID v1.00 Mouse [4D Mouse USB Mouse] on usb-0000:00:07.2-2 [ 36.072354] kjournald starting. Commit interval 5 seconds [ 36.079452] EXT3-fs: mounted filesystem with ordered data mode. [ 36.659958] usb 5-3: new high speed USB device using ehci_hcd and address 2 [ 36.797553] usb 5-3: configuration #1 chosen from 1 choice [ 44.160396] parport_pc: VIA 686A/8231 detected [ 44.160408] parport_pc: probing current configuration [ 44.160444] parport_pc: Current parallel port base: 0x378 [ 44.160624] parport0: PC-style at 0x378 (0x778), irq 7 [PCSPP(,...)] [ 44.160730] parport_pc: VIA parallel port: io=0x378, irq=7 [ 44.333685] SCSI subsystem initialized [ 44.953934] Initializing USB Mass Storage driver... [ 44.954609] scsi0 : SCSI emulation for USB Mass Storage devices [ 44.954899] usb-storage: device found at 2 [ 44.954906] usb-storage: waiting for device to settle before scanning [ 44.954966] usbcore: registered new interface driver usb-storage [ 44.954977] USB Mass Storage support registered. [ 47.803596] Floppy drive(s): fd0 is 1.44M [ 47.820265] FDC 0 is a post-1991 82077 [ 49.955147] scsi 0:0:0:0: Direct-Access ST325082 3A PQ: 0 ANSI: 0 [ 49.965543] usb-storage: device scan complete [ 50.005188] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 50.006303] sd 0:0:0:0: [sda] Write Protect is off [ 50.006314] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 50.006321] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 50.007684] sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors (250059 MB) [ 50.008728] sd 0:0:0:0: [sda] Write Protect is off [ 50.008773] sd 0:0:0:0: [sda] Mode Sense: 33 00 00 00 [ 50.008781] sd 0:0:0:0: [sda] Assuming drive cache: write through [ 50.008792] sda: sda1 [ 50.032167] sd 0:0:0:0: [sda] Attached SCSI disk [ 51.462168] EXT3 FS on hdb3, internal journal [ 51.675449] kjournald starting. Commit interval 5 seconds [ 51.675688] EXT3 FS on hda2, internal journal [ 51.675718] EXT3-fs: mounted filesystem with ordered data mode. [ 51.698000] kjournald starting. Commit interval 5 seconds [ 51.698394] EXT3 FS on hdb1, internal journal [ 51.698420] EXT3-fs: mounted filesystem with ordered data mode. [ 51.721574] kjournald starting. Commit interval 5 seconds [ 51.721968] EXT3 FS on hda3, internal journal [ 51.721994] EXT3-fs: mounted filesystem with ordered data mode. [ 51.741869] kjournald starting. Commit interval 5 seconds [ 51.742323] EXT3 FS on hda6, internal journal [ 51.742350] EXT3-fs: mounted filesystem with ordered data mode. [ 51.758531] kjournald starting. Commit interval 5 seconds [ 51.759060] EXT3 FS on hdb2, internal journal [ 51.759087] EXT3-fs: mounted filesystem with ordered data mode. [ 51.778290] kjournald starting. Commit interval 5 seconds [ 51.778686] EXT3 FS on hdb5, internal journal [ 51.778712] EXT3-fs: mounted filesystem with ordered data mode. [ 51.819091] kjournald starting. Commit interval 5 seconds [ 51.820073] EXT3 FS on sda1, internal journal [ 51.820102] EXT3-fs: mounted filesystem with ordered data mode. [ 52.610568] Adding 248968k swap on /dev/hda5. Priority:-1 extents:1 across:248968k [ 52.637059] Adding 240932k swap on /dev/hdb6. Priority:-2 extents:1 across:240932k [ 60.137033] NET: Registered protocol family 10 [ 65.726821] eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1 [ 70.572985] skge eth1: enabling interface [ 70.582947] ADDRCONF(NETDEV_UP): eth1: link is not ready [ 75.936943] eth0: no IPv6 routers present ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-17 22:31 ` Alessandro Suardi @ 2007-07-17 22:40 ` john stultz 2007-07-18 21:31 ` Alessandro Suardi 0 siblings, 1 reply; 9+ messages in thread From: john stultz @ 2007-07-17 22:40 UTC (permalink / raw) To: Alessandro Suardi Cc: Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner On Wed, 2007-07-18 at 00:31 +0200, Alessandro Suardi wrote: > On 7/11/07, john stultz <johnstul@us.ibm.com> wrote: > > On Wed, 2007-07-11 at 01:31 +0200, Alessandro Suardi wrote: > > > On 7/10/07, john stultz <johnstul@us.ibm.com> wrote: > > > > On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > > > > > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > > > > > > > > > My oldish AMD K7-800's clock began falling behind after > > > > > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > > > > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > > > > > > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > > > > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > > > > > gets the original stable system time back. > > > > > > > > Alessandro, > > > > Can you send me dmesg output for 2.6.20 and 2.6.22 (without > > > > clocksource=tsc)? > > > > > > Actually, I lied a little bit - it was 2.6.22 with clock=tsc (which > > > warns on boot about clock= being deprecated in favor of > > > clocksource= ). I assume behavior is identical for now. > > > > > > Please find attached the dmesg ring (incomplete, as the > > > kernel ring size I have seems too small to hold the full > > > buffer, but it seems to have all the interesting stuff) of > > > 2.6.20, 2.6.22, 2.6.22 with clock=tsc. > > > > > > If you need more info, just ask. I'll be out of the country > > > from July 12 to the morning of July 16, and again from > > > July 17 to July 20, so if you'd rather get at this later on, > > > it's okay for me ;) > > > > You're dmesg output got chopped at the top. Please increase the kernel > > log buffer size. > > Done, please find attached both 2620 and 2622 full dmesg output, > with no clock= or clocksource= parameters. > > > Sounds like your PIT frequency is out of whack, and I'm guessing the > > generic clocksource watchdog blames the TSC and disqualifies it. > > > > Few things to check: > > 1) Make sure you're running the latest BIOS. > > I'm probably not, though I'm not sure I'd flash anything on such > an old machine - been running it since RedHat 9 with the > current BIOS. Plus, I removed the floppy drive to make room > for an extra IDE disk... it'd take me a little bit to find out whether > I still have the floppy drive around. > > > 2) See if booting w/ noapic changes anything > > Nope, 2622+noapic => PIT is still used and clock very quickly > lags behind. > > For the moment being I'll keep booting with clocksource=tsc. > Let me know whether you want me to test anything more... Hmm. One other thing to check: If you boot 2.6.20 w/ clocksource=pit, is it consistent w/ 2.6.22 and same slow timekeeping issue shows up? thanks -john ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown 2007-07-17 22:40 ` john stultz @ 2007-07-18 21:31 ` Alessandro Suardi 0 siblings, 0 replies; 9+ messages in thread From: Alessandro Suardi @ 2007-07-18 21:31 UTC (permalink / raw) To: john stultz; +Cc: Andrew Morton, Linux Kernel Mailing List, Thomas Gleixner On 7/18/07, john stultz <johnstul@us.ibm.com> wrote: > On Wed, 2007-07-18 at 00:31 +0200, Alessandro Suardi wrote: > > On 7/11/07, john stultz <johnstul@us.ibm.com> wrote: > > > On Wed, 2007-07-11 at 01:31 +0200, Alessandro Suardi wrote: > > > > On 7/10/07, john stultz <johnstul@us.ibm.com> wrote: > > > > > On Tue, 2007-07-10 at 00:29 -0700, Andrew Morton wrote: > > > > > > On Mon, 9 Jul 2007 16:27:59 +0200 "Alessandro Suardi" <alessandro.suardi@gmail.com> wrote: > > > > > > > > > > > > > My oldish AMD K7-800's clock began falling behind after > > > > > > > rebooting from 2.6.20 (and 109 days uptime with a spotless > > > > > > > clock) into 2.6.22; time lost is about four minutes each hour. > > > > > > > > > > > > > > Turns out that 2.6.22 marks my TSC as unstable and starts > > > > > > > using PIT instead. Rebooting 2.6.22 with clocksource=tsc > > > > > > > gets the original stable system time back. > > > > > > > > > > Alessandro, > > > > > Can you send me dmesg output for 2.6.20 and 2.6.22 (without > > > > > clocksource=tsc)? > > > > > > > > Actually, I lied a little bit - it was 2.6.22 with clock=tsc (which > > > > warns on boot about clock= being deprecated in favor of > > > > clocksource= ). I assume behavior is identical for now. > > > > > > > > Please find attached the dmesg ring (incomplete, as the > > > > kernel ring size I have seems too small to hold the full > > > > buffer, but it seems to have all the interesting stuff) of > > > > 2.6.20, 2.6.22, 2.6.22 with clock=tsc. > > > > > > > > If you need more info, just ask. I'll be out of the country > > > > from July 12 to the morning of July 16, and again from > > > > July 17 to July 20, so if you'd rather get at this later on, > > > > it's okay for me ;) > > > > > > You're dmesg output got chopped at the top. Please increase the kernel > > > log buffer size. > > > > Done, please find attached both 2620 and 2622 full dmesg output, > > with no clock= or clocksource= parameters. > > > > > Sounds like your PIT frequency is out of whack, and I'm guessing the > > > generic clocksource watchdog blames the TSC and disqualifies it. > > > > > > Few things to check: > > > 1) Make sure you're running the latest BIOS. > > > > I'm probably not, though I'm not sure I'd flash anything on such > > an old machine - been running it since RedHat 9 with the > > current BIOS. Plus, I removed the floppy drive to make room > > for an extra IDE disk... it'd take me a little bit to find out whether > > I still have the floppy drive around. > > > > > 2) See if booting w/ noapic changes anything > > > > Nope, 2622+noapic => PIT is still used and clock very quickly > > lags behind. > > > > For the moment being I'll keep booting with clocksource=tsc. > > Let me know whether you want me to test anything more... > > Hmm. One other thing to check: If you boot 2.6.20 w/ clocksource=pit, is > it consistent w/ 2.6.22 and same slow timekeeping issue shows up? Yes, 2620+clocksource=pit is noticeably slow in timekeeping as well. >From my laptop (Dell D610 running 2.6.22-git10 on top of Fedora7) I ssh'd into my K7-800 and with two terminal windows I ran the same simple bash loop, starting more or less at the same time: while :; do let i=i+1; echo $i; sleep 1; done When the laptop reached 60, the K7-800 was at 57. In order to eliminate any possible doubt about how I started the two sessions, I let the loop run; when the laptop reached 120, the K7-800 was displaying 114. So it's indeed a 3-second per minute loss with PIT in either 2620 or 2622. --alessandro "Did you get married but forgot to get divorced ?" (Danny and Dusty, 'The Good Old Days') ^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2007-07-18 21:31 UTC | newest] Thread overview: 9+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2007-07-09 14:27 clocksource change of behavior in 2.6.22 compared to 2.6.20 causes massive system clock slowdown Alessandro Suardi 2007-07-10 7:29 ` Andrew Morton 2007-07-10 17:28 ` john stultz 2007-07-10 23:31 ` Alessandro Suardi 2007-07-11 21:06 ` john stultz 2007-07-12 11:03 ` Tilman Schmidt 2007-07-17 22:31 ` Alessandro Suardi 2007-07-17 22:40 ` john stultz 2007-07-18 21:31 ` Alessandro Suardi
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).