Bug#497397: linux-image-2.6.26-1-486: timing problem with kvm
Package: linux-image-2.6.26-1-486
Version: 2.6.26-4
Severity: normal
I found a kernel timing problem in 2.6.26-1-486 running as VM in kvm,
dmesg attachted. To login into the machine isn't posible, because after
I type in the username and press <Enter>, login told me, the maximum
waiting time is passed. KVM version is 63.
Greetings,
Christoph
** Kernel log:
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Linux version 2.6.26-1-486 (Debian 2.6.26-4) (waldi@debian.org) (gcc version 4.1.3 20080623 (prerelease) (Debian 4.1.2-23)) #1 Thu Aug 28 11:14:57 UTC 2008
[ 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: 00000000000e8000 - 0000000000100000 (reserved)
[ 0.000000] BIOS-e820: 0000000000100000 - 000000001fff0000 (usable)
[ 0.000000] BIOS-e820: 000000001fff0000 - 0000000020000000 (ACPI data)
[ 0.000000] BIOS-e820: 00000000fffbd000 - 0000000100000000 (reserved)
[ 0.000000] 511MB LOWMEM available.
[ 0.000000] kvm-clock: cpu 0, msr 0:3c86e1, boot clock
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0 -> 4096
[ 0.000000] Normal 4096 -> 131056
[ 0.000000] Movable zone start PFN for each node
[ 0.000000] early_node_map[1] active PFN ranges
[ 0.000000] 0: 0 -> 131056
[ 0.000000] DMI 2.4 present.
[ 0.000000] ACPI: RSDP 000FB450, 0014 (r0 QEMU )
[ 0.000000] ACPI: RSDT 1FFF0000, 002C (r1 QEMU QEMURSDT 1 QEMU 1)
[ 0.000000] ACPI: FACP 1FFF002C, 0074 (r1 QEMU QEMUFACP 1 QEMU 1)
[ 0.000000] ACPI: DSDT 1FFF0100, 1632 (r1 BXPC BXDSDT 1 INTL 20061109)
[ 0.000000] ACPI: FACS 1FFF00C0, 0040
[ 0.000000] ACPI: APIC 1FFF1738, 00E0 (r1 QEMU QEMUAPIC 1 QEMU 1)
[ 0.000000] ACPI: PM-Timer IO Port: 0xb008
[ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x03] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x04] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x05] lapic_id[0x05] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x06] lapic_id[0x06] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x07] lapic_id[0x07] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x08] lapic_id[0x08] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x09] lapic_id[0x09] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0a] lapic_id[0x0a] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0b] lapic_id[0x0b] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0c] lapic_id[0x0c] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0d] lapic_id[0x0d] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0e] lapic_id[0x0e] disabled)
[ 0.000000] ACPI: LAPIC (acpi_id[0x0f] lapic_id[0x0f] disabled)
[ 0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
[ 0.000000] IOAPIC[0]: apic_id 1, version 17, address 0xfec00000, GSI 0-23
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.000000] Enabling APIC mode: Flat. Using 1 I/O APICs
[ 0.000000] Using ACPI (MADT) for SMP configuration information
[ 0.000000] Allocating PCI resources starting at 30000000 (gap: 20000000:dffbd000)
[ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
[ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000e8000
[ 0.000000] PM: Registered nosave memory: 00000000000e8000 - 0000000000100000
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 130032
[ 0.000000] Kernel command line: root=/dev/hda2 ro console=ttyS0
[ 0.000000] Enabling fast FPU save and restore... done.
[ 0.000000] Enabling unmasked SIMD FPU exception support... done.
[ 0.000000] Initializing CPU#0
[ 0.000000] PID hash table entries: 2048 (order: 11, 8192 bytes)
[ 0.000000] Detected 2800.955 MHz processor.
[ 0.004000] Console: colour VGA+ 80x25
[ 0.004000] console [ttyS0] enabled
[ 0.004000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.004000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.004000] Memory: 510360k/524224k available (1693k kernel code, 13304k reserved, 746k data, 320k init, 0k highmem)
[ 0.004000] virtual kernel memory layout:
[ 0.004000] fixmap : 0xfffb3000 - 0xfffff000 ( 304 kB)
[ 0.004000] vmalloc : 0xe0800000 - 0xfffb1000 ( 503 MB)
[ 0.004000] lowmem : 0xc0000000 - 0xdfff0000 ( 511 MB)
[ 0.004000] .init : 0xc0364000 - 0xc03b4000 ( 320 kB)
[ 0.004000] .data : 0xc02a75d3 - 0xc0362000 ( 746 kB)
[ 0.004000] .text : 0xc0100000 - 0xc02a75d3 (1693 kB)
[ 0.004000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[ 0.088005] Calibrating delay using timer specific routine.. 10523.01 BogoMIPS (lpj=21046026)
[ 0.096006] Security Framework initialized
[ 0.096006] SELinux: Disabled at boot.
[ 0.100006] Capability LSM initialized
[ 0.100006] Mount-cache hash table entries: 512
[ 0.104006] Initializing cgroup subsys ns
[ 0.108006] Initializing cgroup subsys cpuacct
[ 0.108006] Initializing cgroup subsys devices
[ 0.112007] CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
[ 0.116007] CPU: L2 Cache: 512K (64 bytes/line)
[ 0.116007] CPU: AMD QEMU Virtual CPU version 0.9.1 stepping 03
[ 0.128008] Freeing SMP alternatives: 0k freed
[ 0.132008] ACPI: Core revision 20080321
[ 0.136008] ENABLING IO-APIC IRQs
[ 0.140008] ..TIMER: vector=0x31 apic1=0 pin1=0 apic2=-1 pin2=-1
[ 0.224014] APIC calibration not consistent with PM Timer: 184ms instead of 100ms
[ 0.224014] APIC delta adjusted to PM-Timer: 6249976 (11500632)
[ 0.228014] net_namespace: 652 bytes
[ 0.228014] Booting paravirtualized kernel on KVM
[ 0.232014] NET: Registered protocol family 16
[ 0.232014] EISA bus registered
[ 0.236014] ACPI: bus type pci registered
[ 0.236014] PCI: PCI BIOS revision 2.10 entry at 0xfadb0, last bus=0
[ 0.240015] PCI: Using configuration type 1 for base access
[ 0.244015] Setting up standard PCI resources
[ 0.248015] ACPI: Interpreter enabled
[ 0.252015] ACPI: (supports S0 S5)
[ 0.252015] ACPI: Using IOAPIC for interrupt routing
[ 0.256016] ACPI: PCI Root Bridge [PCI0] (0000:00)
[ 0.292018] pci 0000:00:01.3: quirk: region b000-b03f claimed by PIIX4 ACPI
[ 0.296018] pci 0000:00:01.3: quirk: region b100-b10f claimed by PIIX4 SMB
[ 0.304019] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[ 0.304019] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[ 0.308019] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[ 0.312019] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[ 0.316019] Linux Plug and Play Support v0.97 (c) Adam Belay
[ 0.316019] pnp: PnP ACPI init
[ 0.320020] ACPI: bus type pnp registered
[ 0.324020] pnp: PnP ACPI: found 7 devices
[ 0.324020] ACPI: ACPI bus type pnp unregistered
[ 0.328020] PnPBIOS: Disabled
[ 0.328020] PCI: Using ACPI for IRQ routing
[ 1.478184] Clocksource tsc unstable (delta = -674166761 ns)
[ 8.249591] PM-Timer running at invalid rate: 146% of normal - aborting.
[ 8.917681] NET: Registered protocol family 2
[ 9.361715] IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
[ 10.076171] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
[ 10.836908] TCP bind hash table entries: 16384 (order: 4, 65536 bytes)
[ 11.499949] TCP: Hash tables configured (established 16384 bind 16384)
[ 12.176231] TCP reno registered
[ 12.177379] NET: Registered protocol family 1
[ 12.937450] checking if image is initramfs... it is
[ 149.154801] Freeing initrd memory: 5629k freed
[ 150.969756] audit: initializing netlink socket (disabled)
[ 151.659614] type=2000 audit(3328654539.659:1): initialized
[ 152.211888] Total HugeTLB memory allocated, 0
[ 152.667909] VFS: Disk quotas dquot_6.5.1
[ 152.669604] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 153.719424] msgmni has been set to 1008
[ 154.103494] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[ 154.887741] io scheduler noop registered
[ 155.275605] io scheduler anticipatory registered
[ 155.726456] io scheduler deadline registered
[ 155.728932] io scheduler cfq registered (default)
[ 156.596990] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 156.600052] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 164.240888] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 164.849046] isapnp: Scanning for PnP cards...
[ 412.752707] isapnp: No Plug & Play device found
[ 419.549293] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
[ 420.806286] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
[ 421.434448] 00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
[ 422.076216] brd: module loaded
[ 422.076216] PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 429.569944] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 430.087204] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 430.595258] mice: PS/2 mouse device common for all mice
[ 431.136093] input: AT Translated Set 2 keyboard as /class/input/input0
[ 431.136093] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[ 432.461797] rtc0: alarms up to one day
[ 432.461797] EISA: Probing bus 0 at eisa.0
[ 433.253255] EISA: Detected 0 cards.
[ 433.253255] cpuidle: using governor ladder
[ 434.082557] cpuidle: using governor menu
[ 434.478581] No iBFT detected.
[ 434.481513] TCP cubic registered
[ 435.151495] NET: Registered protocol family 17
[ 435.607524] Using IPI Shortcut mode
[ 435.608019] registered taskstats version 1
[ 436.435759] rtc_cmos 00:01: setting system clock to 2008-09-01 09:16:49 UTC (1220260609)
[ 437.243861] Freeing unused kernel memory: 320k freed
Loading, please wait...
Begin: Loading essential drivers ... done.
Begin: Running /scripts/init-premount ... [ 497.991857] ACPI: ACPI0007:00 is registered as cooling_device0
[ 712.940031] No dock devices found.
[ 722.675097] usbcore: registered new interface driver usbfs
[ 723.271635] usbcore: registered new interface driver hub
[ 732.015167] SCSI subsystem initialized
[ 738.372317] usbcore: registered new device driver usb
[ 739.439560] USB Universal Host Controller Interface driver v3.0
[ 741.327093] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[ 741.943537] ACPI: PCI Interrupt 0000:00:01.2[D] -> Link [LNKD] -> GSI 11 (level, high) -> IRQ 11
[ 742.852212] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 742.852212] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 744.134834] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c020
[ 744.731242] usb usb1: configuration #1 chosen from 1 choice
[ 745.355290] hub 1-0:1.0: USB hub found
[ 745.742921] hub 1-0:1.0: 2 ports detected
[ 757.375898] 8139cp: 10/100 PCI Ethernet driver v1.3 (Mar 22, 2004)
[ 765.168844] FDC 0 is a S82078B
[ 771.424332] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[ 772.908539] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 773.888598] usb usb1: Product: UHCI Host Controller
[ 773.892524] usb usb1: Manufacturer: Linux 2.6.26-1-486 uhci_hcd
[ 775.338320] usb usb1: SerialNumber: 0000:00:01.2
[ 776.184190] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
[ 777.751024] ACPI: PCI Interrupt 0000:00:03.0[A] -> Link [LNKC] -> GSI 10 (level, high) -> IRQ 10
[ 779.494593] eth0: RTL-8139C+ at 0xe0874000, 54:52:00:d9:67:27, IRQ 10
[ 781.169286] Uniform Multi-Platform E-IDE driver
[ 782.370557] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
[ 784.728135] usb 1-2: new full speed USB device using uhci_hcd and address 2
[ 787.493284] PIIX3: IDE controller (0x8086:0x7010 rev 0x00) at PCI slot 0000:00:01.1
[ 788.804511] PIIX3: not 100% native mode: will probe irqs later
[ 789.616049] ide0: BM-DMA at 0xc000-0xc007
[ 789.616049] ide1: BM-DMA at 0xc008-0xc00f
[ 796.533209] 8139too Fast Ethernet driver 0.9.28
[ 802.287422] hda: QEMU HARDDISK, ATA DISK drive
[ 809.951448] usb 1-2: configuration #1 chosen from 1 choice
[ 818.432986] usb 1-2: New USB device found, idVendor=0627, idProduct=0001
[ 819.591220] usb 1-2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 820.558177] usb 1-2: Product: QEMU USB Tablet
[ 821.152296] usb 1-2: Manufacturer: QEMU 0.9.1
[ 821.152296] usb 1-2: SerialNumber: 1
[ 822.216233] hda: MWDMA2 mode selected
[ 828.726416] usbcore: registered new interface driver hiddev
[ 832.028544] input: QEMU 0.9.1 QEMU USB Tablet as /class/input/input1
[ 833.089085] input,hidraw0: USB HID v0.01 Pointer [QEMU 0.9.1 QEMU USB Tablet] on usb-0000:00:01.2-2
[ 835.578568] usbcore: registered new interface driver usbhid
[ 836.337857] usbhid: v2.6:USB HID core driver
[ 836.917431] hdc: QEMU DVD-ROM, ATAPI CD/DVD-ROM drive
[ 851.031421] hdc: MWDMA2 mode selected
[ 857.929847] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[ 858.564784] ide1 at 0x170-0x177,0x376 on irq 15
[ 875.149368] hda: max request size: 512KiB
[ 881.819307] hda: 41943040 sectors (21474 MB) w/256KiB Cache, CHS=16383/255/63
[ 882.392260] hda: cache flushes supported
[ 883.431621] hda: hda1 hda2 hda3 < hda5 >
[ 899.902854] hdc: ATAPI 4X CD-ROM drive, 512kB Cache
[ 900.309498] Uniform CD-ROM driver Revision: 3.20
done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... kinit: name_to_dev_t(/dev/hda1) = hda1(3,1)
kinit: trying to resume from /dev/hda1
[ 967.688487] PM: Starting manual resume from disk
kinit: No resume image, doing normal boot...
done.
[ 980.504026] EXT3-fs: INFO: recovery required on readonly filesystem.
[ 981.644219] EXT3-fs: write access will be enabled during recovery.
[ 1210.605565] kjournald starting. Commit interval 5 seconds
[ 1211.522568] EXT3-fs: recovery complete.
[ 1212.049771] EXT3-fs: mounted filesystem with ordered data mode.
Begin: Running /scripts/local-bottom ... done.
done.
Begin: Running /scripts/init-bottom ... done.
INIT: version 2.86 booting
[ 1418.986606] udevd version 125 started
[ 2215.005465] input: Power Button (FF) as /class/input/input2
[ 2227.497605] input: ImExPS/2 Generic Explorer Mouse as /class/input/input3
[ 2241.381506] ACPI: Power Button (FF) [PWRF]
[ 2289.297678] piix4_smbus 0000:00:01.3: Found 0000:00:01.3 device
[ 2296.501141] parport_pc 00:05: reported by Plug and Play ACPI
[ 2297.836097] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE]
[ 2403.774512] input: PC Speaker as /class/input/input4
[ 2432.850564] Error: Driver 'pcspkr' is already registered, aborting...
[ 3240.580312] loop: module loaded
[ 3469.617422] kjournald starting. Commit interval 5 seconds
[ 3470.520309] EXT3 FS on hda5, internal journal
[ 3471.348108] EXT3-fs: mounted filesystem with ordered data mode.
[ 3758.614868] eth0: link up, 100Mbps, full-duplex, lpa 0x05E1
[ 3979.572811] NET: Registered protocol family 10
[ 3980.421670] lo: Disabled Privacy Extensions
Reply to: