Re: 2.6.35-rc1 regression with pvclock and smp guests

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 2010-07-26 20:59, Arjan Koers wrote:

> I ran into the same problem. 2.6.34.1 and 2.6.35-rc6 SMP guest
> kernels hang during boot.


It appears that last is way ahead of ret twice.
The kernel boots with this debug patch that makes the clock go
backwards if the difference is big:

 	last = atomic64_read(&last_value);
 	do {
-		if (ret < last)
-			return last;
+		if (ret < last) {
+			if ( last - ret < 25000000 )
+				return last;
+			else
+				printk("pvclock backwards: ret = %llx; last = %llx\n", ret, last);
+		}
 		last = atomic64_cmpxchg(&last_value, last, ret);
 	} while (unlikely(last != ret));


Here's the boot log:

[    0.000000] Linux version 2.6.35-rc6-201007272047-guestmp+ (arjan@dev-lenny) (gcc version 4.3.2 (Debian 4.3.2-1.1) ) #1 SMP Tue Jul 27 20:52:36 UTC 2010
[    0.000000] Command line: root=/dev/vda1 ro single
[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  BIOS-e820: 0000000000000000 - 000000000009bc00 (usable)
[    0.000000]  BIOS-e820: 000000000009bc00 - 00000000000a0000 (reserved)
[    0.000000]  BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
[    0.000000]  BIOS-e820: 0000000000100000 - 000000001fffd000 (usable)
[    0.000000]  BIOS-e820: 000000001fffd000 - 0000000020000000 (reserved)
[    0.000000]  BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI 2.4 present.
[    0.000000] e820 update range: 0000000000000000 - 0000000000001000 (usable) ==> (reserved)
[    0.000000] e820 remove range: 00000000000a0000 - 0000000000100000 (usable)
[    0.000000] No AGP bridge found
[    0.000000] last_pfn = 0x1fffd max_arch_pfn = 0x400000000
[    0.000000] MTRR default type: write-back
[    0.000000] MTRR fixed ranges enabled:
[    0.000000]   00000-9FFFF write-back
[    0.000000]   A0000-BFFFF uncachable
[    0.000000]   C0000-FFFFF write-protect
[    0.000000] MTRR variable ranges enabled:
[    0.000000]   0 base 00E0000000 mask FFE0000000 uncachable
[    0.000000]   1 disabled
[    0.000000]   2 disabled
[    0.000000]   3 disabled
[    0.000000]   4 disabled
[    0.000000]   5 disabled
[    0.000000]   6 disabled
[    0.000000]   7 disabled
[    0.000000] x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
[    0.000000] initial memory mapped : 0 - 20000000
[    0.000000] Using GB pages for direct mapping
[    0.000000] init_memory_mapping: 0000000000000000-000000001fffd000
[    0.000000]  0000000000 - 001fe00000 page 2M
[    0.000000]  001fe00000 - 001fffd000 page 4k
[    0.000000] kernel direct mapping tables up to 1fffd000 @ 8000-b000
[    0.000000] RAMDISK: 1fdfc000 - 1ffed000
[    0.000000] ACPI: RSDP 00000000000fdb80 00014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 000000001fffde10 00034 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 000000001ffffe40 00074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 000000001fffdfd0 01E22 (v01   BXPC   BXDSDT 00000001 INTL 20090123)
[    0.000000] ACPI: FACS 000000001ffffe00 00040
[    0.000000] ACPI: SSDT 000000001fffdf80 00044 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 000000001fffde90 0007A (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: HPET 000000001fffde50 00038 (v01 BOCHS  BXPCHPET 00000001 BXPC 00000001)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] kvm-clock: Using msrs 12 and 11
[    0.000000] kvm-clock: cpu 0, msr 0:1344c01, boot clock
[    0.000000]  [ffffea0000000000-ffffea00007fffff] PMD -> [ffff880001c00000-ffff8800023fffff] on node 0
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA      0x00000001 -> 0x00001000
[    0.000000]   DMA32    0x00001000 -> 0x00100000
[    0.000000]   Normal   empty
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[2] active PFN ranges
[    0.000000]     0: 0x00000001 -> 0x0000009b
[    0.000000]     0: 0x00000100 -> 0x0001fffd
[    0.000000] On node 0 totalpages: 130967
[    0.000000]   DMA zone: 56 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 3938 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 1736 pages used for memmap
[    0.000000]   DMA32 zone: 125237 pages, LIFO batch:31
[    0.000000] ACPI: PM-Timer IO Port: 0xb008
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[    0.000000] ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
[    0.000000] IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    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] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ2 used by override.
[    0.000000] ACPI: IRQ5 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] ACPI: IRQ10 used by override.
[    0.000000] ACPI: IRQ11 used by override.
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.000000] SMP: Allowing 2 CPUs, 0 hotplug CPUs
[    0.000000] nr_irqs_gsi: 40
[    0.000000] Allocating PCI resources starting at 20000000 (gap: 20000000:dffc0000)
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] setup_percpu: NR_CPUS:6 nr_cpumask_bits:6 nr_cpu_ids:2 nr_node_ids:1
[    0.000000] early_res array is doubled to 64 at [3000 - 37ff]
[    0.000000] PERCPU: Embedded 26 pages/cpu @ffff880001400000 s75712 r8192 d22592 u1048576
[    0.000000] pcpu-alloc: s75712 r8192 d22592 u1048576 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 0 1
[    0.000000] kvm-clock: cpu 0, msr 0:1411c01, primary cpu clock
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 129175
[    0.000000] Kernel command line: root=/dev/vda1 ro single
[    0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.000000] Checking aperture...
[    0.000000] No AGP bridge found
[    0.000000] Subtract (38 early reservations)
[    0.000000]   #1 [0001000000 - 00013f4378]   TEXT DATA BSS
[    0.000000]   #2 [001fdfc000 - 001ffed000]         RAMDISK
[    0.000000]   #3 [000009bc00 - 0000100000]   BIOS reserved
[    0.000000]   #4 [00013f5000 - 00013f5071]             BRK
[    0.000000]   #5 [0000001000 - 0000003000]      TRAMPOLINE
[    0.000000]   #6 [0000008000 - 0000009000]         PGTABLE
[    0.000000]   #7 [00013f5080 - 00013f6080]         BOOTMEM
[    0.000000]   #8 [00013f4380 - 00013f43e0]         BOOTMEM
[    0.000000]   #9 [0001bf7000 - 0001bf8000]         BOOTMEM
[    0.000000]   #10 [0001bf8000 - 0001bf9000]         BOOTMEM
[    0.000000]   #11 [0001c00000 - 0002400000]        MEMMAP 0
[    0.000000]   #12 [00013f4400 - 00013f4580]         BOOTMEM
[    0.000000]   #13 [00013f6080 - 00013f9080]         BOOTMEM
[    0.000000]   #14 [00013fa000 - 00013fb000]         BOOTMEM
[    0.000000]   #15 [00013f4580 - 00013f45c1]         BOOTMEM
[    0.000000]   #16 [00013f4600 - 00013f4643]         BOOTMEM
[    0.000000]   #17 [00013f4680 - 00013f4808]         BOOTMEM
[    0.000000]   #18 [00013f4840 - 00013f48a8]         BOOTMEM
[    0.000000]   #19 [00013f48c0 - 00013f4928]         BOOTMEM
[    0.000000]   #20 [00013f4940 - 00013f49a8]         BOOTMEM
[    0.000000]   #21 [00013f49c0 - 00013f4a28]         BOOTMEM
[    0.000000]   #22 [00013f4a40 - 00013f4aa8]         BOOTMEM
[    0.000000]   #23 [00013f4ac0 - 00013f4b28]         BOOTMEM
[    0.000000]   #24 [00013f4b40 - 00013f4b59]         BOOTMEM
[    0.000000]   #25 [00013f4b80 - 00013f4b99]         BOOTMEM
[    0.000000]   #26 [0001400000 - 000141a000]         BOOTMEM
[    0.000000]   #27 [0001500000 - 000151a000]         BOOTMEM
[    0.000000]   #28 [00013f4bc0 - 00013f4bc8]         BOOTMEM
[    0.000000]   #29 [00013f4c00 - 00013f4c08]         BOOTMEM
[    0.000000]   #30 [00013f4c40 - 00013f4c48]         BOOTMEM
[    0.000000]   #31 [00013f4c80 - 00013f4c90]         BOOTMEM
[    0.000000]   #32 [00013f4cc0 - 00013f4e00]         BOOTMEM
[    0.000000]   #33 [00013f4e00 - 00013f4e60]         BOOTMEM
[    0.000000]   #34 [00013f4e80 - 00013f4ee0]         BOOTMEM
[    0.000000]   #35 [00013fb000 - 00013ff000]         BOOTMEM
[    0.000000]   #36 [000141a000 - 000149a000]         BOOTMEM
[    0.000000]   #37 [000149a000 - 00014da000]         BOOTMEM
[    0.000000] Memory: 508600k/524276k available (2135k kernel code, 408k absent, 15268k reserved, 1134k data, 464k init)
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	RCU-based detection of stalled CPUs is disabled.
[    0.000000] 	Verbose stalled-CPUs detection is disabled.
[    0.000000] NR_IRQS:448
[    0.000000] Console: colour VGA+ 80x25
[    0.000000] console [tty0] enabled
[    0.000000] hpet clockevent registered
[    0.000000] Detected 2799.520 MHz processor.
[    0.016000] Calibrating delay loop (skipped) preset value.. 5599.04 BogoMIPS (lpj=11198080)
[    0.016000] pid_max: default: 32768 minimum: 301
[    0.016000] Mount-cache hash table entries: 256
[    0.016000] using C1E aware idle routine
[    0.016000] Performance Events: AMD PMU driver.
[    0.016000] ... version:                0
[    0.016000] ... bit width:              48
[    0.016000] ... generic registers:      4
[    0.016004] ... value mask:             0000ffffffffffff
[    0.016388] ... max period:             00007fffffffffff
[    0.016767] ... fixed-purpose events:   0
[    0.017109] ... event mask:             000000000000000f
[    0.021772] Freeing SMP alternatives: 12k freed
[    0.022135] ACPI: Core revision 20100428
[    0.024224] Setting APIC routing to flat
[    0.026212] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.026608] CPU0: AMD Athlon(tm) II X2 240 Processor stepping 02
[    0.028000] Booting Node   0, Processors  #1 Ok.
[    0.016000] kvm-clock: cpu 1, msr 0:1511c01, secondary cpu clock
[    0.037105] pvclock backwards: ret = 108372ffd10b; last = 210aff03671a
[    0.037119] BUG: recent printk recursion!
[    0.037120] <6>Brought up 2 CPUs
[    0.037122] Total of 2 processors activated (11198.08 BogoMIPS).
[    0.037118] x86 PAT enabled: cpu 1, old 0x0, new 0x7010600070106
[    0.040000] pvclock backwards: ret = 108373705fe2; last = 210aff61470a
[    0.044219] BUG: recent printk recursion!
[    0.044220] <6>NET: Registered protocol family 16
[    0.048108] ACPI: bus type pci registered
[    0.048447] PCI: Using configuration type 1 for base access
[    0.048855] PCI: Using configuration type 1 for extended access
[    0.049280] mtrr: your CPUs had inconsistent variable MTRR settings
[    0.049280] mtrr: your CPUs had inconsistent MTRRdefType settings
[    0.049280] mtrr: probably your BIOS does not setup all CPUs.
[    0.052005] mtrr: corrected configuration.
[    0.060192] bio: create slab <bio-0> at 0
[    0.060806] ACPI: EC: Look up EC in DSDT
[    0.065677] ACPI: Interpreter enabled
[    0.066004] ACPI: (supports S0 S5)
[    0.066406] ACPI: Using IOAPIC for interrupt routing
[    0.084131] PCI: Ignoring host bridge windows from ACPI; if necessary, use "pci=use_crs" and report a bug
[    0.086541] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.088068] pci_root PNP0A03:00: host bridge window [io  0x0000-0x0cf7] (ignored)
[    0.088072] pci_root PNP0A03:00: host bridge window [io  0x0d00-0xffff] (ignored)
[    0.088075] pci_root PNP0A03:00: host bridge window [mem 0x000a0000-0x000bffff] (ignored)
[    0.088078] pci_root PNP0A03:00: host bridge window [mem 0xe0000000-0xfebfffff] (ignored)
[    0.088713] pci 0000:00:01.1: reg 20: [io  0xc000-0xc00f]
[    0.089004] pci 0000:00:01.3: quirk: [io  0xb000-0xb03f] claimed by PIIX4 ACPI
[    0.092010] pci 0000:00:01.3: quirk: [io  0xb100-0xb10f] claimed by PIIX4 SMB
[    0.097988] pci 0000:00:02.0: reg 10: [mem 0xf0000000-0xf1ffffff pref]
[    0.098912] pci 0000:00:02.0: reg 14: [mem 0xf2000000-0xf2000fff]
[    0.104911] pci 0000:00:03.0: reg 10: [io  0xc020-0xc03f]
[    0.104980] pci 0000:00:03.0: reg 14: [mem 0xf2001000-0xf2001fff]
[    0.105330] pci 0000:00:04.0: reg 10: [io  0xc040-0xc05f]
[    0.105636] pci 0000:00:05.0: reg 10: [io  0xc080-0xc0bf]
[    0.105940] pci 0000:00:06.0: reg 10: [io  0xc0c0-0xc0ff]
[    0.106325] pci_bus 0000:00: on NUMA node 0
[    0.106382] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[    0.116539] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    0.117359] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    0.118458] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    0.120675] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    0.121798] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[    0.124010] vgaarb: loaded
[    0.124570] PCI: Using ACPI for IRQ routing
[    0.124605] PCI: pci_cache_line_size set to 64 bytes
[    0.124781] reserve RAM buffer: 000000000009bc00 - 000000000009ffff
[    0.124789] reserve RAM buffer: 000000001fffd000 - 000000001fffffff
[    0.124913] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[    0.128044] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[    0.129060] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[    0.140184] Switching to clocksource kvm-clock
[    0.140791] pnp: PnP ACPI init
[    0.141564] ACPI: bus type pnp registered
[    0.148623] pnp: PnP ACPI: found 7 devices
[    0.149737] ACPI: ACPI bus type pnp unregistered
[    0.161792] pci_bus 0000:00: resource 0 [io  0x0000-0xffff]
[    0.161801] pci_bus 0000:00: resource 1 [mem 0x00000000-0xffffffffffffffff]
[    0.162325] NET: Registered protocol family 2
[    0.163891] IP route cache hash table entries: 4096 (order: 3, 32768 bytes)
[    0.166098] TCP established hash table entries: 16384 (order: 6, 262144 bytes)
[    0.169226] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[    0.170987] TCP: Hash tables configured (established 16384 bind 16384)
[    0.172335] TCP reno registered
[    0.173378] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.174607] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.176343] NET: Registered protocol family 1
[    0.197118] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.197502] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    0.197960] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    0.198360] pci 0000:00:02.0: Boot video device
[    0.198385] PCI: CLS 0 bytes, default 64
[    0.198451] Unpacking initramfs...
[    0.231639] Freeing initrd memory: 1988k freed
[    0.241648] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.243184] msgmni has been set to 997
[    0.244500] alg: No test for stdrng (krng)
[    0.245449] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    0.246246] io scheduler noop registered
[    0.246664] io scheduler deadline registered
[    0.247248] io scheduler cfq registered (default)
[    0.295494] PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    0.298886] serio: i8042 KBD port at 0x60,0x64 irq 1
[    0.299496] serio: i8042 AUX port at 0x60,0x64 irq 12
[    0.300600] mice: PS/2 mouse device common for all mice
[    0.302311] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[    0.303099] rtc0: alarms up to one day, 114 bytes nvram, hpet irqs
[    0.303836] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    0.304006] cpuidle: using governor ladder
[    0.304067] cpuidle: using governor menu
[    0.306138] TCP cubic registered
[    0.307334] NET: Registered protocol family 17
[    0.310261] rtc_cmos 00:01: setting system clock to 2010-07-27 20:56:06 UTC (1280264166)
[    0.312599] Freeing unused kernel memory: 464k freed
[    0.513685] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[    0.514278] virtio-pci 0000:00:03.0: PCI INT A -> Link[LNKC] -> GSI 11 (level, high) -> IRQ 11
[    0.514928] virtio-pci 0000:00:03.0: setting latency timer to 64
[    0.515092] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 10
[    0.515493] virtio-pci 0000:00:04.0: PCI INT A -> Link[LNKD] -> GSI 10 (level, high) -> IRQ 10
[    0.516198] virtio-pci 0000:00:04.0: setting latency timer to 64
[    0.536171] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[    0.536565] virtio-pci 0000:00:05.0: PCI INT A -> Link[LNKA] -> GSI 10 (level, high) -> IRQ 10
[    0.537225] virtio-pci 0000:00:05.0: setting latency timer to 64
[    0.537386] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 11
[    0.537762] virtio-pci 0000:00:06.0: PCI INT A -> Link[LNKB] -> GSI 11 (level, high) -> IRQ 11
[    0.538410] virtio-pci 0000:00:06.0: setting latency timer to 64
[    0.634593]  vda: vda1 vda2 < vda5 >
[    0.649159]  vdb: vdb1
[    1.013119] Clocksource tsc unstable (delta = 582181654385 ns)
[    1.044251] EXT3-fs: barriers not enabled
[    1.063011] kjournald starting.  Commit interval 5 seconds
[    1.063115] EXT3-fs (vda1): mounted filesystem with writeback data mode
[    2.620528] udevd version 125 started
[    2.865930] virtio-pci 0000:00:03.0: irq 40 for MSI/MSI-X
[    2.865945] virtio-pci 0000:00:03.0: irq 41 for MSI/MSI-X
[    2.865958] virtio-pci 0000:00:03.0: irq 42 for MSI/MSI-X
[    2.910519] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input1
[    2.912585] ACPI: Power Button [PWRF]
[    2.921754] ACPI: acpi_idle registered with cpuidle
[    4.408057] Adding 409620k swap on /dev/vda5.  Priority:-1 extents:1 across:409620k
[    4.959959] EXT3-fs (vda1): using internal journal
[    5.495306] loop: module loaded
[    9.680594] hrtimer: interrupt took 11934233 ns
[   10.246663] NET: Registered protocol family 10
[   10.247565] lo: Disabled Privacy Extensions
[   20.576118] eth0: no IPv6 routers present
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[Index of Archives]     [KVM ARM]     [KVM ia64]     [KVM ppc]     [Virtualization Tools]     [Spice Development]     [Libvirt]     [Libvirt Users]     [Linux USB Devel]     [Linux Audio Users]     [Yosemite Questions]     [Linux Kernel]     [Linux SCSI]     [XFree86]
  Powered by Linux