Re: Failing back to INSANE timesource :) Time stopped today.

From: Niclas Gustafsson
Date: Tue Apr 13 2004 - 03:27:54 EST


Hi,

Sorry for the late reply I was away on Easter holidays.

I'm attaching both the dmesg output (dmesg.265-IBM305_2) and the
unpacked /proc/config.gz (config.gz.IBM_265_2)

However the last lines from dmesg:
---
> set_rtc_mmss: can't update from 52 to 0
> > set_rtc_mmss: can't update from 53 to 1
> > set_rtc_mmss: can't update from 54 to 2
> > set_rtc_mmss: can't update from 55 to 3
> > set_rtc_mmss: can't update from 56 to 4
> > set_rtc_mmss: can't update from 57 to 5
> > set_rtc_mmss: can't update from 58 to 6
> > Losing too many ticks!
> > TSC cannot be used as a timesource. <4>Possible reasons for this are:
> > You're running with Speedstep,
> > You don't have DMA enabled for your hard disk (see hdparm),
> > Incorrect TSC synchronization on an SMP system (see dmesg).
---

Were not synched to disk before I rebooted the system.


I've compiled a new kernel that seems to be working better although I
need to run some more tests to be sure.


Regards,

Niclas Gustafsson


fre 2004-04-09 klockan 00.58 skrev john stultz:
> On Thu, 2004-04-08 at 02:21, Niclas Gustafsson wrote:
> > Hi,
> >
> > I'm running Linux 2.6.5 on a IBM xSeries 305 with a Intel P4 2.8Ghz.
> >
> > And something is very very wrong, I'm getting the following last
> > messages in dmesg:
> >
> > ------
> > set_rtc_mmss: can't update from 52 to 0
> > set_rtc_mmss: can't update from 53 to 1
> > set_rtc_mmss: can't update from 54 to 2
> > set_rtc_mmss: can't update from 55 to 3
> > set_rtc_mmss: can't update from 56 to 4
> > set_rtc_mmss: can't update from 57 to 5
> > set_rtc_mmss: can't update from 58 to 6
> > Losing too many ticks!
> > TSC cannot be used as a timesource. <4>Possible reasons for this are:
> > You're running with Speedstep,
> > You don't have DMA enabled for your hard disk (see hdparm),
> > Incorrect TSC synchronization on an SMP system (see dmesg).
> > ------
> >
> > The problem seesm to be related to heavy loads.
> > I experienced a similar problem yesterday. The machine completly hung
> > after that and i had to cut the power to reboot it. Now however it is
> > responsive and I can log on to it through ssh.
> >
> > Problem is that the clock stopped completly! - I've never seen anything
> > like this before.
> >
> > Local time is about 11 am here and a time gives me:
> >
> > [root@s151 root]# date
> > Thu Apr 8 03:51:21 CEST 2004
> >
> > ...10 s later, using my wristwatch, not sleep 10 ;)
> >
> > [root@s151 root]# date
> > Thu Apr 8 03:51:21 CEST 2004
> >
> >
> > Any ideas anyone, I'd really like to know why it is behaving this way.
>
> Huh. Very very odd.
>
> Does /proc/interrupts show timer ticks increasing?
> Does setting the date change anything?
>
> Would you mind sending me your complete dmesg?
>
> I'll look into reproducing the error here if you can give me a better
> description of what triggers it and how frequently you see the problem.
>
> thanks
> -john
>
>
>
IBM ) @ 0x000fe030
ACPI: RSDT (v001 IBM M51SL 0x00000001 IBM 0x00000000) @ 0x3ffe0000
ACPI: FADT (v001 IBM M51SL 0x00000001 IBM 0x00000000) @ 0x3ffe014b
ACPI: ASF! (v016 IBM 0x01000000 0x00000000) @ 0x3ffe0030
ACPI: MADT (v001 IBM M51SL 0x00000001 IBM 0x00000000) @ 0x3ffe00e3
ACPI: DSDT (v001 IBM M51SL 0x00001000 MSFT 0x0100000d) @ 0x00000000
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
Processor #0 15:2 APIC version 20
ACPI: LAPIC_NMI (acpi_id[0xff] high edge lint[0x1])
ACPI: IOAPIC (id[0x01] address[0xfec00000] global_irq_base[0x0])
IOAPIC[0]: Assigned apic_id 1
IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-15
ACPI: IOAPIC (id[0x02] address[0xfec01000] global_irq_base[0x10])
IOAPIC[1]: Assigned apic_id 2
IOAPIC[1]: apic_id 2, version 17, address 0xfec01000, GSI 16-31
ACPI: IOAPIC (id[0x03] address[0xfec02000] global_irq_base[0x20])
IOAPIC[2]: Assigned apic_id 3
IOAPIC[2]: apic_id 3, version 17, address 0xfec02000, GSI 32-47
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
Enabling APIC mode: Flat. Using 3 I/O APICs
Using ACPI (MADT) for SMP configuration information
Built 1 zonelists
Kernel command line: root=/dev/sda2
Initializing CPU#0
PID hash table entries: 4096 (order 12: 32768 bytes)
Detected 2800.545 MHz processor.
Using tsc for high-res timesource
Console: colour VGA+ 80x25
Memory: 1033864k/1048448k available (1981k kernel code, 13688k reserved, 749k data, 344k init, 130944k highmem)
Checking if this processor honours the WP bit even in supervisor mode... Ok.
Calibrating delay loop... 5505.02 BogoMIPS
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
CPU: After generic identify, caps: bfebfbff 00000000 00000000 00000000
CPU: After vendor identify, caps: bfebfbff 00000000 00000000 00000000
CPU: Trace cache: 12K uops, L1 D cache: 8K
CPU: L2 cache: 512K
CPU: After all inits, caps: bfebfbff 00000000 00000000 00000080
Intel machine check architecture supported.
Intel machine check reporting enabled on CPU#0.
CPU#0: Intel P4/Xeon Extended MCE MSRs (12) available
CPU: Intel(R) Pentium(R) 4 CPU 2.80GHz stepping 09
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Checking 'hlt' instruction... OK.
POSIX conformance testing by UNIFIX
enabled ExtINT on CPU#0
ESR value before enabling vector: 00000000
ESR value after enabling vector: 00000000
ENABLING IO-APIC IRQs
init IO_APIC IRQs
IO-APIC (apicid-pin) 1-0, 2-0, 2-1, 2-2, 2-3, 2-4, 2-5, 2-6, 2-7, 2-8, 2-9, 2-10, 2-11, 2-12, 2-13, 2-14, 2-15, 3-0, 3-1, 3-2, 3-3, 3-4, 3-5, 3-6, 3-7, 3-8, 3-9, 3-10, 3-11, 3-12, 3-13, 3-14, 3-15 not connected.
..TIMER: vector=0x31 pin1=2 pin2=-1
..MP-BIOS bug: 8254 timer not connected to IO-APIC
...trying to set up timer (IRQ0) through the 8259A ... failed.
...trying to set up timer as Virtual Wire IRQ... works.
Using local APIC timer interrupts.
calibrating APIC timer ...
..... CPU clock speed is 2798.0746 MHz.
..... host bus clock speed is 133.0273 MHz.
NET: Registered protocol family 16
PCI: PCI BIOS revision 2.10 entry at 0xf0220, last bus=2
PCI: Using configuration type 1
mtrr: v2.0 (20020519)
ACPI: Subsystem revision 20040326
tbxface-0117 [03] acpi_load_tables : ACPI Tables successfully acquired
Parsing all Control Methods:............................................................................................................................................................................................
Table [DSDT](id F004) - 618 Objects with 53 Devices 188 Methods 27 Regions
ACPI Namespace successfully loaded at root c041873c
evxfevnt-0093 [04] acpi_enable : Transition to ACPI mode successful
evgpeblk-0867 [06] ev_create_gpe_block : GPE 00 to 31 [_GPE] 4 regs at 0000000000000428 on int 9
evgpeblk-0925 [06] ev_create_gpe_block : Found 0 Wake, Enabled 1 Runtime GPEs in this block
evgpeblk-0867 [06] ev_create_gpe_block : GPE 32 to 63 [_GPE] 4 regs at 0000000000000528 on int 9
evgpeblk-0925 [06] ev_create_gpe_block : Found 0 Wake, Enabled 7 Runtime GPEs in this block
Completing Region/Field/Buffer/Package initialization:.....................................................
Initialized 27/27 Regions 0/0 Fields 14/14 Buffers 12/12 Packages (627 nodes)
Executing all Device _STA and_INI methods:.......................................................
55 Devices found containing: 55 _STA, 1 _INI methods
ACPI: Interpreter enabled
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Interrupt Link [PII0] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII1] (IRQs 3 4 5 6 7 *9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII2] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII3] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII4] (IRQs 3 4 5 6 7 9 10 *11 12 14 15)
ACPI: PCI Interrupt Link [PII5] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII6] (IRQs 3 4 5 6 *7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII7] (IRQs 3 4 *5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII8] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PII9] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIA] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIB] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIC] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIID] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIE] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIF] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI10] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI11] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI12] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI13] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI14] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PI15] (IRQs 3 4 5 6 7 9 10 11 12 14 15)
ACPI: PCI Interrupt Link [PIIU] (IRQs 3 4 5 6 7 9 *10 11 12 14 15)
ACPI: PCI Root Bridge [PCI0] (00:00)
PCI: Probing PCI hardware (bus 00)
PCI: Ignoring BAR0-3 of IDE controller 0000:00:0f.1
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Root Bridge [PCI1] (00:01)
PCI: Probing PCI hardware (bus 01)
ACPI: PCI Interrupt Routing Table [\_SB_.PCI1._PRT]
ACPI: PCI Root Bridge [PCI2] (00:02)
PCI: Probing PCI hardware (bus 02)
ACPI: PCI Interrupt Routing Table [\_SB_.PCI2._PRT]
SCSI subsystem initialized
/usr/src/linux-2.6.5/drivers/usb/core/usb.c: registered new driver usbfs
/usr/src/linux-2.6.5/drivers/usb/core/usb.c: registered new driver hub
IOAPIC[1]: Set PCI routing entry (2-1 -> 0xa9 -> IRQ 17 Mode:1 Active:1)
00:00:03[A] -> 2-1 -> IRQ 17
ACPI: PCI Interrupt Link [PIIU] enabled at IRQ 10
IOAPIC[0]: Set PCI routing entry (1-10 -> 0x79 -> IRQ 10 Mode:1 Active:1)
00:00:0f[A] -> 1-10 -> IRQ 10
IOAPIC[1]: Set PCI routing entry (2-0 -> 0xb1 -> IRQ 16 Mode:1 Active:1)
00:00:02[A] -> 2-0 -> IRQ 16
IOAPIC[1]: Set PCI routing entry (2-2 -> 0xb9 -> IRQ 18 Mode:1 Active:1)
00:01:02[A] -> 2-2 -> IRQ 18
IOAPIC[1]: Set PCI routing entry (2-3 -> 0xc1 -> IRQ 19 Mode:1 Active:1)
00:01:02[B] -> 2-3 -> IRQ 19
IOAPIC[1]: Set PCI routing entry (2-4 -> 0xc9 -> IRQ 20 Mode:1 Active:1)
00:01:03[A] -> 2-4 -> IRQ 20
IOAPIC[1]: Set PCI routing entry (2-5 -> 0xd1 -> IRQ 21 Mode:1 Active:1)
00:01:03[B] -> 2-5 -> IRQ 21
IOAPIC[1]: Set PCI routing entry (2-6 -> 0xd9 -> IRQ 22 Mode:1 Active:1)
00:02:04[A] -> 2-6 -> IRQ 22
IOAPIC[1]: Set PCI routing entry (2-7 -> 0xe1 -> IRQ 23 Mode:1 Active:1)
00:02:05[A] -> 2-7 -> IRQ 23
number of MP IRQ sources: 15.
number of IO-APIC #1 registers: 16.
number of IO-APIC #2 registers: 16.
number of IO-APIC #3 registers: 16.
testing the IO APIC.......................
IO APIC #1......
.... register #00: 01000000
....... : physical APIC id: 01
....... : Delivery Type: 0
....... : LTS : 0
.... register #01: 000F0011
....... : max redirection entries: 000F
....... : PRQ implemented: 0
....... : IO APIC version: 0011
.... register #02: 01000000
....... : arbitration: 01
.... IRQ redirection table:
NR Log Phy Mask Trig IRR Pol Stat Dest Deli Vect:
00 000 00 1 0 0 0 0 0 0 00
01 001 01 0 0 0 0 0 1 1 39
02 000 00 1 0 0 0 0 0 0 00
03 001 01 0 0 0 0 0 1 1 41
04 001 01 0 0 0 0 0 1 1 49
05 001 01 0 0 0 0 0 1 1 51
06 001 01 0 0 0 0 0 1 1 59
07 001 01 0 0 0 0 0 1 1 61
08 001 01 0 0 0 0 0 1 1 69
09 001 01 0 1 0 1 0 1 1 71
0a 001 01 1 1 0 1 0 1 1 79
0b 001 01 0 0 0 0 0 1 1 81
0c 001 01 0 0 0 0 0 1 1 89
0d 001 01 0 0 0 0 0 1 1 91
0e 001 01 0 0 0 0 0 1 1 99
0f 001 01 0 0 0 0 0 1 1 A1
IO APIC #2......
.... register #00: 02000000
....... : physical APIC id: 02
....... : Delivery Type: 0
....... : LTS : 0
.... register #01: 000F0011
....... : max redirection entries: 000F
....... : PRQ implemented: 0
....... : IO APIC version: 0011
.... register #02: 02000000
....... : arbitration: 02
.... IRQ redirection table:
NR Log Phy Mask Trig IRR Pol Stat Dest Deli Vect:
00 001 01 1 1 0 1 0 1 1 B1
01 001 01 1 1 0 1 0 1 1 A9
02 001 01 1 1 0 1 0 1 1 B9
03 001 01 1 1 0 1 0 1 1 C1
04 001 01 1 1 0 1 0 1 1 C9
05 001 01 1 1 0 1 0 1 1 D1
06 001 01 1 1 0 1 0 1 1 D9
07 001 01 1 1 0 1 0 1 1 E1
08 023 03 1 0 0 0 0 0 2 00
09 00C 0C 1 0 0 0 0 0 2 08
0a 000 00 1 0 0 0 0 0 0 00
0b 000 00 1 0 0 0 0 0 0 00
0c 000 00 1 0 0 0 0 0 0 00
0d 000 00 1 0 0 0 0 0 0 00
0e 000 00 1 0 0 0 0 0 0 00
0f 000 00 1 0 0 0 0 0 0 00
IO APIC #3......
.... register #00: 03000000
....... : physical APIC id: 03
....... : Delivery Type: 0
....... : LTS : 0
.... register #01: 000F0011
....... : max redirection entries: 000F
....... : PRQ implemented: 0
....... : IO APIC version: 0011
.... register #02: 03000000
....... : arbitration: 03
.... IRQ redirection table:
NR Log Phy Mask Trig IRR Pol Stat Dest Deli Vect:
00 000 00 1 0 0 0 0 0 0 00
01 000 00 1 0 0 0 0 0 0 00
02 000 00 1 0 0 0 0 0 0 00
03 000 00 1 0 0 0 0 0 0 00
04 000 00 1 0 0 0 0 0 0 00
05 000 00 1 0 0 0 0 0 0 00
06 000 00 1 0 0 0 0 0 0 00
07 060 00 1 0 0 0 0 0 2 44
08 000 00 1 0 0 0 0 0 0 00
09 000 00 1 0 0 0 0 0 0 00
0a 000 00 1 0 0 0 0 0 0 00
0b 000 00 1 0 0 0 0 0 0 00
0c 000 00 1 0 0 0 0 0 0 00
0d 000 00 1 0 0 0 0 0 0 00
0e 000 00 1 0 0 0 0 0 0 00
0f 000 00 1 0 0 0 0 0 0 00
IRQ to pin mappings:
IRQ0 -> 0:2
IRQ1 -> 0:1
IRQ3 -> 0:3
IRQ4 -> 0:4
IRQ5 -> 0:5
IRQ6 -> 0:6
IRQ7 -> 0:7
IRQ8 -> 0:8
IRQ9 -> 0:9
IRQ10 -> 0:10
IRQ11 -> 0:11
IRQ12 -> 0:12
IRQ13 -> 0:13
IRQ14 -> 0:14
IRQ15 -> 0:15
IRQ16 -> 1:0
IRQ17 -> 1:1
IRQ18 -> 1:2
IRQ19 -> 1:3
IRQ20 -> 1:4
IRQ21 -> 1:5
IRQ22 -> 1:6
IRQ23 -> 1:7
.................................... done.
PCI: Using ACPI for IRQ routing
PCI: if you experience problems, try using option 'pci=noacpi' or even 'acpi=off'
Machine check exception polling timer started.
ikconfig 0.7 with /proc/config*
highmem bounce pool size: 64 pages
Installing knfsd (copyright (C) 1996 okir@xxxxxxxxxxxx).
Initializing Cryptographic API
lp: driver loaded but no devices found
Serial: 8250/16550 driver $Revision: 1.90 $ 8 ports, IRQ sharing disabled
ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Using anticipatory io scheduler
Floppy drive(s): fd0 is 1.44M
FDC 0 is a National Semiconductor PC87306
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
hdb: CD-224E, ATAPI CD/DVD-ROM drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
hdb: ATAPI 24X CD-ROM drive, 128kB Cache
Uniform CD-ROM driver Revision: 3.20
scsi0 : Adaptec AIC7XXX EISA/VLB/PCI SCSI HBA DRIVER, Rev 6.2.36
<Adaptec 29160B Ultra160 SCSI adapter>
aic7892: Ultra160 Wide Channel A, SCSI Id=7, 32/253 SCBs

(scsi0:A:0): 160.000MB/s transfers (80.000MHz DT, offset 127, 16bit)
Vendor: IBM-ESXS Model: DTN018W3UWDY10FN Rev: S23J
Type: Direct-Access ANSI SCSI revision: 03
scsi0:A:0:0: Tagged Queuing enabled. Depth 32
SCSI device sda: 35548320 512-byte hdwr sectors (18201 MB)
SCSI device sda: drive cache: write through
sda: sda1 sda2 sda3
Attached scsi disk sda at scsi0, channel 0, id 0, lun 0
Fusion MPT base driver 3.01.01
Copyright (c) 1999-2004 LSI Logic Corporation
Fusion MPT SCSI Host driver 3.01.01
ohci_hcd: 2004 Feb 02 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
ohci_hcd: block sizes: ed 64 td 64
ohci_hcd 0000:00:0f.2: ServerWorks OSB4/CSB5 OHCI USB Controller
ohci_hcd 0000:00:0f.2: irq 10, pci mem f880b000
ohci_hcd 0000:00:0f.2: new USB bus registered, assigned bus number 1
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
/usr/src/linux-2.6.5/drivers/usb/core/usb.c: registered new driver hid
/usr/src/linux-2.6.5/drivers/usb/input/hid-core.c: v2.0:USB HID core driver
mice: PS/2 mouse device common for all mice
serio: i8042 AUX port at 0x60,0x64 irq 12
serio: i8042 KBD port at 0x60,0x64 irq 1
NET: Registered protocol family 2
IP: routing cache hash table of 8192 buckets, 64Kbytes
TCP: Hash tables configured (established 262144 bind 65536)
NET: Registered protocol family 1
NET: Registered protocol family 17
EXT3-fs: INFO: recovery required on readonly filesystem.
EXT3-fs: write access will be enabled during recovery.
kjournald starting. Commit interval 5 seconds
EXT3-fs: sda2: orphan cleanup on readonly fs
ext3_orphan_cleanup: deleting unreferenced inode 213361
ext3_orphan_cleanup: deleting unreferenced inode 213364
EXT3-fs: sda2: 2 orphan inodes deleted
EXT3-fs: recovery complete.
EXT3-fs: mounted filesystem with ordered data mode.
VFS: Mounted root (ext3 filesystem) readonly.
Freeing unused kernel memory: 344k freed
EXT3 FS on sda2, internal journal
Adding 522104k swap on /dev/sda3. Priority:-1 extents:1
kjournald starting. Commit interval 5 seconds
EXT3 FS on sda1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
tg3.c:v2.9 (March 8, 2004)
eth0: Tigon3 [partno(BCM95703A30) rev 1002 PHY(5703)] (PCIX:100MHz:64-bit) 10/100/1000BaseT Ethernet 00:0d:60:0f:5f:7a
eth1: Tigon3 [partno(BCM95703A30) rev 1002 PHY(5703)] (PCIX:100MHz:64-bit) 10/100/1000BaseT Ethernet 00:0d:60:0f:5f:7b
tg3: eth0: Link is up at 100 Mbps, full duplex.
tg3: eth0: Flow control is on for TX and on for RX.

Attachment: config.gz.IBM-265_2
Description: GNU Zip compressed data