2.6.27.5 guest boot failure using in-kernel PIT

2.6.27.5 guest boot failure using in-kernel PIT

[Eduardo Habkost]

[-- Attachment #1: Type: text/plain, Size: 1570 bytes --]


Hi,

When using a kvm.git kernel as host, I am getting guest boot failures
when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
stops booting at:

ENABLING IO-APIC IRQs
..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
..MP-BIOS bug: 8254 timer not connected to IO-APIC
...trying to set up timer (IRQ0) through the 8259A ...
..... (found apic 0 pin 0) ...
....... failed.
...trying to set up timer as Virtual Wire IRQ...
..... failed.
...trying to set up timer as ExtINT IRQ...


When using -no-kvm-pit on qemu command-line, the guest boots properly.
The guest also boots properly when using 2.6.27.5-117.fc10.x86_64 as
the host kernel.

Guest dmesg from both cases are attached. Additional info:

host kernel:
  kvm.git commit 30d95f352f0f7da8788016894db3b2a7efdd3674

host qemu:
 kvm-userspace.git commit 0cf57d569f3204182f768bc135c9dcc1c36a98bc

qemu command lines:

fails: qemu-system-x86_64 -m 512 -serial stdio -kernel /boot/vmlinuz-2.6.27.5-117.fc10.x86_64 -append 'console=ttyS0,115200 apic=debug'

works: qemu-system-x86_64 -m 512 -serial stdio -kernel /boot/vmlinuz-2.6.27.5-117.fc10.x86_64 -append 'console=ttyS0,115200 apic=debug' -no-kvm-pit


Some debugging using systemtap indicated that on some point
kvm_pic_reset() runs but doesn't ack the timer IRQ for some reason,
then kvm_inject_pit_timer_irqs() stops injecting IRQs because irq_ack
is cleared.

It looks like the bug commit fa7fed6d2dfa9f62c658414ca1a1be0b2cc94438
tried to fix, but somehow kvm_pic_reset() is still failing to ack the
timer interrupts on my case.

-- 
Eduardo

[-- Attachment #2: dmesg-ok.txt --]
[-- Type: text/plain, Size: 12144 bytes --]

Initializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.27.5-117.fc10.x86_64 (mockbuild@x86-1.fedora.phx.redhat.com) (gcc version 4.3.2 20081105 (Red Hat 4.3.2-7) (GCC) ) #1 SMP Tue Nov 18 11:58:53 EST 2008
Command line: console=ttyS0,115200 apic=debug
KERNEL supported cpus:
  Intel GenuineIntel
  AMD AuthenticAMD
  Centaur CentaurHauls
PAT WC disabled due to known CPU erratum.
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
 BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000001fff0000 (usable)
 BIOS-e820: 000000001fff0000 - 0000000020000000 (ACPI data)
 BIOS-e820: 00000000fffbd000 - 0000000100000000 (reserved)
last_pfn = 0x1fff0 max_arch_pfn = 0x3ffffffff
init_memory_mapping
last_map_addr: 1fff0000 end: 1fff0000
DMI 2.4 present.
ACPI: RSDP 000FBC80, 0014 (r0 QEMU  )
ACPI: RSDT 1FFF0000, 002C (r1 QEMU   QEMURSDT        1 QEMU        1)
ACPI: FACP 1FFF002C, 0074 (r1 QEMU   QEMUFACP        1 QEMU        1)
ACPI: DSDT 1FFF0100, 24A4 (r1   BXPC   BXDSDT        1 INTL 20061109)
ACPI: FACS 1FFF00C0, 0040
ACPI: APIC 1FFF25A8, 00E0 (r1 QEMU   QEMUAPIC        1 QEMU        1)
No NUMA configuration found
Faking a node at 0000000000000000-000000001fff0000
Bootmem setup node 0 0000000000000000-000000001fff0000
  NODE_DATA [0000000000009000 - 000000000001dfff]
  bootmap [000000000001e000 -  0000000000021fff] pages 4
(5 early reservations) ==> bootmem [0000000000 - 001fff0000]
  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
  #1 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
  #2 [0000200000 - 0000a2b20c]    TEXT DATA BSS ==> [0000200000 - 0000a2b20c]
  #3 [000009fc00 - 0000100000]    BIOS reserved ==> [000009fc00 - 0000100000]
  #4 [0000008000 - 0000009000]          PGTABLE ==> [0000008000 - 0000009000]
Scan SMP from ffff880000000000 for 1024 bytes.
Scan SMP from ffff88000009fc00 for 1024 bytes.
Scan SMP from ffff8800000f0000 for 65536 bytes.
found SMP MP-table at [ffff8800000fbb60] 000fbb60
kvm-clock: cpu 0, msr 0:8de481, boot clock
Zone PFN ranges:
  DMA      0x00000000 -> 0x00001000
  DMA32    0x00001000 -> 0x00100000
  Normal   0x00100000 -> 0x00100000
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
    0: 0x00000000 -> 0x0000009f
    0: 0x00000100 -> 0x0001fff0
ACPI: PM-Timer IO Port: 0xb008
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] disabled)
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] disabled)
ACPI: LAPIC (acpi_id[0x03] lapic_id[0x03] disabled)
ACPI: LAPIC (acpi_id[0x04] lapic_id[0x04] disabled)
ACPI: LAPIC (acpi_id[0x05] lapic_id[0x05] disabled)
ACPI: LAPIC (acpi_id[0x06] lapic_id[0x06] disabled)
ACPI: LAPIC (acpi_id[0x07] lapic_id[0x07] disabled)
ACPI: LAPIC (acpi_id[0x08] lapic_id[0x08] disabled)
ACPI: LAPIC (acpi_id[0x09] lapic_id[0x09] disabled)
ACPI: LAPIC (acpi_id[0x0a] lapic_id[0x0a] disabled)
ACPI: LAPIC (acpi_id[0x0b] lapic_id[0x0b] disabled)
ACPI: LAPIC (acpi_id[0x0c] lapic_id[0x0c] disabled)
ACPI: LAPIC (acpi_id[0x0d] lapic_id[0x0d] disabled)
ACPI: LAPIC (acpi_id[0x0e] lapic_id[0x0e] disabled)
ACPI: LAPIC (acpi_id[0x0f] lapic_id[0x0f] disabled)
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, version 0, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
Setting APIC routing to flat
Using ACPI (MADT) for SMP configuration information
SMP: Allowing 16 CPUs, 15 hotplug CPUs
mapped APIC to ffffffffff5fc000 (        fee00000)
mapped IOAPIC to ffffffffff5fb000 (00000000fec00000)
PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000e8000
PM: Registered nosave memory: 00000000000e8000 - 0000000000100000
Allocating PCI resources starting at 30000000 (gap: 20000000:dffbd000)
PERCPU: Allocating 65184 bytes of per cpu data
kvm-clock: cpu 0, msr 0:1014481, primary cpu clock
Built 1 zonelists in Node order, mobility grouping on.  Total pages: 126974
Policy zone: DMA32
Kernel command line: console=ttyS0,115200 apic=debug
Initializing CPU#0
PID hash table entries: 2048 (order: 11, 16384 bytes)
TSC: PIT calibration confirmed by PMTIMER.
TSC: using PIT calibration value
Detected 1596.074 MHz processor.
Console: colour VGA+ 80x25
console [ttyS0] enabled
Checking aperture...
No AGP bridge found
Memory: 506008k/524224k available (3300k kernel code, 17828k reserved, 1838k data, 1288k init)
SLUB: Genslabs=13, HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
Calibrating delay loop (skipped), value calculated using timer frequency.. 3192.14 BogoMIPS (lpj=1596074)
Security Framework initialized
SELinux:  Initializing.
Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
Mount-cache hash table entries: 256
Initializing cgroup subsys ns
Initializing cgroup subsys cpuacct
Initializing cgroup subsys devices
PAT WC disabled due to known CPU erratum.
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 2048K
CPU 0/0 -> Node 0
SMP alternatives: switching to UP code
ACPI: Core revision 20080609
Getting VERSION: 50014
Getting VERSION: 50014
Getting ID: 0
Getting ID: ff000000
Getting LVT0: 700
Getting LVT1: 10000
enabled ExtINT on CPU#0
ENABLING IO-APIC IRQs
..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
CPU0: QEMU Virtual CPU version 0.9.1 stepping 03
Using local APIC timer interrupts.
Detected 62.491 MHz APIC timer.
Brought up 1 CPUs
Total of 1 processors activated (3192.14 BogoMIPS).
net_namespace: 1552 bytes
Booting paravirtualized kernel on KVM
Time: 13:42:53  Date: 11/20/08
NET: Registered protocol family 16
No dock devices found.
ACPI: bus type pci registered
PCI: Using configuration type 1 for base access
ACPI: Interpreter enabled
ACPI: (supports S0 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: PCI Root Bridge [PCI0] (0000:00)
pci 0000:00:01.3: quirk: region b000-b03f claimed by PIIX4 ACPI
pci 0000:00:01.3: quirk: region b100-b10f claimed by PIIX4 SMB
ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 7 devices
ACPI: ACPI bus type pnp unregistered
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
testing the IO APIC.......................

.................................... done.
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
PCI-GART: No AMD northbridge found.
tracer: 1286 pages allocated for 65536 entries of 80 bytes
   actual entries 65586
bus: 00 index 0 io port: [0, ffff]
bus: 00 index 1 mmio: [0, ffffffffffffffff]
NET: Registered protocol family 2
IP route cache hash table entries: 4096 (order: 3, 32768 bytes)
TCP established hash table entries: 16384 (order: 6, 262144 bytes)
TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
TCP: Hash tables configured (established 16384 bind 16384)
TCP reno registered
NET: Registered protocol family 1
audit: initializing netlink socket (disabled)
type=2000 audit(1227188575.206:1): initialized
HugeTLB registered 2 MB page size, pre-allocated 0 pages
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
msgmni has been set to 988
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
pci 0000:00:00.0: Limiting direct PCI/PCI transfers
pci 0000:00:01.0: PIIX3: Enabling Passive Release
pci 0000:00:01.0: Activating ISA DMA hang workarounds
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
acpiphp_glue: can't get bus number, assuming 0
decode_hpp: Could not get hotplug parameters. Use defaults
acpiphp: Slot [1] registered
acpiphp: Slot [2] registered
acpiphp: Slot [3] registered
acpiphp: Slot [4] registered
acpiphp: Slot [5] registered
acpiphp: Slot [6] registered
acpiphp: Slot [7] registered
acpiphp: Slot [8] registered
acpiphp: Slot [9] registered
acpiphp: Slot [10] registered
acpiphp: Slot [11] registered
acpiphp: Slot [12] registered
acpiphp: Slot [13] registered
acpiphp: Slot [14] registered
acpiphp: Slot [15] registered
acpiphp: Slot [16] registered
acpiphp: Slot [17] registered
acpiphp: Slot [18] registered
acpiphp: Slot [19] registered
acpiphp: Slot [20] registered
acpiphp: Slot [21] registered
acpiphp: Slot [22] registered
acpiphp: Slot [23] registered
acpiphp: Slot [24] registered
acpiphp: Slot [25] registered
acpiphp: Slot [26] registered
acpiphp: Slot [27] registered
acpiphp: Slot [28] registered
acpiphp: Slot [29] registered
acpiphp: Slot [30] registered
acpiphp: Slot [31] registered
input: Power Button (FF) as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
ACPI: Power Button (FF) [PWRF]
processor ACPI0007:00: registered as cooling_device0
Non-volatile memory driver v1.2
Linux agpgart interface v0.103
Serial: 8250/16550 driver4 ports, IRQ sharing enabled
ÿserial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
brd: module loaded
loop: module loaded
input: Macintosh mouse button emulation as /devices/virtual/input/input1
Driver 'sd' needs updating - please use bus_type methods
Driver 'sr' needs updating - please use bus_type methods
scsi0 : ata_piix
scsi1 : ata_piix
ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc000 irq 14
ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc008 irq 15
ata2.00: ATAPI: QEMU DVD-ROM, 0.9.1, max UDMA/100
ata2.00: configured for MWDMA2
isa bounce pool size: 16 pages
scsi 1:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     0.9. PQ: 0 ANSI: 5
sr0: scsi3-mmc drive: 4x/4x xa/form2 tray
Uniform CD-ROM driver Revision: 3.20
sr 1:0:0:0: Attached scsi generic sg0 type 5
USB Universal Host Controller Interface driver v3.0
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
rtc0: alarms up to one day
device-mapper: uevent: version 1.0.3
device-mapper: ioctl: 4.14.0-ioctl (2008-04-23) initialised: dm-devel@redhat.com
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input2
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver hiddev
usbcore: registered new interface driver usbhid
usbhid: v2.6:USB HID core driver
nf_conntrack version 0.5.0 (4096 buckets, 16384 max)
CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Plase use
nf_conntrack.acct=1 kernel paramater, acct=1 nf_conntrack module option or
sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
ip_tables: (C) 2000-2006 Netfilter Core Team
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 17
registered taskstats version 1
  Magic number: 0:596:736
input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
md: Autodetecting RAID arrays.
md: Scanned 0 and added 0 devices.
md: autorun ...
md: ... autorun DONE.
EXT3-fs: unable to read superblock
isofs_fill_super: bread failed, dev=md2, iso_blknum=16, block=32
List of all partitions:
0b00    1048575 sr0 driver: sr
No filesystem could mount root, tried:  ext3 iso9660
Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(9,2)


[-- Attachment #3: dmesg-fail.txt --]
[-- Type: text/plain, Size: 5938 bytes --]

Initializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.27.5-117.fc10.x86_64 (mockbuild@x86-1.fedora.phx.redhat.com) (gcc version 4.3.2 20081105 (Red Hat 4.3.2-7) (GCC) ) #1 SMP Tue Nov 18 11:58:53 EST 2008
Command line: console=ttyS0,115200 apic=debug
KERNEL supported cpus:
  Intel GenuineIntel
  AMD AuthenticAMD
  Centaur CentaurHauls
PAT WC disabled due to known CPU erratum.
BIOS-provided physical RAM map:
 BIOS-e820: 0000000000000000 - 000000000009fc00 (usable)
 BIOS-e820: 000000000009fc00 - 00000000000a0000 (reserved)
 BIOS-e820: 00000000000e8000 - 0000000000100000 (reserved)
 BIOS-e820: 0000000000100000 - 000000001fff0000 (usable)
 BIOS-e820: 000000001fff0000 - 0000000020000000 (ACPI data)
 BIOS-e820: 00000000fffbd000 - 0000000100000000 (reserved)
last_pfn = 0x1fff0 max_arch_pfn = 0x3ffffffff
init_memory_mapping
last_map_addr: 1fff0000 end: 1fff0000
DMI 2.4 present.
ACPI: RSDP 000FBC80, 0014 (r0 QEMU  )
ACPI: RSDT 1FFF0000, 002C (r1 QEMU   QEMURSDT        1 QEMU        1)
ACPI: FACP 1FFF002C, 0074 (r1 QEMU   QEMUFACP        1 QEMU        1)
ACPI: DSDT 1FFF0100, 24A4 (r1   BXPC   BXDSDT        1 INTL 20061109)
ACPI: FACS 1FFF00C0, 0040
ACPI: APIC 1FFF25A8, 00E0 (r1 QEMU   QEMUAPIC        1 QEMU        1)
No NUMA configuration found
Faking a node at 0000000000000000-000000001fff0000
Bootmem setup node 0 0000000000000000-000000001fff0000
  NODE_DATA [0000000000009000 - 000000000001dfff]
  bootmap [000000000001e000 -  0000000000021fff] pages 4
(5 early reservations) ==> bootmem [0000000000 - 001fff0000]
  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
  #1 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
  #2 [0000200000 - 0000a2b20c]    TEXT DATA BSS ==> [0000200000 - 0000a2b20c]
  #3 [000009fc00 - 0000100000]    BIOS reserved ==> [000009fc00 - 0000100000]
  #4 [0000008000 - 0000009000]          PGTABLE ==> [0000008000 - 0000009000]
Scan SMP from ffff880000000000 for 1024 bytes.
Scan SMP from ffff88000009fc00 for 1024 bytes.
Scan SMP from ffff8800000f0000 for 65536 bytes.
found SMP MP-table at [ffff8800000fbb60] 000fbb60
kvm-clock: cpu 0, msr 0:8de481, boot clock
Zone PFN ranges:
  DMA      0x00000000 -> 0x00001000
  DMA32    0x00001000 -> 0x00100000
  Normal   0x00100000 -> 0x00100000
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
    0: 0x00000000 -> 0x0000009f
    0: 0x00000100 -> 0x0001fff0
ACPI: PM-Timer IO Port: 0xb008
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] disabled)
ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] disabled)
ACPI: LAPIC (acpi_id[0x03] lapic_id[0x03] disabled)
ACPI: LAPIC (acpi_id[0x04] lapic_id[0x04] disabled)
ACPI: LAPIC (acpi_id[0x05] lapic_id[0x05] disabled)
ACPI: LAPIC (acpi_id[0x06] lapic_id[0x06] disabled)
ACPI: LAPIC (acpi_id[0x07] lapic_id[0x07] disabled)
ACPI: LAPIC (acpi_id[0x08] lapic_id[0x08] disabled)
ACPI: LAPIC (acpi_id[0x09] lapic_id[0x09] disabled)
ACPI: LAPIC (acpi_id[0x0a] lapic_id[0x0a] disabled)
ACPI: LAPIC (acpi_id[0x0b] lapic_id[0x0b] disabled)
ACPI: LAPIC (acpi_id[0x0c] lapic_id[0x0c] disabled)
ACPI: LAPIC (acpi_id[0x0d] lapic_id[0x0d] disabled)
ACPI: LAPIC (acpi_id[0x0e] lapic_id[0x0e] disabled)
ACPI: LAPIC (acpi_id[0x0f] lapic_id[0x0f] disabled)
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, version 0, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
Setting APIC routing to flat
Using ACPI (MADT) for SMP configuration information
SMP: Allowing 16 CPUs, 15 hotplug CPUs
mapped APIC to ffffffffff5fc000 (        fee00000)
mapped IOAPIC to ffffffffff5fb000 (00000000fec00000)
PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000e8000
PM: Registered nosave memory: 00000000000e8000 - 0000000000100000
Allocating PCI resources starting at 30000000 (gap: 20000000:dffbd000)
PERCPU: Allocating 65184 bytes of per cpu data
kvm-clock: cpu 0, msr 0:1014481, primary cpu clock
Built 1 zonelists in Node order, mobility grouping on.  Total pages: 126974
Policy zone: DMA32
Kernel command line: console=ttyS0,115200 apic=debug
Initializing CPU#0
PID hash table entries: 2048 (order: 11, 16384 bytes)
TSC: PIT calibration confirmed by PMTIMER.
TSC: using PIT calibration value
Detected 1596.214 MHz processor.
Console: colour VGA+ 80x25
console [ttyS0] enabled
Checking aperture...
No AGP bridge found
Memory: 506008k/524224k available (3300k kernel code, 17828k reserved, 1838k data, 1288k init)
SLUB: Genslabs=13, HWalign=64, Order=0-3, MinObjects=0, CPUs=16, Nodes=1
Calibrating delay loop (skipped), value calculated using timer frequency.. 3192.42 BogoMIPS (lpj=1596214)
Security Framework initialized
SELinux:  Initializing.
Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
Mount-cache hash table entries: 256
Initializing cgroup subsys ns
Initializing cgroup subsys cpuacct
Initializing cgroup subsys devices
PAT WC disabled due to known CPU erratum.
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 2048K
CPU 0/0 -> Node 0
SMP alternatives: switching to UP code
ACPI: Core revision 20080609
Getting VERSION: 50014
Getting VERSION: 50014
Getting ID: 0
Getting ID: ff000000
Getting LVT0: 700
Getting LVT1: 10000
enabled ExtINT on CPU#0
ENABLING IO-APIC IRQs
..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
..MP-BIOS bug: 8254 timer not connected to IO-APIC
...trying to set up timer (IRQ0) through the 8259A ...
..... (found apic 0 pin 0) ...
....... failed.
...trying to set up timer as Virtual Wire IRQ...
..... failed.
...trying to set up timer as ExtINT IRQ...

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Eduardo Habkost]

On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
> 
> Hi,
> 
> When using a kvm.git kernel as host, I am getting guest boot failures
> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
> stops booting at:
> 
> ENABLING IO-APIC IRQs
> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
> ...trying to set up timer (IRQ0) through the 8259A ...
> ..... (found apic 0 pin 0) ...
> ....... failed.
> ...trying to set up timer as Virtual Wire IRQ...
> ..... failed.
> ...trying to set up timer as ExtINT IRQ...

I've just found out this problem happens because the guest has HZ=1000
and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.

With this setup, the host is not managing to inject enough timer
interrupts during the mdelay() loop on timer_irq_works().

-- 
Eduardo

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Sheng Yang]

On Friday 21 November 2008 06:05:17 Eduardo Habkost wrote:
> On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
> > Hi,
> >
> > When using a kvm.git kernel as host, I am getting guest boot failures
> > when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
> > stops booting at:
> >
> > ENABLING IO-APIC IRQs
> > ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
> > ..MP-BIOS bug: 8254 timer not connected to IO-APIC
> > ...trying to set up timer (IRQ0) through the 8259A ...
> > ..... (found apic 0 pin 0) ...
> > ....... failed.
> > ...trying to set up timer as Virtual Wire IRQ...
> > ..... failed.
> > ...trying to set up timer as ExtINT IRQ...
>
> I've just found out this problem happens because the guest has HZ=1000
> and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
>
> With this setup, the host is not managing to inject enough timer
> interrupts during the mdelay() loop on timer_irq_works().

So, do we need to depend on CONFIG_HIGH_RES_TIMERS? I think most modern 
machine should have this.

-- 
regards
Yang, Sheng

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Jan Kiszka]

[-- Attachment #1: Type: text/plain, Size: 1445 bytes --]

Eduardo Habkost wrote:
> On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
>> Hi,
>>
>> When using a kvm.git kernel as host, I am getting guest boot failures
>> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
>> stops booting at:
>>
>> ENABLING IO-APIC IRQs
>> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
>> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
>> ...trying to set up timer (IRQ0) through the 8259A ...
>> ..... (found apic 0 pin 0) ...
>> ....... failed.
>> ...trying to set up timer as Virtual Wire IRQ...
>> ..... failed.
>> ...trying to set up timer as ExtINT IRQ...
> 
> I've just found out this problem happens because the guest has HZ=1000
> and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
> 
> With this setup, the host is not managing to inject enough timer
> interrupts during the mdelay() loop on timer_irq_works().
> 

Interesting, and plausible.

My observation so far is a sporadic test failure, often correlating with
some raised host OS load. I'm running a high-res kernel, but that cannot
prevent that this only 10 ticks long loop of the guest may obtain too
few CPU cycles to handle enough of them once in a while (IIRC, it needs
4 out of the 10 ticks to declare the timer routing functional).

Maybe Gleb's anti-coalesce patches for the PIC can also deal with your
timer resolution conflict. At least worth a try...

Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 257 bytes --]

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Eduardo Habkost]

On Fri, Nov 21, 2008 at 08:54:56AM +0100, Jan Kiszka wrote:
> Eduardo Habkost wrote:
> > On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
> >> Hi,
> >>
> >> When using a kvm.git kernel as host, I am getting guest boot failures
> >> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
> >> stops booting at:
> >>
> >> ENABLING IO-APIC IRQs
> >> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
> >> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
> >> ...trying to set up timer (IRQ0) through the 8259A ...
> >> ..... (found apic 0 pin 0) ...
> >> ....... failed.
> >> ...trying to set up timer as Virtual Wire IRQ...
> >> ..... failed.
> >> ...trying to set up timer as ExtINT IRQ...
> > 
> > I've just found out this problem happens because the guest has HZ=1000
> > and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
> > 
> > With this setup, the host is not managing to inject enough timer
> > interrupts during the mdelay() loop on timer_irq_works().
> > 
> 
> Interesting, and plausible.
> 
> My observation so far is a sporadic test failure, often correlating with
> some raised host OS load. I'm running a high-res kernel, but that cannot
> prevent that this only 10 ticks long loop of the guest may obtain too
> few CPU cycles to handle enough of them once in a while (IIRC, it needs
> 4 out of the 10 ticks to declare the timer routing functional).
> 
> Maybe Gleb's anti-coalesce patches for the PIC can also deal with your
> timer resolution conflict. At least worth a try...

Aren't Gleb patches for the userspace PIT? I am seeing the problem here
when using the in-kernel PIT, but (surprisingly) my setup works when
using -no-kvm-pit.

-- 
Eduardo

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Jan Kiszka]

[-- Attachment #1: Type: text/plain, Size: 2010 bytes --]

Eduardo Habkost wrote:
> On Fri, Nov 21, 2008 at 08:54:56AM +0100, Jan Kiszka wrote:
>> Eduardo Habkost wrote:
>>> On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
>>>> Hi,
>>>>
>>>> When using a kvm.git kernel as host, I am getting guest boot failures
>>>> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
>>>> stops booting at:
>>>>
>>>> ENABLING IO-APIC IRQs
>>>> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
>>>> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
>>>> ...trying to set up timer (IRQ0) through the 8259A ...
>>>> ..... (found apic 0 pin 0) ...
>>>> ....... failed.
>>>> ...trying to set up timer as Virtual Wire IRQ...
>>>> ..... failed.
>>>> ...trying to set up timer as ExtINT IRQ...
>>> I've just found out this problem happens because the guest has HZ=1000
>>> and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
>>>
>>> With this setup, the host is not managing to inject enough timer
>>> interrupts during the mdelay() loop on timer_irq_works().
>>>
>> Interesting, and plausible.
>>
>> My observation so far is a sporadic test failure, often correlating with
>> some raised host OS load. I'm running a high-res kernel, but that cannot
>> prevent that this only 10 ticks long loop of the guest may obtain too
>> few CPU cycles to handle enough of them once in a while (IIRC, it needs
>> 4 out of the 10 ticks to declare the timer routing functional).
>>
>> Maybe Gleb's anti-coalesce patches for the PIC can also deal with your
>> timer resolution conflict. At least worth a try...
> 
> Aren't Gleb patches for the userspace PIT?

Yeah, they are, so you won't benefit from them for in-kernel cases. But
with in-kernel emulation just the probability of coalesced ticks is a
bit lower, they cannot be avoided either.

> I am seeing the problem here
> when using the in-kernel PIT, but (surprisingly) my setup works when
> using -no-kvm-pit.

Weird, makes no sense to me as well ATM.

Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 257 bytes --]

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Eduardo Habkost]

On Fri, Nov 21, 2008 at 04:41:00PM +0100, Jan Kiszka wrote:
> Eduardo Habkost wrote:
> > On Fri, Nov 21, 2008 at 08:54:56AM +0100, Jan Kiszka wrote:
> >> Eduardo Habkost wrote:
> >>> On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
> >>>> Hi,
> >>>>
> >>>> When using a kvm.git kernel as host, I am getting guest boot failures
> >>>> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
> >>>> stops booting at:
> >>>>
> >>>> ENABLING IO-APIC IRQs
> >>>> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
> >>>> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
> >>>> ...trying to set up timer (IRQ0) through the 8259A ...
> >>>> ..... (found apic 0 pin 0) ...
> >>>> ....... failed.
> >>>> ...trying to set up timer as Virtual Wire IRQ...
> >>>> ..... failed.
> >>>> ...trying to set up timer as ExtINT IRQ...
> >>> I've just found out this problem happens because the guest has HZ=1000
> >>> and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
> >>>
> >>> With this setup, the host is not managing to inject enough timer
> >>> interrupts during the mdelay() loop on timer_irq_works().
> >>>
> >> Interesting, and plausible.
> >>
> >> My observation so far is a sporadic test failure, often correlating with
> >> some raised host OS load. I'm running a high-res kernel, but that cannot
> >> prevent that this only 10 ticks long loop of the guest may obtain too
> >> few CPU cycles to handle enough of them once in a while (IIRC, it needs
> >> 4 out of the 10 ticks to declare the timer routing functional).
> >>
> >> Maybe Gleb's anti-coalesce patches for the PIC can also deal with your
> >> timer resolution conflict. At least worth a try...
> > 
> > Aren't Gleb patches for the userspace PIT?
> 
> Yeah, they are, so you won't benefit from them for in-kernel cases. But
> with in-kernel emulation just the probability of coalesced ticks is a
> bit lower, they cannot be avoided either.
> 
> > I am seeing the problem here
> > when using the in-kernel PIT, but (surprisingly) my setup works when
> > using -no-kvm-pit.
> 
> Weird, makes no sense to me as well ATM.

The qemu PIT seems to calculate the timeout for its timer as a function
of the time where the PIT timer was set up (count_load_time) and the
last timer set up (next_transition_time), without looking at the current
time. After missing some ticks and getting the timer triggered late,
it will set up a lot of "trigger on the past" timers before the guest
finished the mdelay() loop.

The in-kernel PIT seems to try to do the same thing (it just calls
hrtimer_add_expires_ns() on the timer), but maybe the behaviour of the
kernel timers is different of the qemu timers when a timer is set up
to be triggered on the past. On my host-HZ=250 guest-HZ=1000 setup,
it was incrementing pit_timer.pending only once every 4 milliseconds.

-- 
Eduardo

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Eduardo Habkost]

On Fri, Nov 21, 2008 at 02:39:22PM -0200, Eduardo Habkost wrote:
> On Fri, Nov 21, 2008 at 04:41:00PM +0100, Jan Kiszka wrote:
> > Eduardo Habkost wrote:
<snip>
> > > I am seeing the problem here
> > > when using the in-kernel PIT, but (surprisingly) my setup works when
> > > using -no-kvm-pit.
> > 
> > Weird, makes no sense to me as well ATM.
> 
> The qemu PIT seems to calculate the timeout for its timer as a function
> of the time where the PIT timer was set up (count_load_time) and the
> last timer set up (next_transition_time), without looking at the current
> time. After missing some ticks and getting the timer triggered late,
> it will set up a lot of "trigger on the past" timers before the guest
> finished the mdelay() loop.
> 
> The in-kernel PIT seems to try to do the same thing (it just calls
> hrtimer_add_expires_ns() on the timer), but maybe the behaviour of the
> kernel timers is different of the qemu timers when a timer is set up
> to be triggered on the past. On my host-HZ=250 guest-HZ=1000 setup,
> it was incrementing pit_timer.pending only once every 4 milliseconds.

That's the case. From a probe on __pit_timer_fn.return:
19344471136382 timer_fn returning. timer expires now at: 19343448496177
19344475128359 timer_fn returning. timer expires now at: 19343449496025
19344479128694 timer_fn returning. timer expires now at: 19343450495873
19344483129394 timer_fn returning. timer expires now at: 19343451495721

The number at the beginning of the lines is ktime_get(). The timer
expiration time is on the past, but the kernel keeps triggering the
timer once every 4 ms.

-- 
Eduardo

hrtimer_forward() semantics when using non-high-res timers

[Eduardo Habkost]

Hi, Thomas,

I've been looking at a timer problem on KVM recently[1] and I've got a
question about the expected semantics of hrtimer_forward().

The problem I am looking at is related to having proper accouting of
missed ticks on the KVM timer code when it the host has lost timer
ticks because of high CPU load, or because it doesn't have hrtimers
enabled. hrtimer_forward_now() overrun accounting looked perfect for
the task of checking how many ticks we have lost.

However hrtimer_forward() limits the interval parameter to the timer
resolution, making it useless for calculating how many timer periods we've
lost because of too-low timer resolution. I am even a bit surprised no
other code needs a hrtimer_forward-like function for that, yet.

For example: if we want to account for a tick every 1 ms and the host
has HZ=250 and no high-resolution timers, calling hrtimer_forward_now()
on every timer tick will normally return 1 because it will count how
many 4 ms periods were added to the timer expiration time. However,
I would like to calculate how many 1 ms periods I've lost, no matter
what the real timer resolution is.

I could do my own missed-ticks calculation, but the hrtimer_forward()
logic would be perfect for my needs if it didn't have the resolution check
code, and I don't feel like duplicating part of hrtimer_forward(). Do you
think it would make sense to have on the timers API a hrtimer_forward-like
function that doesn't have the interval lower-limit?


[1] http://marc.info/?l=kvm&m=122728725028262&w=2

-- 
Eduardo

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Marcelo Tosatti]

Hi Jan,

On Fri, Nov 21, 2008 at 08:54:56AM +0100, Jan Kiszka wrote:
> Eduardo Habkost wrote:
> > On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
> >> Hi,
> >>
> >> When using a kvm.git kernel as host, I am getting guest boot failures
> >> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
> >> stops booting at:
> >>
> >> ENABLING IO-APIC IRQs
> >> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
> >> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
> >> ...trying to set up timer (IRQ0) through the 8259A ...
> >> ..... (found apic 0 pin 0) ...
> >> ....... failed.
> >> ...trying to set up timer as Virtual Wire IRQ...
> >> ..... failed.
> >> ...trying to set up timer as ExtINT IRQ...
> > 
> > I've just found out this problem happens because the guest has HZ=1000
> > and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
> > 
> > With this setup, the host is not managing to inject enough timer
> > interrupts during the mdelay() loop on timer_irq_works().
> > 
> 
> Interesting, and plausible.
> 
> My observation so far is a sporadic test failure, often correlating with
> some raised host OS load. I'm running a high-res kernel, but that cannot
> prevent that this only 10 ticks long loop of the guest may obtain too
> few CPU cycles to handle enough of them once in a while (IIRC, it needs
> 4 out of the 10 ticks to declare the timer routing functional).

Using in-kernel PIT?

This is a potential problem which can be worked around by disabling the
whole thing either via no_timer_check or paravirt equivalent (Glauber?)
but for the non-paravirt case it seems its not the culprit. Possible
failure scenarios:

1) lpj miscalibration (SMP guests), which kvm-clock deals with.

2) proper lpj calibration, so m/udelay behave as expected, but not
enough interrupts can be injected due to CPU starvation as you mention.

On my testbox, with each pCPU running a cycle hog on nice -10, the first
timer_irq_works call (via IOAPIC) won't fail (guest is truly starved).
Host with both CONFIG_PREEMPT/CONFIG_PREEMPT_VOLUNTARY.

And moreover, code attempts to first deliver via IOAPIC, then 8259A, 
then virtual wire. Reports show all three failing.

3) Failure to inject the interrupt will break the in-kernel PIT ack
logic. The VMX NMI/IRQ race you fixed can certainly cause this. Can you
reproduce it with the fix (and CONFIG_KVM_CLOCK=y) ?

Any other possibilities? 

> Maybe Gleb's anti-coalesce patches for the PIC can also deal with your
> timer resolution conflict. At least worth a try...
> 
> Jan
> 

Re: 2.6.27.5 guest boot failure using in-kernel PIT

[Glauber Costa]

On Fri, Nov 21, 2008 at 3:10 PM, Marcelo Tosatti <mtosatti@redhat.com> wrote:
> Hi Jan,
>
> On Fri, Nov 21, 2008 at 08:54:56AM +0100, Jan Kiszka wrote:
>> Eduardo Habkost wrote:
>> > On Thu, Nov 20, 2008 at 12:22:53PM -0200, Eduardo Habkost wrote:
>> >> Hi,
>> >>
>> >> When using a kvm.git kernel as host, I am getting guest boot failures
>> >> when booting Fedora Rawhide kernel (2.6.27.5-117.fc10.x86_64). Guest
>> >> stops booting at:
>> >>
>> >> ENABLING IO-APIC IRQs
>> >> ..TIMER: vector=0x30 apic1=0 pin1=0 apic2=-1 pin2=-1
>> >> ..MP-BIOS bug: 8254 timer not connected to IO-APIC
>> >> ...trying to set up timer (IRQ0) through the 8259A ...
>> >> ..... (found apic 0 pin 0) ...
>> >> ....... failed.
>> >> ...trying to set up timer as Virtual Wire IRQ...
>> >> ..... failed.
>> >> ...trying to set up timer as ExtINT IRQ...
>> >
>> > I've just found out this problem happens because the guest has HZ=1000
>> > and the host had HZ=250 and no CONFIG_HIGH_RES_TIMERS.
>> >
>> > With this setup, the host is not managing to inject enough timer
>> > interrupts during the mdelay() loop on timer_irq_works().
>> >
>>
>> Interesting, and plausible.
>>
>> My observation so far is a sporadic test failure, often correlating with
>> some raised host OS load. I'm running a high-res kernel, but that cannot
>> prevent that this only 10 ticks long loop of the guest may obtain too
>> few CPU cycles to handle enough of them once in a while (IIRC, it needs
>> 4 out of the 10 ticks to declare the timer routing functional).
>
> Using in-kernel PIT?
>
> This is a potential problem which can be worked around by disabling the
> whole thing either via no_timer_check or paravirt equivalent (Glauber?)
> but for the non-paravirt case it seems its not the culprit. Possible
> failure scenarios:

For KVM_CLOCK case, I believe there's absolutely no reason to be more
complicated than than that:

+extern int no_timer_check;
+
 void __init kvmclock_init(void)
 {
 	if (!kvm_para_available())
@@ -178,6 +180,8 @@ void __init kvmclock_init(void)
 	if (kvmclock && kvm_para_has_feature(KVM_FEATURE_CLOCKSOURCE)) {
 		if (kvm_register_clock("boot clock"))
 			return;
+
+		no_timer_check = 1;	
 		pv_time_ops.get_wallclock = kvm_get_wallclock;
 		pv_time_ops.set_wallclock = kvm_set_wallclock;
 		pv_time_ops.sched_clock = kvm_clock_read;