Re: 2.6.35-rc1 regression with pvclock and smp guests

Arjan Koers
2010-10-20T20:47:53Z

On 2010-10-09 03:10, Arjan Koers wrote:
> > On 2010-10-09 00:06, Marcelo Tosatti wrote:
...
>> >>
>> >> Backports attached. Michael, Arjan, please give them a try.
>> >>
> >
> > Thanks for the patches.
> >
> > Successfully tested with 2.6.34.7, 2.6.35.7 and 2.6.36-rc7 host
> > (with a 2.6.35.7 guest).

Here's a smaller version of a previous email that didn't make it to
the list...

The host side fixes stop the hanging problem, but the real problem is
on the guest:
The guest starts with one hv_clock struct, which gets written to by
the host (for CPU0).
The percpu code allocates separate hv_clock structs for each CPU and
copies the data from the old hv_clock struct to the new structs.
The CPU1 hv_clock struct with old CPU0 data is accessed, which causes
the problems.

I've performed some tests with an unmodified 2.6.32.24 host and a
recent kvm.git guest. The unmodified guest hangs. A modified guest
where the CPU1 hv_clock struct is initialized to 0, doesn't hang.

Here's a boot log that shows what happens:

+-printk_cpu (kernel/printk.c)
| +-&hv_clock CPU0 (arch/x86/kernel/kvmclock.c)
| | +-hv_clock.version CPU0
| | | +-&hv_clock CPU1
| | | | +-hv_clock.version CPU1
| | | | |
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] Linux version 2.6.36-rc7-201010141519-guestmp-kvm+ (arjan@dev-lenny) (gcc version 4.4.5 20100728 (prerelease) (Debian 4.4.4-8) ) #1 SMP Thu Oct 14 15:22:48 UTC 2010
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-2.6.36-rc7-201010141519-guestmp-kvm+ root=UUID=22a4b388-70e0-4d2a-9aa1-bd842504378a ro quiet
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-provided physical RAM map:
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 0000000000000000 - 000000000009bc00 (usable)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 000000000009bc00 - 00000000000a0000 (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 00000000000f0000 - 0000000000100000 (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 0000000000100000 - 000000001fffd000 (usable)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 000000001fffd000 - 0000000020000000 (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: 00000000fffc0000 - 0000000100000000 (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] BIOS-e820: feffd00000000000 - ff00100000000000 (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] NX (Execute Disable) protection: active
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] DMI 2.4 present.
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] e820 update range: 0000000000000000 - 0000000000001000 (usable) ==> (reserved)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] e820 remove range: 00000000000a0000 - 0000000000100000 (usable)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] No AGP bridge found
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] last_pfn = 0x1fffd max_arch_pfn = 0x400000000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] MTRR default type: write-back
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] MTRR fixed ranges enabled:
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 00000-9FFFF write-back
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] A0000-BFFFF uncachable
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] C0000-FFFFF write-protect
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] MTRR variable ranges enabled:
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 0 base 00E0000000 mask FFE0000000 uncachable
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 1 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 2 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 3 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 4 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 5 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 6 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 7 disabled
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] x86 PAT enabled: cpu 0, old 0x0, new 0x7010600070106
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] initial memory mapped : 0 - 20000000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] Using GB pages for direct mapping
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] init_memory_mapping: 0000000000000000-000000001fffd000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 0000000000 - 001fe00000 page 2M
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] 001fe00000 - 001fffd000 page 4k
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] kernel direct mapping tables up to 1fffd000 @ 8000-b000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] RAMDISK: 17df6000 - 1803e000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: RSDP 00000000000fdb80 00014 (v00 BOCHS )
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: RSDT 000000001fffde10 00034 (v01 BOCHS BXPCRSDT 00000001 BXPC 00000001)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: FACP 000000001ffffe40 00074 (v01 BOCHS BXPCFACP 00000001 BXPC 00000001)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: DSDT 000000001fffdfd0 01E22 (v01 BXPC BXDSDT 00000001 INTL 20090123)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: FACS 000000001ffffe00 00040
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: SSDT 000000001fffdf80 00044 (v01 BOCHS BXPCSSDT 00000001 BXPC 00000001)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: APIC 000000001fffde90 0007A (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: HPET 000000001fffde50 00038 (v01 BOCHS BXPCHPET 00000001 BXPC 00000001)
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] ACPI: Local APIC address 0xfee00000
[0 ffffffff81324fc0 0 ffffffff81324fc0 0 0.000000] kvm-clock: Using msrs 12 and 11
pass the address of the hv_clock struct to the host; the host starts writing to it:
[0 ffffffff81324fc0 11c3c2 ffffffff81324fc0 11c3c2 0.000000] kvm-clock: cpu 0, msr 0:1324fc1, boot clock
pv_clock data is accessed in kvm_get_tsc_khz:
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] [ffffea0000000000-ffffea00007fffff] PMD -> [ffff880001c00000-ffff8800023fffff] on node 0
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] Zone PFN ranges:
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA 0x00000001 -> 0x00001000
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA32 0x00001000 -> 0x00100000
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] Normal empty
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] Movable zone start PFN for each node
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] early_node_map[2] active PFN ranges
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] 0: 0x00000001 -> 0x0000009b
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] 0: 0x00000100 -> 0x0001fffd
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] On node 0 totalpages: 130967
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA zone: 56 pages used for memmap
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA zone: 0 pages reserved
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA zone: 3938 pages, LIFO batch:0
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA32 zone: 1736 pages used for memmap
[0 ffffffff81324fc0 11c3ca ffffffff81324fc0 11c3ca 0.000000] DMA32 zone: 125237 pages, LIFO batch:31
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: PM-Timer IO Port: 0xb008
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: Local APIC address 0xfee00000
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0])
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] IOAPIC[0]: apic_id 2, version 17, address 0xfec00000, GSI 0-23
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ0 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ2 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ5 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ9 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ10 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: IRQ11 used by override.
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] Using ACPI (MADT) for SMP configuration information
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] SMP: Allowing 2 CPUs, 0 hotplug CPUs
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] nr_irqs_gsi: 40
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] Allocating PCI resources starting at 20000000 (gap: 20000000:dffc0000)
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] Booting paravirtualized kernel on KVM
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] setup_percpu: NR_CPUS:2 nr_cpumask_bits:2 nr_cpu_ids:2 nr_node_ids:1
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] early_res array is doubled to 64 at [3000 - 37ff]
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] PERCPU: Embedded 26 pages/cpu @ffff880001400000 s76736 r8192 d21568 u1048576
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] pcpu-alloc: s76736 r8192 d21568 u1048576 alloc=1*2097152
[0 ffffffff81324fc0 11c4ae ffffffff81324fc0 11c4ae 0.000000] pcpu-alloc: [0] 0 1
the single hv_clock struct has been copied to two new structs (one for each CPU); the contents are correct for CPU0, but not for CPU1
the host may still write to the old pv_clock location; can this cause problems?

if the CPU1 hv_clock struct is zeroed here, pvclock_clocksource_read will not return wrong data and the guest won't hang

pass the address of the CPU0 hv_clock struct to the host; the host starts writing to it:
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] kvm-clock: cpu 0, msr 0:1411fc1, primary cpu clock
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 129175
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-2.6.36-rc7-201010141519-guestmp-kvm+ root=UUID=22a4b388-70e0-4d2a-9aa1-bd842504378a ro quiet
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)
[0 ffff880001411fc0 11c4b0 ffff880001511fc0 11c4ae 0.000000] Checking aperture...
[0 ffff880001411fc0 1244dc ffff880001511fc0 11c4ae 0.000000] No AGP bridge found
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] Subtract (39 early reservations)
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #1 [0001000000 - 00013d6d38] TEXT DATA BSS
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #2 [0017df6000 - 001803e000] RAMDISK
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #3 [000009bc00 - 0000100000] BIOS reserved
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #4 [00013d7000 - 00013d7071] BRK
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #5 [0000001000 - 0000003000] TRAMPOLINE
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #6 [0000008000 - 0000009000] PGTABLE
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #7 [00013d7080 - 00013d8080] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #8 [00013d6d40 - 00013d6da0] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #9 [0001bd9000 - 0001bda000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #10 [0001bda000 - 0001bdb000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #11 [0001c00000 - 0002400000] MEMMAP 0
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #12 [00013d6dc0 - 00013d6f40] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #13 [00013d8080 - 00013db080] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #14 [00013dc000 - 00013dd000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #15 [00013d6f40 - 00013d6f81] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #16 [00013db080 - 00013db0c3] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #17 [00013db100 - 00013db2c0] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #18 [00013db2c0 - 00013db328] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #19 [00013db340 - 00013db3a8] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #20 [00013db3c0 - 00013db428] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #21 [00013db440 - 00013db4a8] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #22 [00013db4c0 - 00013db528] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #23 [00013db540 - 00013db5a8] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #24 [00013db5c0 - 00013db628] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #25 [00013db640 - 00013db6b6] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #26 [00013db6c0 - 00013db736] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #27 [0001400000 - 000141a000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #28 [0001500000 - 000151a000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #29 [00013d6fc0 - 00013d6fc8] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #30 [00013db740 - 00013db748] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #31 [00013db780 - 00013db788] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #32 [00013db7c0 - 00013db7d0] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #33 [00013db800 - 00013db940] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #34 [00013db940 - 00013db9a0] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #35 [00013db9c0 - 00013dba20] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #36 [00013dd000 - 00013e1000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #37 [000141a000 - 000149a000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] #38 [000149a000 - 00014da000] BOOTMEM
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] Memory: 508372k/524276k available (2128k kernel code, 408k absent, 15496k reserved, 1011k data, 472k init)
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] Hierarchical RCU implementation.
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] RCU-based detection of stalled CPUs is disabled.
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] Verbose stalled-CPUs detection is disabled.
[0 ffff880001411fc0 1245fc ffff880001511fc0 11c4ae 0.000000] NR_IRQS:320
[0 ffff880001411fc0 126736 ffff880001511fc0 11c4ae 0.000000] Console: colour VGA+ 80x25
[0 ffff880001411fc0 126736 ffff880001511fc0 11c4ae 0.000000] console [tty0] enabled
[0 ffff880001411fc0 126766 ffff880001511fc0 11c4ae 0.000000] hpet clockevent registered
[0 ffff880001411fc0 126766 ffff880001511fc0 11c4ae 0.000000] Detected 2799.750 MHz processor.
[0 ffff880001411fc0 126766 ffff880001511fc0 11c4ae 0.012000] Calibrating delay loop (skipped) preset value.. 5599.50 BogoMIPS (lpj=11199000)
[0 ffff880001411fc0 126766 ffff880001511fc0 11c4ae 0.012000] pid_max: default: 32768 minimum: 301
[0 ffff880001411fc0 126766 ffff880001511fc0 11c4ae 0.012000] Mount-cache hash table entries: 256
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] using C1E aware idle routine
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] Performance Events: AMD PMU driver.
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... version: 0
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... bit width: 48
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... generic registers: 4
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... value mask: 0000ffffffffffff
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... max period: 00007fffffffffff
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... fixed-purpose events: 0
[0 ffff880001411fc0 12676a ffff880001511fc0 11c4ae 0.012000] ... event mask: 000000000000000f
[0 ffff880001411fc0 12676c ffff880001511fc0 11c4ae 0.012333] Freeing SMP alternatives: 12k freed
[0 ffff880001411fc0 12676c ffff880001511fc0 11c4ae 0.012342] ACPI: Core revision 20100702
[0 ffff880001411fc0 126770 ffff880001511fc0 11c4ae 0.014061] Setting APIC routing to flat
[0 ffff880001411fc0 126774 ffff880001511fc0 11c4ae 0.015478] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[0 ffff880001411fc0 126774 ffff880001511fc0 11c4ae 0.015483] CPU0: AMD Athlon(tm) II X2 240 Processor stepping 02
[0 ffff880001411fc0 126830 ffff880001511fc0 11c4ae 0.016000] ++++++++++++++++++++=_---CPU UP 1
[0 ffff880001411fc0 126830 ffff880001511fc0 11c4ae 0.016000] Booting Node 0, Processors #1 Ok.
[0 ffff880001411fc0 126830 ffff880001511fc0 11c4ae 0.016000] Setting warm reset code and vector.
[0 ffff880001411fc0 126834 ffff880001511fc0 11c4ae 0.016000] 1.
[0 ffff880001411fc0 126834 ffff880001511fc0 11c4ae 0.016000] 2.
[0 ffff880001411fc0 126834 ffff880001511fc0 11c4ae 0.016000] 3.
[0 ffff880001411fc0 126834 ffff880001511fc0 11c4ae 0.016000] Asserting INIT.
[0 ffff880001411fc0 126834 ffff880001511fc0 11c4ae 0.016000] Waiting for send to finish...
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.022250] Deasserting INIT.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.022259] Waiting for send to finish...
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.022265] #startup loops: 2.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.022268] Sending STARTUP #1.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.022275] After apic_write.
this printk gets the time from the CPU1 hv_clock (with old CPU0 data), which results in value far into the future:
[1 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.012000] CPU#1 (phys ID: 1) waiting for CALLOUT
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Startup point 1.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Waiting for send to finish...
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Sending STARTUP #2.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] After apic_write.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Startup point 1.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Waiting for send to finish...
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] After Startup.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] Before Callout 1.
[0 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.024000] After Callout 1.
same as previous comment:
[1 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.012000] CALLIN, before setup_local_APIC().
same as previous comment:
[1 ffff880001411fc0 126836 ffff880001511fc0 11c4ae 0.012000] Stack at about ffff88001f89ff44
pass the address of the CPU1 hv_clock struct to the host; the host starts writing to it and the data in both structs (CPU0 and CPU1) is valid now:
[1 ffff880001411fc0 126836 ffff880001511fc0 11ddcc 0.012000] kvm-clock: cpu 1, msr 0:1511fc1, secondary cpu clock
[0 ffff880001411fc0 126836 ffff880001511fc0 11ddcc 0.025001] CPU1: has booted.
[0 ffff880001411fc0 12683a ffff880001511fc0 11ddcc 0.025001] Brought up 2 CPUs
[0 ffff880001411fc0 12683a ffff880001511fc0 11ddcc 0.025001] Boot done.
[0 ffff880001411fc0 12683a ffff880001511fc0 11ddcc 0.025001] Before bogomips.
[0 ffff880001411fc0 12683a ffff880001511fc0 11ddcc 0.025001] Total of 2 processors activated (11199.00 BogoMIPS).
[0 ffff880001411fc0 12683a ffff880001511fc0 11ddcc 0.025001] Before bogocount - setting activated=1.
[1 ffff880001411fc0 12683a ffff880001511fc0 11ddce 0.025001] x86 PAT enabled: cpu 1, old 0x0, new 0x7010600070106
...