thr3ads.net - Xen devel - [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used [Jan 2010]

If this information is useful, please help other people find it:
Share via:

Frank Van Der Linden

2010-Jan-05 20:55 UTC

[Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

I''ve been looking at Xen (3.4.2) power management, and have been trying
out different settings. One machine I tried was a Toshiba M30 laptop, 
which has an Intel Core 2 Duo CPU:

CPU0: Intel(R) Core(TM)2 Duo CPU     P8400  @ 2.26GHz stepping 06
CPU1: Intel(R) Core(TM)2 Duo CPU     P8400  @ 2.26GHz stepping 06

When dom0 initialized power management, the messages printed are as follows:

Set CPU acpi_id(0) cpuid(0) Px State info:
  _PCT: descriptor=0, length=0, space_id=127, bit_width=0, bit_offset=0, 
reserved=0, address=0
  _PCT: descriptor=0, length=0, space_id=127, bit_width=0, bit_offset=0, 
reserved=0, address=0
  _PSS: state_count=4
  State0: 2261MHz 35000mW 10us 10us 0x927 0x927
  State1: 2260MHz 35000mW 10us 10us 0x4822 0x4822
  State2: 1600MHz 16000mW 10us 10us 0x617 0x617
  State3: 800MHz 14300mW 10us 10us 0x8611 0x8611
  _PSD: num_entries=5 rev=0 domain=0 coord_type=252 num_processors=1
  _PPC: 0
xen_pminfo: @acpi_cpufreq_cpu_init,HARDWARE addr space
CPU 0 initialization completed
Set CPU acpi_id(1) cpuid(1) Px State info:
  _PCT: descriptor=0, length=0, space_id=127, bit_width=0, bit_offset=0, 
reserved=0, address=0
  _PCT: descriptor=0, length=0, space_id=127, bit_width=0, bit_offset=0, 
reserved=0, address=0
  _PSS: state_count=4
  State0: 2261MHz 35000mW 10us 10us 0x927 0x927
  State1: 2260MHz 35000mW 10us 10us 0x4822 0x4822
  State2: 1600MHz 16000mW 10us 10us 0x617 0x617
  State3: 800MHz 14300mW 10us 10us 0x8611 0x8611
  _PSD: num_entries=5 rev=0 domain=1 coord_type=252 num_processors=1
  _PPC: 0
xen_pminfo: @acpi_cpufreq_cpu_init,HARDWARE addr space
CPU 1 initialization completed
cpuid.MWAIT[.eax=40, .ebx=40, .ecx=3, .edx=3122220]
Monitor-Mwait will be used to enter C-1 state
cpuid.MWAIT[.eax=40, .ebx=40, .ecx=3, .edx=3122220]
Monitor-Mwait will be used to enter C-1 state

It seems to mostly work ok, except that an OpenSolaris HVM domU slows 
down to a crawl. When I examined it, I noticed that it wasn''t getting 
any timer interrupts. Or, almost none; occasionally the interrupt count 
for the timer jumps, but mostly it stays frozen.

If I limit the maximum C state to C2, things seem ok, but when C3 is 
used, the problems pops up pretty quickly, though not immediately: if I 
initialize the maximum C state to 1, but then change it to C3 when the 
domU is already running, it won''t immediately slow down, it might take 
about a minute, during which time the xenpm utility already is showing 
that C3 is being used. So a switch to C3 isn''t guaranteed to cause the 
problem, but it eventually will.

I tried other HVM domains, such as Windows, and they don''t seem to have
the problem. But, they might be more "tickless" than OpenSolaris is.

I haven''t looked at the PM code much yet, and I haven''t tried
-unstable,
but there don''t seem to be any changes in -unstable that would fix
this.

Is this a known problem? Any hints for diagnosing the problem?

- Frank


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Keir Fraser

2010-Jan-05 21:02 UTC

head link

Re: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

On 05/01/2010 20:55, "Frank Van Der Linden"
<Frank.Vanderlinden@Sun.COM>
wrote:
> I tried other HVM domains, such as Windows, and they don''t seem to
have
> the problem. But, they might be more "tickless" than OpenSolaris
is.
> 
> I haven''t looked at the PM code much yet, and I haven''t
tried -unstable,
> but there don''t seem to be any changes in -unstable that would fix
this.
> 
> Is this a known problem? Any hints for diagnosing the problem?
Perhaps CPUs are not being woken from C3 in a timely manner? Could check how
late timers are fired in timer_softirq_action(), perhaps printing largest
missed deadline every few seconds or soemthing like that.

 -- Keir




_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Wei, Gang

2010-Jan-06 01:55 UTC

head link

RE: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

Frank Van Der Linden wrote:> I haven''t looked at the PM code much yet, and I haven''t
tried
> -unstable, but there don''t seem to be any changes in -unstable
that
> would fix this. 
> 
> Is this a known problem? Any hints for diagnosing the problem?
> 
> - Frank
To make sure whether it is problem of the xen time sub-system, can you try some
"while true; do date; sleep 1; done" loop from dom0 directly, w/o
creating HVM domain?

BTW, could you also do "xm debug c; xm dmesg > xmdmesg.log" in dom0
only case and attach the entire xmdmesg.log? More platform related information
can be got from it.

Jimmy
_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Frank Van Der Linden

2010-Jan-06 02:29 UTC

head link

Re: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

Wei, Gang wrote:> Frank Van Der Linden wrote:
>   
>> I haven''t looked at the PM code much yet, and I
haven''t tried
>> -unstable, but there don''t seem to be any changes in -unstable
that
>> would fix this. 
>>
>> Is this a known problem? Any hints for diagnosing the problem?
>>
>> - Frank
>>     
>
> To make sure whether it is problem of the xen time sub-system, can you try
some "while true; do date; sleep 1; done" loop from dom0 directly, w/o
creating HVM domain?
>
> BTW, could you also do "xm debug c; xm dmesg > xmdmesg.log" in
dom0 only case and attach the entire xmdmesg.log? More platform related
information can be got from it.
>
> Jimmy
>   I tested dom0, and time on dom0 is working just fine. This is the 
Solaris dom0, but that shouldn''t matter in this case. Here is the xm 
dmesg output (plus the c debug key output), with dom0 having been up for 
a while, but no domUs had ever been run:

(xVM)  xVM version 3.4.2-xvm-debug
(xVM) Command line: console=com1 com1=115200,8n1 dom0_mem=1536M
(xVM) Video information:
(xVM)  VGA is text mode 80x25, font 8x16
(xVM)  VBE/DDC methods: none; EDID transfer time: 0 seconds
(xVM)  EDID info not retrieved because no DDC retrieval method detected
(xVM) Disc information:
(xVM)  Found 1 MBR signatures
(xVM)  Found 1 EDD information structures
(xVM) Xen-e820 RAM map:
(xVM)  0000000000000000 - 000000000009bc00 (usable)
(xVM)  000000000009bc00 - 00000000000a0000 (reserved)
(xVM)  00000000000e8000 - 00000000000eee00 (reserved)
(xVM)  00000000000eee00 - 00000000000ef000 (ACPI NVS)
(xVM)  00000000000ef000 - 0000000000100000 (reserved)
(xVM)  0000000000100000 - 00000000bfba0000 (usable)
(xVM)  00000000bfba0000 - 00000000c0000000 (reserved)
(xVM)  00000000fec00000 - 00000000fec28000 (reserved)
(xVM)  00000000fed00000 - 00000000fed00500 (reserved)
(xVM)  00000000fed10000 - 00000000fed1a000 (reserved)
(xVM)  00000000fed1c000 - 00000000fed94000 (reserved)
(xVM)  00000000fee00000 - 00000000fee01000 (reserved)
(xVM)  00000000ffa00000 - 00000000ffc00000 (reserved)
(xVM)  00000000ffd00000 - 0000000100000000 (reserved)
(xVM)  0000000100000000 - 000000013c000000 (usable)
(xVM) System RAM: 4027MB (4123884kB)
(xVM) ACPI: RSDP 000F00B0, 0014 (r0 TOSHIB)
(xVM) ACPI: RSDT BFBA0000, 0058 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: FACP BFBA0084, 0084 (r2 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: DSDT BFBA0108, 82BF (r2 TOSHIB A0066    20080603 MSFT  3000000)
(xVM) ACPI: FACS 000EEE00, 0040
(xVM) ACPI: SSDT BFBA83C7, 0506 (r2 TOSHIB A0066    20070720 MSFT  3000000)
(xVM) ACPI: BOOT BFBA005C, 0028 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: APIC BFBA8EA1, 0068 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: MCFG BFBA8F09, 003C (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: HPET BFBA8F45, 0038 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: TCPA BFBA924A, 0032 (r2 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: SLIC BFBA927C, 0176 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: ASF! BFBA8FB1, 0075 (r16 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: DMAR BFBA9026, 00C8 (r1 TOSHIB A0066    20080603 TASM  4010000)
(xVM) ACPI: SSDT BFBA9E91, 01A3 (r2 TOSHIB A0066    20080317 MSFT  3000000)
(xVM) ACPI: SSDT BFBA93F2, 0076 (r2 TOSHIB A0066    20080310 MSFT  3000000)
(xVM) ACPI: SSDT BFBA9468, 0A29 (r2 TOSHIB A0066    20080411 MSFT  3000000)
(xVM) NUMA turned off
(xVM) Faking a node at 0000000000000000-000000013c000000
(xVM) Domain heap initialised
(xVM) DMI 2.5 present.
(xVM) Using APIC driver default
(xVM) ACPI: PM-Timer IO Port: 0xd808
(xVM) ACPI: ACPI SLEEP INFO: pm1x_cnt[d804,0], pm1x_evt[d800,0]
(xVM) ACPI:                  wakeup_vec[eee0c], vec_size[20]
(xVM) ACPI: Local APIC address 0xfee00000
(xVM) ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
(xVM) Processor #0 7:7 APIC version 20
(xVM) ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
(xVM) Processor #1 7:7 APIC version 20
(xVM) ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
(xVM) ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
(xVM) ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
(xVM) IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23
(xVM) ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
(xVM) ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
(xVM) ACPI: IRQ0 used by override.
(xVM) ACPI: IRQ2 used by override.
(xVM) ACPI: IRQ9 used by override.
(xVM) Enabling APIC mode:  Flat.  Using 1 I/O APICs
(xVM) ACPI: HPET id: 0x8086a301 base: 0xfed00000
(xVM) Using ACPI (MADT) for SMP configuration information
(xVM) Using scheduler: SMP Credit Scheduler (credit)
(xVM) Initializing CPU#0
(xVM) Detected 2261.053 MHz processor.
(xVM) CPU: L1 I cache: 32K, L1 D cache: 32K
(xVM) CPU: L2 cache: 3072K
(xVM) CPU: Physical Processor ID: 0
(xVM) CPU: Processor Core ID: 0
(xVM) VMX: Supported advanced features:
(xVM)  - APIC MMIO access virtualisation
(xVM)  - APIC TPR shadow
(xVM)  - Virtual NMI
(xVM)  - MSR direct-access bitmap
(xVM) HVM: VMX enabled
(xVM) Intel machine check reporting enabled on CPU#0.
(xVM) mce_init: init bank1
(xVM) mce_init: init bank2
(xVM) mce_init: init bank3
(xVM) mce_init: init bank4
(xVM) mce_init: init bank5
(xVM) CPU0: Thermal monitoring handled by SMI
(xVM) CMCI: CPU0 has no CMCI support
(xVM) CPU0: Intel(R) Core(TM)2 Duo CPU     P8400  @ 2.26GHz stepping 06
(xVM) Booting processor 1/1 eip 8c000
(xVM) Initializing CPU#1
(xVM) CPU: L1 I cache: 32K, L1 D cache: 32K
(xVM) CPU: L2 cache: 3072K
(xVM) CPU: Physical Processor ID: 0
(xVM) CPU: Processor Core ID: 1
(xVM) Intel machine check reporting enabled on CPU#1.
(xVM) mce_init: init bank1
(xVM) mce_init: init bank2
(xVM) mce_init: init bank4
(xVM) mce_init: init bank5
(xVM) CPU1: Thermal monitoring enabled (TM2)
(xVM) CMCI: CPU1 has no CMCI support
(xVM) CPU1: Intel(R) Core(TM)2 Duo CPU     P8400  @ 2.26GHz stepping 06
(xVM) Total of 2 processors activated.
(xVM) ENABLING IO-APIC IRQs
(xVM)  -> Using new ACK method
(xVM) ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
(xVM) checking TSC synchronization across 2 CPUs: passed.
(xVM) Platform timer is 14.318MHz HPET
(xVM) Brought up 2 CPUs
(xVM) microcode.c:73:d32767 microcode: CPU1 resumed
(xVM) I/O virtualisation disabled
(xVM) HPET: 4 timers in total, 0 timers will be used for broadcast
(xVM) ACPI sleep modes: S3
(xVM) mcheck_poll: Machine check polling timer started.
(xVM) *** LOADING DOMAIN 0 ***
(xVM) elf_parse_binary: phdr: paddr=0x40800000 memsz=0x273e8
(xVM) elf_parse_binary: phdr: paddr=0x40000000 memsz=0x1a916c
(xVM) elf_parse_binary: phdr: paddr=0x40400000 memsz=0xd97f0
(xVM) elf_parse_binary: memory: 0x40000000 -> 0x408273e8
(xVM) elf_xen_parse_note: LOADER = "generic"
(xVM) elf_xen_parse_note: XEN_VERSION = "xen-3.0"
(xVM) elf_xen_parse_note: GUEST_OS = "Solaris"
(xVM) elf_xen_parse_note: VIRT_BASE = 0x40000000
(xVM) elf_xen_parse_note: PADDR_OFFSET = 0x40000000
(xVM) elf_xen_addr_calc_check: addresses:
(xVM)     virt_base        = 0x40000000
(xVM)     elf_paddr_offset = 0x40000000
(xVM)     virt_offset      = 0x0
(xVM)     virt_kstart      = 0x40000000
(xVM)     virt_kend        = 0x408273e8
(xVM)     virt_entry       = 0x40800000
(xVM)     p2m_base         = 0xffffffffffffffff
(xVM)  Xen  kernel: 64-bit, lsb, compat32
(xVM)  Dom0 kernel: 64-bit, lsb, paddr 0x40000000 -> 0x408273e8
(xVM) PHYSICAL MEMORY ARRANGEMENT:
(xVM)  Dom0 alloc.:   0000000134000000->0000000138000000 (376832 pages 
to be allocated)
(xVM) VIRTUAL MEMORY ARRANGEMENT:
(xVM)  Loaded kernel: 0000000040000000->00000000408273e8
(xVM)  Init. ramdisk: 0000000040828000->0000000043548000
(xVM)  Phys-Mach map: 0000000043548000->0000000043848000
(xVM)  Start info:    0000000043848000->00000000438484b4
(xVM)  Page tables:   0000000043849000->000000004386a000
(xVM)  Boot stack:    000000004386a000->000000004386b000
(xVM)  TOTAL:         0000000040000000->0000000043c00000
(xVM)  ENTRY ADDRESS: 0000000040800000
(xVM) Dom0 has maximum 2 VCPUs
(xVM) elf_load_binary: phdr 1 at 0x0000000040800000 -> 0x00000000408273e8
(xVM) elf_load_binary: phdr 2 at 0x0000000040000000 -> 0x00000000401a916c
(xVM) elf_load_binary: phdr 3 at 0x0000000040400000 -> 0x00000000404136ff
(xVM) Scrubbing Free RAM: ........................done.
(xVM) Xen trace buffers: disabled
(xVM) Std. Loglevel: All
(xVM) Guest Loglevel: All
(xVM) *** Serial input -> DOM0 (type \047CTRL-a\047 three times to 
switch input to Xen)
(xVM) Freed 156kB init memory.
(xVM) grant_table.c:808:d0 Expanding dom (0) grant table from (4) to 
(32) frames.
(xVM) PCI add device 00:1f.2
(xVM) Set CPU acpi_id(0) cpuid(0) Px State info:
(xVM)   _PCT: descriptor=0, length=0, space_id=127, bit_width=0, 
bit_offset=0, reserved=0, address=0
(xVM)   _PCT: descriptor=0, length=0, space_id=127, bit_width=0, 
bit_offset=0, reserved=0, address=0
(xVM)   _PSS: state_count=4
(xVM)   State0: 2261MHz 35000mW 10us 10us 0x927 0x927
(xVM)   State1: 2260MHz 35000mW 10us 10us 0x4822 0x4822
(xVM)   State2: 1600MHz 16000mW 10us 10us 0x617 0x617
(xVM)   State3: 800MHz 14300mW 10us 10us 0x8611 0x8611
(xVM)   _PSD: num_entries=5 rev=0 domain=0 coord_type=252 num_processors=1
(xVM)   _PPC: 0
(xVM) xen_pminfo: @acpi_cpufreq_cpu_init,HARDWARE addr space
(xVM) CPU 0 initialization completed
(xVM) Set CPU acpi_id(1) cpuid(1) Px State info:
(xVM)   _PCT: descriptor=0, length=0, space_id=127, bit_width=0, 
bit_offset=0, reserved=0, address=0
(xVM)   _PCT: descriptor=0, length=0, space_id=127, bit_width=0, 
bit_offset=0, reserved=0, address=0
(xVM)   _PSS: state_count=4
(xVM)   State0: 2261MHz 35000mW 10us 10us 0x927 0x927
(xVM)   State1: 2260MHz 35000mW 10us 10us 0x4822 0x4822
(xVM)   State2: 1600MHz 16000mW 10us 10us 0x617 0x617
(xVM)   State3: 800MHz 14300mW 10us 10us 0x8611 0x8611
(xVM)   _PSD: num_entries=5 rev=0 domain=1 coord_type=252 num_processors=1
(xVM)   _PPC: 0
(xVM) xen_pminfo: @acpi_cpufreq_cpu_init,HARDWARE addr space
(xVM) CPU 1 initialization completed
(xVM) cpuid.MWAIT[.eax=40, .ebx=40, .ecx=3, .edx=3122220]
(xVM) Monitor-Mwait will be used to enter C-1 state
(xVM) cpuid.MWAIT[.eax=40, .ebx=40, .ecx=3, .edx=3122220]
(xVM) Monitor-Mwait will be used to enter C-1 state
(xVM) PCI add device 00:19.0
(xVM) PCI add device 00:1b.0
(xVM) Xen trace buffers: initialized
(xVM) *** Serial input -> Xen (type \047CTRL-a\047 three times to switch 
input to DOM0)
(xVM) ==cpu0=(xVM) active state:             C3
(xVM) max_cstate:               C7
(xVM) states:
(xVM)     C1:   type[C1] latency[001] usage[00005351] duration[16709386]
(xVM)     C2:   type[C2] latency[001] usage[00072721] duration[48331319757]
(xVM)    *C3:   type[C3] latency[057] usage[05261685] 
duration[32698354952269]
(xVM)     C0:   usage[05339757] duration[337842300997]
(xVM) ==cpu1=(xVM) active state:             C3
(xVM) max_cstate:               C7
(xVM) states:
(xVM)     C1:   type[C1] latency[001] usage[00000050] duration[1916444]
(xVM)     C2:   type[C2] latency[001] usage[00039050] duration[77772952140]
(xVM)    *C3:   type[C3] latency[057] usage[05592302] 
duration[32757362666651]
(xVM)     C0:   usage[05631402] duration[249407777117]

- Frank

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Wei, Gang

2010-Jan-06 04:01 UTC

head link

RE: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

Frank Van Der Linden wrote:> I tested dom0, and time on dom0 is working just fine. This is the
> Solaris dom0, but that shouldn''t matter in this case. Here is the
xm
> dmesg output (plus the c debug key output), with dom0 having been up
> for 
> a while, but no domUs had ever been run:
Can''t see any problem from the serial output. Let''s take a
further step. Attached patch is a __draft__ patch to collect statistics related
with timer interrupts & timer fns. Can you apply it, rebuild the xen
hypervisor code, then do "xm debug 9; sleep 20; xm debug 9; xm dmesg >
xmdmesg.log" in both dom0 only & 1 HVM cases. Let''s have a
look on the timer statistics first.

Jimmy

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel

Xen devel - Jan 2010 - xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

[Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

Re: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

RE: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

Re: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used

RE: [Xen-devel] xenpm: opensolaris HVM domU stops getting timer interrupts when C3 used