* Strange CPU load - acpi_os_read_port
@ 2010-07-22 19:39 Paweł Staszewski
2010-07-22 19:44 ` Paweł Staszewski
2010-08-15 3:33 ` Len Brown
0 siblings, 2 replies; 6+ messages in thread
From: Paweł Staszewski @ 2010-07-22 19:39 UTC (permalink / raw)
To: linux-acpi
Hello
I have strange problem with cpu load and acpi_os_read_port
please look at
perf top - output:
PerfTop: 1852 irqs/sec kernel:99.4% exact: 0.0% [1000Hz
cycles], (all, 16 CPUs)
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
samples pcnt function DSO
_______ _____ _______________________________
_________________
2217.00 13.7% acpi_os_read_port
[kernel.kallsyms]
613.00 3.8% igb_poll
[kernel.kallsyms]
546.00 3.4% acpi_idle_enter_bm
[kernel.kallsyms]
482.00 3.0% _raw_spin_lock
[kernel.kallsyms]
469.00 2.9% ipt_do_table
[kernel.kallsyms]
415.00 2.6% find_busiest_group
[kernel.kallsyms]
341.00 2.1% tick_dev_program_event
[kernel.kallsyms]
299.00 1.9% u32_classify
[kernel.kallsyms]
299.00 1.9% __slab_free
[kernel.kallsyms]
294.00 1.8% timer_stats_update_stats
[kernel.kallsyms]
235.00 1.5% leave_mm
[kernel.kallsyms]
231.00 1.4% skb_release_data
[kernel.kallsyms]
227.00 1.4% __hrtimer_start_range_ns
[kernel.kallsyms]
220.00 1.4% tick_program_event
[kernel.kallsyms]
211.00 1.3% irq_entries_start
[kernel.kallsyms]
206.00 1.3% cpuidle_idle_call
[kernel.kallsyms]
181.00 1.1% acpi_hw_validate_io_request
[kernel.kallsyms]
178.00 1.1% apic_timer_interrupt
[kernel.kallsyms]
172.00 1.1% consume_skb
[kernel.kallsyms]
162.00 1.0% getnstimeofday
[kernel.kallsyms]
162.00 1.0% rb_erase
[kernel.kallsyms]
161.00 1.0% read_tsc
[kernel.kallsyms]
154.00 1.0% hrtimer_interrupt
[kernel.kallsyms]
148.00 0.9% _raw_spin_unlock_irqrestore
[kernel.kallsyms]
148.00 0.9% napi_schedule
[kernel.kallsyms]
136.00 0.8% __do_softirq
[kernel.kallsyms]
135.00 0.8% dma_issue_pending_all
[kernel.kallsyms]
130.00 0.8% virt_to_head_page
[kernel.kallsyms]
125.00 0.8% clockevents_program_event
[kernel.kallsyms]
118.00 0.7% ladder_select_state
[kernel.kallsyms]
114.00 0.7% hrtimer_force_reprogram
[kernel.kallsyms]
108.00 0.7% timekeeping_get_ns
[kernel.kallsyms]
107.00 0.7% __dma_has_cap
[kernel.kallsyms]
105.00 0.7% dev_queue_xmit
[kernel.kallsyms]
103.00 0.6% acpi_idle_do_entry
[kernel.kallsyms]
102.00 0.6% kfree
[kernel.kallsyms]
98.00 0.6% sched_clock
[kernel.kallsyms]
95.00 0.6% load_balance
[kernel.kallsyms]
95.00 0.6% pskb_expand_head
[kernel.kallsyms]
88.00 0.5% kmem_cache_free
[kernel.kallsyms]
86.00 0.5% run_timer_softirq
[kernel.kallsyms]
84.00 0.5% __rcu_pending
[kernel.kallsyms]
82.00 0.5% acpi_processor_ffh_cstate_enter
[kernel.kallsyms]
80.00 0.5% notifier_call_chain
[kernel.kallsyms]
80.00 0.5% acpi_hw_read_port
[kernel.kallsyms]
79.00 0.5% nf_iterate
[kernel.kallsyms]
77.00 0.5% dev_gro_receive
[kernel.kallsyms]
77.00 0.5% rb_insert_color
[kernel.kallsyms]
75.00 0.5% find_next_bit
[kernel.kallsyms]
74.00 0.5% skb_header_pointer
[kernel.kallsyms]
72.00 0.4% run_posix_cpu_timers
[kernel.kallsyms]
72.00 0.4% hfsc_enqueue
[kernel.kallsyms]
69.00 0.4% run_rebalance_domains
[kernel.kallsyms]
68.00 0.4% __napi_complete
[kernel.kallsyms]
67.00 0.4% ktime_get
[kernel.kallsyms]
67.00 0.4% scheduler_tick
[kernel.kallsyms]
66.00 0.4% skb_release_head_state
[kernel.kallsyms]
64.00 0.4% __run_hrtimer
[kernel.kallsyms]
64.00 0.4% acpi_hw_validate_register
[kernel.kallsyms]
62.00 0.4% ip_route_input_common
[kernel.kallsyms]
mpstat -P 1,2 1 10
Linux 2.6.35-rc5 (eP-RTR-IX-01) 07/22/10 _x86_64_
(16 CPU)
23:39:26 CPU %usr %nice %sys %iowait %irq %soft
%steal %guest %idle
23:39:27 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:27 2 0.00 0.00 0.00 0.00 0.00 17.00
0.00 0.00 83.00
23:39:28 1 0.00 0.00 0.00 0.00 0.00 39.00
0.00 0.00 61.00
23:39:28 2 0.00 0.00 0.00 0.00 0.00 8.00
0.00 0.00 92.00
23:39:29 1 0.00 0.00 0.00 0.00 0.00 47.00
0.00 0.00 53.00
23:39:29 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
23:39:30 1 58.00 0.00 0.00 0.00 0.00 42.00
0.00 0.00 0.00
23:39:30 2 0.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 82.00
23:39:31 1 9.00 0.00 0.00 0.00 0.00 51.00
0.00 0.00 40.00
23:39:31 2 2.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 80.00
23:39:32 1 0.00 0.00 0.00 0.00 0.00 39.00
0.00 0.00 61.00
23:39:32 2 2.00 0.00 0.00 0.00 0.00 20.00
0.00 0.00 78.00
23:39:33 1 0.00 0.00 0.00 0.00 0.00 48.00
0.00 0.00 52.00
23:39:33 2 0.00 0.00 0.00 0.00 0.00 13.00
0.00 0.00 87.00
23:39:34 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:34 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
23:39:35 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:35 2 0.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 82.00
23:39:36 1 0.00 0.00 0.00 0.00 0.00 50.00
0.00 0.00 50.00
23:39:36 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
Average: 1 6.70 0.00 0.00 0.00 0.00 47.20
0.00 0.00 46.10
Average: 2 0.40 0.00 0.00 0.00 0.00 13.90
0.00 0.00 85.70
Server is acting as a bgp router - 500Mbit/s RX / 500Mbit/s TX traffic.
But the topper of cpu load is acpi_os_read_port - why ?
Thanks
Pawel
^ permalink raw reply [flat|nested] 6+ messages in thread
* Strange CPU load - acpi_os_read_port
2010-07-22 19:39 Strange CPU load - acpi_os_read_port Paweł Staszewski
@ 2010-07-22 19:44 ` Paweł Staszewski
2010-08-15 3:33 ` Len Brown
1 sibling, 0 replies; 6+ messages in thread
From: Paweł Staszewski @ 2010-07-22 19:44 UTC (permalink / raw)
To: linux-acpi
Hello
I have strange problem with cpu load and acpi_os_read_port
please look at
perf top - output:
PerfTop: 1852 irqs/sec kernel:99.4% exact: 0.0% [1000Hz
cycles], (all, 16 CPUs)
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
samples pcnt function DSO
_______ _____ _______________________________
_________________
2217.00 13.7% acpi_os_read_port
[kernel.kallsyms]
613.00 3.8% igb_poll
[kernel.kallsyms]
546.00 3.4% acpi_idle_enter_bm
[kernel.kallsyms]
482.00 3.0% _raw_spin_lock
[kernel.kallsyms]
469.00 2.9% ipt_do_table
[kernel.kallsyms]
415.00 2.6% find_busiest_group
[kernel.kallsyms]
341.00 2.1% tick_dev_program_event
[kernel.kallsyms]
299.00 1.9% u32_classify
[kernel.kallsyms]
299.00 1.9% __slab_free
[kernel.kallsyms]
294.00 1.8% timer_stats_update_stats
[kernel.kallsyms]
235.00 1.5% leave_mm
[kernel.kallsyms]
231.00 1.4% skb_release_data
[kernel.kallsyms]
227.00 1.4% __hrtimer_start_range_ns
[kernel.kallsyms]
220.00 1.4% tick_program_event
[kernel.kallsyms]
211.00 1.3% irq_entries_start
[kernel.kallsyms]
206.00 1.3% cpuidle_idle_call
[kernel.kallsyms]
181.00 1.1% acpi_hw_validate_io_request
[kernel.kallsyms]
178.00 1.1% apic_timer_interrupt
[kernel.kallsyms]
172.00 1.1% consume_skb
[kernel.kallsyms]
162.00 1.0% getnstimeofday
[kernel.kallsyms]
162.00 1.0% rb_erase
[kernel.kallsyms]
161.00 1.0% read_tsc
[kernel.kallsyms]
154.00 1.0% hrtimer_interrupt
[kernel.kallsyms]
148.00 0.9% _raw_spin_unlock_irqrestore
[kernel.kallsyms]
148.00 0.9% napi_schedule
[kernel.kallsyms]
136.00 0.8% __do_softirq
[kernel.kallsyms]
135.00 0.8% dma_issue_pending_all
[kernel.kallsyms]
130.00 0.8% virt_to_head_page
[kernel.kallsyms]
125.00 0.8% clockevents_program_event
[kernel.kallsyms]
118.00 0.7% ladder_select_state
[kernel.kallsyms]
114.00 0.7% hrtimer_force_reprogram
[kernel.kallsyms]
108.00 0.7% timekeeping_get_ns
[kernel.kallsyms]
107.00 0.7% __dma_has_cap
[kernel.kallsyms]
105.00 0.7% dev_queue_xmit
[kernel.kallsyms]
103.00 0.6% acpi_idle_do_entry
[kernel.kallsyms]
102.00 0.6% kfree
[kernel.kallsyms]
98.00 0.6% sched_clock
[kernel.kallsyms]
95.00 0.6% load_balance
[kernel.kallsyms]
95.00 0.6% pskb_expand_head
[kernel.kallsyms]
88.00 0.5% kmem_cache_free
[kernel.kallsyms]
86.00 0.5% run_timer_softirq
[kernel.kallsyms]
84.00 0.5% __rcu_pending
[kernel.kallsyms]
82.00 0.5% acpi_processor_ffh_cstate_enter
[kernel.kallsyms]
80.00 0.5% notifier_call_chain
[kernel.kallsyms]
80.00 0.5% acpi_hw_read_port
[kernel.kallsyms]
79.00 0.5% nf_iterate
[kernel.kallsyms]
77.00 0.5% dev_gro_receive
[kernel.kallsyms]
77.00 0.5% rb_insert_color
[kernel.kallsyms]
75.00 0.5% find_next_bit
[kernel.kallsyms]
74.00 0.5% skb_header_pointer
[kernel.kallsyms]
72.00 0.4% run_posix_cpu_timers
[kernel.kallsyms]
72.00 0.4% hfsc_enqueue
[kernel.kallsyms]
69.00 0.4% run_rebalance_domains
[kernel.kallsyms]
68.00 0.4% __napi_complete
[kernel.kallsyms]
67.00 0.4% ktime_get
[kernel.kallsyms]
67.00 0.4% scheduler_tick
[kernel.kallsyms]
66.00 0.4% skb_release_head_state
[kernel.kallsyms]
64.00 0.4% __run_hrtimer
[kernel.kallsyms]
64.00 0.4% acpi_hw_validate_register
[kernel.kallsyms]
62.00 0.4% ip_route_input_common
[kernel.kallsyms]
mpstat -P 1,2 1 10
Linux 2.6.35-rc5 (eP-RTR-IX-01) 07/22/10 _x86_64_
(16 CPU)
23:39:26 CPU %usr %nice %sys %iowait %irq %soft
%steal %guest %idle
23:39:27 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:27 2 0.00 0.00 0.00 0.00 0.00 17.00
0.00 0.00 83.00
23:39:28 1 0.00 0.00 0.00 0.00 0.00 39.00
0.00 0.00 61.00
23:39:28 2 0.00 0.00 0.00 0.00 0.00 8.00
0.00 0.00 92.00
23:39:29 1 0.00 0.00 0.00 0.00 0.00 47.00
0.00 0.00 53.00
23:39:29 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
23:39:30 1 58.00 0.00 0.00 0.00 0.00 42.00
0.00 0.00 0.00
23:39:30 2 0.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 82.00
23:39:31 1 9.00 0.00 0.00 0.00 0.00 51.00
0.00 0.00 40.00
23:39:31 2 2.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 80.00
23:39:32 1 0.00 0.00 0.00 0.00 0.00 39.00
0.00 0.00 61.00
23:39:32 2 2.00 0.00 0.00 0.00 0.00 20.00
0.00 0.00 78.00
23:39:33 1 0.00 0.00 0.00 0.00 0.00 48.00
0.00 0.00 52.00
23:39:33 2 0.00 0.00 0.00 0.00 0.00 13.00
0.00 0.00 87.00
23:39:34 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:34 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
23:39:35 1 0.00 0.00 0.00 0.00 0.00 52.00
0.00 0.00 48.00
23:39:35 2 0.00 0.00 0.00 0.00 0.00 18.00
0.00 0.00 82.00
23:39:36 1 0.00 0.00 0.00 0.00 0.00 50.00
0.00 0.00 50.00
23:39:36 2 0.00 0.00 0.00 0.00 0.00 9.00
0.00 0.00 91.00
Average: 1 6.70 0.00 0.00 0.00 0.00 47.20
0.00 0.00 46.10
Average: 2 0.40 0.00 0.00 0.00 0.00 13.90
0.00 0.00 85.70
Server is acting as a bgp router - 500Mbit/s RX / 500Mbit/s TX traffic.
But the topper of cpu load is acpi_os_read_port - why ?
Thanks
Pawel
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Strange CPU load - acpi_os_read_port
2010-07-22 19:39 Strange CPU load - acpi_os_read_port Paweł Staszewski
2010-07-22 19:44 ` Paweł Staszewski
@ 2010-08-15 3:33 ` Len Brown
2010-08-15 10:25 ` Paweł Staszewski
1 sibling, 1 reply; 6+ messages in thread
From: Len Brown @ 2010-08-15 3:33 UTC (permalink / raw)
To: Paweł Staszewski; +Cc: linux-acpi
[-- Attachment #1: Type: TEXT/PLAIN, Size: 8228 bytes --]
On Thu, 22 Jul 2010, Paweł Staszewski wrote:
> Hello
>
> I have strange problem with cpu load and acpi_os_read_port
> please look at
> perf top - output:
> PerfTop: 1852 irqs/sec kernel:99.4% exact: 0.0% [1000Hz cycles],
> (all, 16 CPUs)
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> samples pcnt function DSO
> _______ _____ _______________________________ _________________
>
> 2217.00 13.7% acpi_os_read_port [kernel.kallsyms]
curious.
does /proc/interrupts show you are receiving acpi interrupts?
if yes, what do you see with 'grep . /sys/firmware/acpi/interrupts/*'?
what do you see with
grep . /sys/devices/system/cpu/cpu*/cpuidle/*/*
and if there are IO states, any change if you boot with "idle=halt" or
"idle=mwait"?
thanks,
-Len Brown
Intel Open Source Technology Center
> 613.00 3.8% igb_poll [kernel.kallsyms]
> 546.00 3.4% acpi_idle_enter_bm [kernel.kallsyms]
> 482.00 3.0% _raw_spin_lock [kernel.kallsyms]
> 469.00 2.9% ipt_do_table [kernel.kallsyms]
> 415.00 2.6% find_busiest_group [kernel.kallsyms]
> 341.00 2.1% tick_dev_program_event [kernel.kallsyms]
> 299.00 1.9% u32_classify [kernel.kallsyms]
> 299.00 1.9% __slab_free [kernel.kallsyms]
> 294.00 1.8% timer_stats_update_stats [kernel.kallsyms]
> 235.00 1.5% leave_mm [kernel.kallsyms]
> 231.00 1.4% skb_release_data [kernel.kallsyms]
> 227.00 1.4% __hrtimer_start_range_ns [kernel.kallsyms]
> 220.00 1.4% tick_program_event [kernel.kallsyms]
> 211.00 1.3% irq_entries_start [kernel.kallsyms]
> 206.00 1.3% cpuidle_idle_call [kernel.kallsyms]
> 181.00 1.1% acpi_hw_validate_io_request [kernel.kallsyms]
> 178.00 1.1% apic_timer_interrupt [kernel.kallsyms]
> 172.00 1.1% consume_skb [kernel.kallsyms]
> 162.00 1.0% getnstimeofday [kernel.kallsyms]
> 162.00 1.0% rb_erase [kernel.kallsyms]
> 161.00 1.0% read_tsc [kernel.kallsyms]
> 154.00 1.0% hrtimer_interrupt [kernel.kallsyms]
> 148.00 0.9% _raw_spin_unlock_irqrestore [kernel.kallsyms]
> 148.00 0.9% napi_schedule [kernel.kallsyms]
> 136.00 0.8% __do_softirq [kernel.kallsyms]
> 135.00 0.8% dma_issue_pending_all [kernel.kallsyms]
> 130.00 0.8% virt_to_head_page [kernel.kallsyms]
> 125.00 0.8% clockevents_program_event [kernel.kallsyms]
> 118.00 0.7% ladder_select_state [kernel.kallsyms]
> 114.00 0.7% hrtimer_force_reprogram [kernel.kallsyms]
> 108.00 0.7% timekeeping_get_ns [kernel.kallsyms]
> 107.00 0.7% __dma_has_cap [kernel.kallsyms]
> 105.00 0.7% dev_queue_xmit [kernel.kallsyms]
> 103.00 0.6% acpi_idle_do_entry [kernel.kallsyms]
> 102.00 0.6% kfree [kernel.kallsyms]
> 98.00 0.6% sched_clock [kernel.kallsyms]
> 95.00 0.6% load_balance [kernel.kallsyms]
> 95.00 0.6% pskb_expand_head [kernel.kallsyms]
> 88.00 0.5% kmem_cache_free [kernel.kallsyms]
> 86.00 0.5% run_timer_softirq [kernel.kallsyms]
> 84.00 0.5% __rcu_pending [kernel.kallsyms]
> 82.00 0.5% acpi_processor_ffh_cstate_enter [kernel.kallsyms]
> 80.00 0.5% notifier_call_chain [kernel.kallsyms]
> 80.00 0.5% acpi_hw_read_port [kernel.kallsyms]
> 79.00 0.5% nf_iterate [kernel.kallsyms]
> 77.00 0.5% dev_gro_receive [kernel.kallsyms]
> 77.00 0.5% rb_insert_color [kernel.kallsyms]
> 75.00 0.5% find_next_bit [kernel.kallsyms]
> 74.00 0.5% skb_header_pointer [kernel.kallsyms]
> 72.00 0.4% run_posix_cpu_timers [kernel.kallsyms]
> 72.00 0.4% hfsc_enqueue [kernel.kallsyms]
> 69.00 0.4% run_rebalance_domains [kernel.kallsyms]
> 68.00 0.4% __napi_complete [kernel.kallsyms]
> 67.00 0.4% ktime_get [kernel.kallsyms]
> 67.00 0.4% scheduler_tick [kernel.kallsyms]
> 66.00 0.4% skb_release_head_state [kernel.kallsyms]
> 64.00 0.4% __run_hrtimer [kernel.kallsyms]
> 64.00 0.4% acpi_hw_validate_register [kernel.kallsyms]
> 62.00 0.4% ip_route_input_common [kernel.kallsyms]
>
>
> mpstat -P 1,2 1 10
> Linux 2.6.35-rc5 (eP-RTR-IX-01) 07/22/10 _x86_64_ (16
> CPU)
>
> 23:39:26 CPU %usr %nice %sys %iowait %irq %soft %steal
> %guest %idle
> 23:39:27 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
> 0.00 48.00
> 23:39:27 2 0.00 0.00 0.00 0.00 0.00 17.00 0.00
> 0.00 83.00
> 23:39:28 1 0.00 0.00 0.00 0.00 0.00 39.00 0.00
> 0.00 61.00
> 23:39:28 2 0.00 0.00 0.00 0.00 0.00 8.00 0.00
> 0.00 92.00
> 23:39:29 1 0.00 0.00 0.00 0.00 0.00 47.00 0.00
> 0.00 53.00
> 23:39:29 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
> 0.00 91.00
> 23:39:30 1 58.00 0.00 0.00 0.00 0.00 42.00 0.00
> 0.00 0.00
> 23:39:30 2 0.00 0.00 0.00 0.00 0.00 18.00 0.00
> 0.00 82.00
> 23:39:31 1 9.00 0.00 0.00 0.00 0.00 51.00 0.00
> 0.00 40.00
> 23:39:31 2 2.00 0.00 0.00 0.00 0.00 18.00 0.00
> 0.00 80.00
> 23:39:32 1 0.00 0.00 0.00 0.00 0.00 39.00 0.00
> 0.00 61.00
> 23:39:32 2 2.00 0.00 0.00 0.00 0.00 20.00 0.00
> 0.00 78.00
> 23:39:33 1 0.00 0.00 0.00 0.00 0.00 48.00 0.00
> 0.00 52.00
> 23:39:33 2 0.00 0.00 0.00 0.00 0.00 13.00 0.00
> 0.00 87.00
> 23:39:34 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
> 0.00 48.00
> 23:39:34 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
> 0.00 91.00
> 23:39:35 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
> 0.00 48.00
> 23:39:35 2 0.00 0.00 0.00 0.00 0.00 18.00 0.00
> 0.00 82.00
> 23:39:36 1 0.00 0.00 0.00 0.00 0.00 50.00 0.00
> 0.00 50.00
> 23:39:36 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
> 0.00 91.00
> Average: 1 6.70 0.00 0.00 0.00 0.00 47.20 0.00
> 0.00 46.10
> Average: 2 0.40 0.00 0.00 0.00 0.00 13.90 0.00
> 0.00 85.70
>
> Server is acting as a bgp router - 500Mbit/s RX / 500Mbit/s TX traffic.
> But the topper of cpu load is acpi_os_read_port - why ?
>
>
> Thanks
> Pawel
> --
> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Strange CPU load - acpi_os_read_port
2010-08-15 3:33 ` Len Brown
@ 2010-08-15 10:25 ` Paweł Staszewski
2010-08-15 14:05 ` Len Brown
0 siblings, 1 reply; 6+ messages in thread
From: Paweł Staszewski @ 2010-08-15 10:25 UTC (permalink / raw)
To: Len Brown; +Cc: linux-acpi
W dniu 2010-08-15 05:33, Len Brown pisze:
> On Thu, 22 Jul 2010, Paweł Staszewski wrote:
>
>
>> Hello
>>
>> I have strange problem with cpu load and acpi_os_read_port
>> please look at
>> perf top - output:
>> PerfTop: 1852 irqs/sec kernel:99.4% exact: 0.0% [1000Hz cycles],
>> (all, 16 CPUs)
>> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> samples pcnt function DSO
>> _______ _____ _______________________________ _________________
>>
>> 2217.00 13.7% acpi_os_read_port [kernel.kallsyms]
>>
> curious.
> does /proc/interrupts show you are receiving acpi interrupts?
> if yes, what do you see with 'grep . /sys/firmware/acpi/interrupts/*'?
>
> what do you see with
> grep . /sys/devices/system/cpu/cpu*/cpuidle/*/*
>
> and if there are IO states, any change if you boot with "idle=halt" or
> "idle=mwait"?
>
>
:) too much time has passed since my first post
so i change many things
I can try to reproduce this again but it will take some time.
For now the solution for me was:
Change configuration for this host and boot with processor.max_cstate=0
now perf top shows:
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
PerfTop: 11670 irqs/sec kernel:99.7% exact: 0.0% [1000Hz
cycles], (all, 16 CPUs)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
samples pcnt function DSO
_______ _____ ___________________________
_________________________________
12146.00 13.6% _raw_spin_lock
/lib/modules/2.6.35/build/vmlinux
3722.00 4.2% ipt_do_table
/lib/modules/2.6.35/build/vmlinux
3161.00 3.5% rb_next
/lib/modules/2.6.35/build/vmlinux
2950.00 3.3% u32_classify
/lib/modules/2.6.35/build/vmlinux
2285.00 2.6% rb_first
/lib/modules/2.6.35/build/vmlinux
2280.00 2.6% tick_program_event
/lib/modules/2.6.35/build/vmlinux
2186.00 2.4% rb_erase
/lib/modules/2.6.35/build/vmlinux
2143.00 2.4% igb_poll
/lib/modules/2.6.35/build/vmlinux
2027.00 2.3% hfsc_enqueue
/lib/modules/2.6.35/build/vmlinux
1822.00 2.0% cftree_insert
/lib/modules/2.6.35/build/vmlinux
1791.00 2.0% vttree_insert
/lib/modules/2.6.35/build/vmlinux
1775.00 2.0% apic_timer_interrupt
/lib/modules/2.6.35/build/vmlinux
1614.00 1.8% dev_queue_xmit
/lib/modules/2.6.35/build/vmlinux
1593.00 1.8% hfsc_dequeue
/lib/modules/2.6.35/build/vmlinux
1457.00 1.6% __hrtimer_start_range_ns
/lib/modules/2.6.35/build/vmlinux
1433.00 1.6% irq_entries_start
/lib/modules/2.6.35/build/vmlinux
1359.00 1.5% rb_insert_color
/lib/modules/2.6.35/build/vmlinux
1334.00 1.5% hrtimer_interrupt
/lib/modules/2.6.35/build/vmlinux
1212.00 1.4% pskb_expand_head
/lib/modules/2.6.35/build/vmlinux
1168.00 1.3% tick_dev_program_event
/lib/modules/2.6.35/build/vmlinux
1031.00 1.2% T.1040
/lib/modules/2.6.35/build/vmlinux
1031.00 1.2% rb_last
/lib/modules/2.6.35/build/vmlinux
without processor.max_cstate=0 at boot i have
acpi_os_read_port in the top
Thanks
Pawel
> thanks,
> -Len Brown
> Intel Open Source Technology Center
>
>
>> 613.00 3.8% igb_poll [kernel.kallsyms]
>> 546.00 3.4% acpi_idle_enter_bm [kernel.kallsyms]
>> 482.00 3.0% _raw_spin_lock [kernel.kallsyms]
>> 469.00 2.9% ipt_do_table [kernel.kallsyms]
>> 415.00 2.6% find_busiest_group [kernel.kallsyms]
>> 341.00 2.1% tick_dev_program_event [kernel.kallsyms]
>> 299.00 1.9% u32_classify [kernel.kallsyms]
>> 299.00 1.9% __slab_free [kernel.kallsyms]
>> 294.00 1.8% timer_stats_update_stats [kernel.kallsyms]
>> 235.00 1.5% leave_mm [kernel.kallsyms]
>> 231.00 1.4% skb_release_data [kernel.kallsyms]
>> 227.00 1.4% __hrtimer_start_range_ns [kernel.kallsyms]
>> 220.00 1.4% tick_program_event [kernel.kallsyms]
>> 211.00 1.3% irq_entries_start [kernel.kallsyms]
>> 206.00 1.3% cpuidle_idle_call [kernel.kallsyms]
>> 181.00 1.1% acpi_hw_validate_io_request [kernel.kallsyms]
>> 178.00 1.1% apic_timer_interrupt [kernel.kallsyms]
>> 172.00 1.1% consume_skb [kernel.kallsyms]
>> 162.00 1.0% getnstimeofday [kernel.kallsyms]
>> 162.00 1.0% rb_erase [kernel.kallsyms]
>> 161.00 1.0% read_tsc [kernel.kallsyms]
>> 154.00 1.0% hrtimer_interrupt [kernel.kallsyms]
>> 148.00 0.9% _raw_spin_unlock_irqrestore [kernel.kallsyms]
>> 148.00 0.9% napi_schedule [kernel.kallsyms]
>> 136.00 0.8% __do_softirq [kernel.kallsyms]
>> 135.00 0.8% dma_issue_pending_all [kernel.kallsyms]
>> 130.00 0.8% virt_to_head_page [kernel.kallsyms]
>> 125.00 0.8% clockevents_program_event [kernel.kallsyms]
>> 118.00 0.7% ladder_select_state [kernel.kallsyms]
>> 114.00 0.7% hrtimer_force_reprogram [kernel.kallsyms]
>> 108.00 0.7% timekeeping_get_ns [kernel.kallsyms]
>> 107.00 0.7% __dma_has_cap [kernel.kallsyms]
>> 105.00 0.7% dev_queue_xmit [kernel.kallsyms]
>> 103.00 0.6% acpi_idle_do_entry [kernel.kallsyms]
>> 102.00 0.6% kfree [kernel.kallsyms]
>> 98.00 0.6% sched_clock [kernel.kallsyms]
>> 95.00 0.6% load_balance [kernel.kallsyms]
>> 95.00 0.6% pskb_expand_head [kernel.kallsyms]
>> 88.00 0.5% kmem_cache_free [kernel.kallsyms]
>> 86.00 0.5% run_timer_softirq [kernel.kallsyms]
>> 84.00 0.5% __rcu_pending [kernel.kallsyms]
>> 82.00 0.5% acpi_processor_ffh_cstate_enter [kernel.kallsyms]
>> 80.00 0.5% notifier_call_chain [kernel.kallsyms]
>> 80.00 0.5% acpi_hw_read_port [kernel.kallsyms]
>> 79.00 0.5% nf_iterate [kernel.kallsyms]
>> 77.00 0.5% dev_gro_receive [kernel.kallsyms]
>> 77.00 0.5% rb_insert_color [kernel.kallsyms]
>> 75.00 0.5% find_next_bit [kernel.kallsyms]
>> 74.00 0.5% skb_header_pointer [kernel.kallsyms]
>> 72.00 0.4% run_posix_cpu_timers [kernel.kallsyms]
>> 72.00 0.4% hfsc_enqueue [kernel.kallsyms]
>> 69.00 0.4% run_rebalance_domains [kernel.kallsyms]
>> 68.00 0.4% __napi_complete [kernel.kallsyms]
>> 67.00 0.4% ktime_get [kernel.kallsyms]
>> 67.00 0.4% scheduler_tick [kernel.kallsyms]
>> 66.00 0.4% skb_release_head_state [kernel.kallsyms]
>> 64.00 0.4% __run_hrtimer [kernel.kallsyms]
>> 64.00 0.4% acpi_hw_validate_register [kernel.kallsyms]
>> 62.00 0.4% ip_route_input_common [kernel.kallsyms]
>>
>>
>> mpstat -P 1,2 1 10
>> Linux 2.6.35-rc5 (eP-RTR-IX-01) 07/22/10 _x86_64_ (16
>> CPU)
>>
>> 23:39:26 CPU %usr %nice %sys %iowait %irq %soft %steal
>> %guest %idle
>> 23:39:27 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
>> 0.00 48.00
>> 23:39:27 2 0.00 0.00 0.00 0.00 0.00 17.00 0.00
>> 0.00 83.00
>> 23:39:28 1 0.00 0.00 0.00 0.00 0.00 39.00 0.00
>> 0.00 61.00
>> 23:39:28 2 0.00 0.00 0.00 0.00 0.00 8.00 0.00
>> 0.00 92.00
>> 23:39:29 1 0.00 0.00 0.00 0.00 0.00 47.00 0.00
>> 0.00 53.00
>> 23:39:29 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
>> 0.00 91.00
>> 23:39:30 1 58.00 0.00 0.00 0.00 0.00 42.00 0.00
>> 0.00 0.00
>> 23:39:30 2 0.00 0.00 0.00 0.00 0.00 18.00 0.00
>> 0.00 82.00
>> 23:39:31 1 9.00 0.00 0.00 0.00 0.00 51.00 0.00
>> 0.00 40.00
>> 23:39:31 2 2.00 0.00 0.00 0.00 0.00 18.00 0.00
>> 0.00 80.00
>> 23:39:32 1 0.00 0.00 0.00 0.00 0.00 39.00 0.00
>> 0.00 61.00
>> 23:39:32 2 2.00 0.00 0.00 0.00 0.00 20.00 0.00
>> 0.00 78.00
>> 23:39:33 1 0.00 0.00 0.00 0.00 0.00 48.00 0.00
>> 0.00 52.00
>> 23:39:33 2 0.00 0.00 0.00 0.00 0.00 13.00 0.00
>> 0.00 87.00
>> 23:39:34 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
>> 0.00 48.00
>> 23:39:34 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
>> 0.00 91.00
>> 23:39:35 1 0.00 0.00 0.00 0.00 0.00 52.00 0.00
>> 0.00 48.00
>> 23:39:35 2 0.00 0.00 0.00 0.00 0.00 18.00 0.00
>> 0.00 82.00
>> 23:39:36 1 0.00 0.00 0.00 0.00 0.00 50.00 0.00
>> 0.00 50.00
>> 23:39:36 2 0.00 0.00 0.00 0.00 0.00 9.00 0.00
>> 0.00 91.00
>> Average: 1 6.70 0.00 0.00 0.00 0.00 47.20 0.00
>> 0.00 46.10
>> Average: 2 0.40 0.00 0.00 0.00 0.00 13.90 0.00
>> 0.00 85.70
>>
>> Server is acting as a bgp router - 500Mbit/s RX / 500Mbit/s TX traffic.
>> But the topper of cpu load is acpi_os_read_port - why ?
>>
>>
>> Thanks
>> Pawel
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>>
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Strange CPU load - acpi_os_read_port
2010-08-15 10:25 ` Paweł Staszewski
@ 2010-08-15 14:05 ` Len Brown
2010-08-19 9:11 ` Paweł Staszewski
0 siblings, 1 reply; 6+ messages in thread
From: Len Brown @ 2010-08-15 14:05 UTC (permalink / raw)
To: Paweł Staszewski; +Cc: linux-acpi
> > > 2217.00 13.7% acpi_os_read_port
> > >
> > curious.
> > does /proc/interrupts show you are receiving acpi interrupts?
> > if yes, what do you see with 'grep . /sys/firmware/acpi/interrupts/*'?
> >
> > what do you see with
> > grep . /sys/devices/system/cpu/cpu*/cpuidle/*/*
> >
> > and if there are IO states, any change if you boot with "idle=halt" or
> > "idle=mwait"?
> I can try to reproduce this again but it will take some time.
>
> For now the solution for me was:
>
> Change configuration for this host and boot with processor.max_cstate=0
likely it will come back when you remove processor.max_cstate=0,
and it will go away if you use either idle=halt or idle=mwait or
processor.max_cstate=1, which are effectively the same.
(and all preferable to processor.max_cstate-0 from a power
saving point of view)
If this is true, then you should try processor.max_cstate=N
where N is 2, 3 etc, depending on the states shown in the
cpuidle grep above.
If you open a bugzilla and attach the output from acpidump,
that may also be helpful. If this is due to c-states, the question
is if for some reason we are not using them optimally.
If we already are doing what the platform allows, the
route might be to use PM_QOS to disable states that
are too expensive.
(Documentation/power/pm_qos_interface.txt)
cheers,
Len Brown, Intel Open Source Technology Center.
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Strange CPU load - acpi_os_read_port
2010-08-15 14:05 ` Len Brown
@ 2010-08-19 9:11 ` Paweł Staszewski
0 siblings, 0 replies; 6+ messages in thread
From: Paweł Staszewski @ 2010-08-19 9:11 UTC (permalink / raw)
To: Len Brown; +Cc: linux-acpi
W dniu 2010-08-15 16:05, Len Brown pisze:
>>>> 2217.00 13.7% acpi_os_read_port
>>>>
>>>>
>>> curious.
>>> does /proc/interrupts show you are receiving acpi interrupts?
>>> if yes, what do you see with 'grep . /sys/firmware/acpi/interrupts/*'?
>>>
>>>
cat /proc/interrupts | grep acpi
9: 0 0 0 0 0
0 0 0 0 0 0
0 0 0 0 0 IO-APIC-fasteoi acpi
No interrupts
/sys/firmware/acpi/interrupts/error: 0
/sys/firmware/acpi/interrupts/ff_gbl_lock: 0 enabled
/sys/firmware/acpi/interrupts/ff_pmtimer: 0 invalid
/sys/firmware/acpi/interrupts/ff_pwr_btn: 0 enabled
/sys/firmware/acpi/interrupts/ff_rt_clk: 0 disabled
/sys/firmware/acpi/interrupts/ff_slp_btn: 0 invalid
/sys/firmware/acpi/interrupts/gpe00: 0 invalid
/sys/firmware/acpi/interrupts/gpe01: 0 invalid
/sys/firmware/acpi/interrupts/gpe02: 0 disabled
/sys/firmware/acpi/interrupts/gpe03: 0 disabled
/sys/firmware/acpi/interrupts/gpe04: 0 disabled
/sys/firmware/acpi/interrupts/gpe05: 0 disabled
/sys/firmware/acpi/interrupts/gpe06: 0 enabled
/sys/firmware/acpi/interrupts/gpe07: 0 invalid
/sys/firmware/acpi/interrupts/gpe08: 0 enabled
/sys/firmware/acpi/interrupts/gpe09: 0 disabled
/sys/firmware/acpi/interrupts/gpe0A: 0 enabled
/sys/firmware/acpi/interrupts/gpe0B: 0 disabled
/sys/firmware/acpi/interrupts/gpe0C: 0 disabled
/sys/firmware/acpi/interrupts/gpe0D: 0 disabled
/sys/firmware/acpi/interrupts/gpe0E: 0 disabled
/sys/firmware/acpi/interrupts/gpe0F: 0 invalid
/sys/firmware/acpi/interrupts/gpe10: 0 invalid
/sys/firmware/acpi/interrupts/gpe11: 0 invalid
/sys/firmware/acpi/interrupts/gpe12: 0 invalid
/sys/firmware/acpi/interrupts/gpe13: 0 invalid
/sys/firmware/acpi/interrupts/gpe14: 0 invalid
/sys/firmware/acpi/interrupts/gpe15: 0 invalid
/sys/firmware/acpi/interrupts/gpe16: 0 invalid
/sys/firmware/acpi/interrupts/gpe17: 0 invalid
/sys/firmware/acpi/interrupts/gpe18: 0 invalid
/sys/firmware/acpi/interrupts/gpe19: 0 invalid
/sys/firmware/acpi/interrupts/gpe1A: 0 invalid
/sys/firmware/acpi/interrupts/gpe1B: 0 invalid
/sys/firmware/acpi/interrupts/gpe1C: 0 invalid
/sys/firmware/acpi/interrupts/gpe1D: 0 invalid
/sys/firmware/acpi/interrupts/gpe1E: 0 enabled
/sys/firmware/acpi/interrupts/gpe1F: 0 invalid
/sys/firmware/acpi/interrupts/gpe20: 0 disabled
/sys/firmware/acpi/interrupts/gpe21: 0 invalid
/sys/firmware/acpi/interrupts/gpe22: 0 invalid
/sys/firmware/acpi/interrupts/gpe23: 0 invalid
/sys/firmware/acpi/interrupts/gpe24: 0 invalid
/sys/firmware/acpi/interrupts/gpe25: 0 invalid
/sys/firmware/acpi/interrupts/gpe26: 0 invalid
/sys/firmware/acpi/interrupts/gpe27: 0 invalid
/sys/firmware/acpi/interrupts/gpe28: 0 invalid
/sys/firmware/acpi/interrupts/gpe29: 0 invalid
/sys/firmware/acpi/interrupts/gpe2A: 0 invalid
/sys/firmware/acpi/interrupts/gpe2B: 0 invalid
/sys/firmware/acpi/interrupts/gpe2C: 0 invalid
/sys/firmware/acpi/interrupts/gpe2D: 0 invalid
/sys/firmware/acpi/interrupts/gpe2E: 0 invalid
/sys/firmware/acpi/interrupts/gpe2F: 0 invalid
/sys/firmware/acpi/interrupts/gpe30: 0 invalid
/sys/firmware/acpi/interrupts/gpe31: 0 invalid
/sys/firmware/acpi/interrupts/gpe32: 0 invalid
/sys/firmware/acpi/interrupts/gpe33: 0 invalid
/sys/firmware/acpi/interrupts/gpe34: 0 invalid
/sys/firmware/acpi/interrupts/gpe35: 0 invalid
/sys/firmware/acpi/interrupts/gpe36: 0 invalid
/sys/firmware/acpi/interrupts/gpe37: 0 invalid
/sys/firmware/acpi/interrupts/gpe38: 0 invalid
/sys/firmware/acpi/interrupts/gpe39: 0 invalid
/sys/firmware/acpi/interrupts/gpe3A: 0 invalid
/sys/firmware/acpi/interrupts/gpe3B: 0 invalid
/sys/firmware/acpi/interrupts/gpe3C: 0 invalid
/sys/firmware/acpi/interrupts/gpe3D: 0 invalid
/sys/firmware/acpi/interrupts/gpe3E: 0 invalid
/sys/firmware/acpi/interrupts/gpe3F: 0 invalid
/sys/firmware/acpi/interrupts/gpe_all: 0
/sys/firmware/acpi/interrupts/sci: 0
/sys/firmware/acpi/interrupts/sci_not: 0
>>> what do you see with
>>> grep . /sys/devices/system/cpu/cpu*/cpuidle/*/*
>>>
>>>
ls /sys/devices/system/cpu/cpu0/
cache crash_notes node0 thermal_throttle topology
no cpuidle dir.
grep . /sys/devices/system/cpu/cpuidle/*
/sys/devices/system/cpu/cpuidle/current_driver:acpi_idle
/sys/devices/system/cpu/cpuidle/current_governor_ro:ladder
>>> and if there are IO states, any change if you boot with "idle=halt" or
>>> "idle=mwait"?
>>>
>
>> I can try to reproduce this again but it will take some time.
>>
>> For now the solution for me was:
>>
>> Change configuration for this host and boot with processor.max_cstate=0
>>
> likely it will come back when you remove processor.max_cstate=0,
> and it will go away if you use either idle=halt or idle=mwait or
> processor.max_cstate=1, which are effectively the same.
> (and all preferable to processor.max_cstate-0 from a power
> saving point of view)
>
> If this is true, then you should try processor.max_cstate=N
> where N is 2, 3 etc, depending on the states shown in the
> cpuidle grep above.
>
> If you open a bugzilla and attach the output from acpidump,
> that may also be helpful. If this is due to c-states, the question
> is if for some reason we are not using them optimally.
> If we already are doing what the platform allows, the
> route might be to use PM_QOS to disable states that
> are too expensive.
> (Documentation/power/pm_qos_interface.txt)
>
> cheers,
> Len Brown, Intel Open Source Technology Center.
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>
>
>
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2010-08-19 9:18 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2010-07-22 19:39 Strange CPU load - acpi_os_read_port Paweł Staszewski
2010-07-22 19:44 ` Paweł Staszewski
2010-08-15 3:33 ` Len Brown
2010-08-15 10:25 ` Paweł Staszewski
2010-08-15 14:05 ` Len Brown
2010-08-19 9:11 ` Paweł Staszewski
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.