Wind River Support Network

HomeDefectsLIN4-12043
Fixed

LIN4-12043 : wrl 4.2 : perf crashes on p4080 BSP (SDK 202 compatible)

Created: Aug 19, 2011    Updated: May 18, 2015
Resolved Date: Sep 28, 2011
Found In Version: 4.2
Fix Version: 4.2,4.3
Severity: Severe
Applicable for: Wind River Linux 4
Component/s: Kernel

Description

* perf crashes on perf top -e L1-dcache-loads
* root@localhost:/root> perf top -e L1-dcache-loads
WARNING: failed to keep up with mmap data.
no symbols found in /sbin/syslogd, maybe install a debug package?
WARNING: failed to keep up with mmap data.
WARNING: failed to keep up with mmap data.

-------------------------------------------------------------------------------
   PerfTop:    1992 irqs/sec  kernel:87.9% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                    DSO
             _______ _____ ___________________________ _________________

             1009.00 24.6% schedule                    [kernel.kallsyms]
              337.00  8.2% ppc_wait                    [kernel.kallsyms]
              204.00  5.0% _init                       /usr/bin/perf    
              160.00  3.9% run_timer_softirq           [kernel.kallsyms]
              122.00  3.0% load_balance                [kernel.kallsyms]
               96.00  2.3% rt_spin_lock_slowlock       [kernel.kallsyms]
               92.00  2.2% __rcu_process_callbacks     [kernel.kallsyms]
               92.00  2.2% debug_smp_processor_id      [kernel.kallsyms]
               78.00  1.9% __might_sleep               [kernel.kallsyms]
               76.00  1.9% check_for_new_grace_period  [kernel.kallsyms]
               53.00  1.3% cpumask_next_and            [kernel.kallsyms]
               51.00  1.2% scale_rt_power              [kernel.kallsyms]
               50.00  1.2% _raw_spin_unlock_irqrestore [kernel.kallsyms]
               50.00  1.2% vsnprintf                   [kernel.kallsyms]
               49.00  1.2% format_decode               [kernel.kallsyms]
               48.00  1.2% rt_spin_lock                [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    6164 irqs/sec  kernel:89.7% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

             5103.00 34.7% schedule                   [kernel.kallsyms]
             2804.00 19.0% ppc_wait                   [kernel.kallsyms]
              721.00  4.9% load_balance               [kernel.kallsyms]
              474.00  3.2% run_timer_softirq          [kernel.kallsyms]
              457.00  3.1% cpumask_next_and           [kernel.kallsyms]
              425.00  2.9% __rcu_process_callbacks    [kernel.kallsyms]
              344.00  2.3% debug_smp_processor_id     [kernel.kallsyms]
              321.00  2.2% _init                      /usr/bin/perf    
              253.00  1.7% check_for_new_grace_period [kernel.kallsyms]
              252.00  1.7% __wake_up_common           [kernel.kallsyms]
              179.00  1.2% __might_sleep              [kernel.kallsyms]
              139.00  0.9% run_ksoftirqd              [kernel.kallsyms]
              135.00  0.9% rt_spin_lock               [kernel.kallsyms]
              133.00  0.9% scale_rt_power             [kernel.kallsyms]
              131.00  0.9% transmit_chars             [kernel.kallsyms]
              116.00  0.8% force_quiescent_state      [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5317 irqs/sec  kernel:95.8% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

             8584.00 37.4% schedule                   [kernel.kallsyms]
             4487.00 19.5% ppc_wait                   [kernel.kallsyms]
             1689.00  7.4% load_balance               [kernel.kallsyms]
              914.00  4.0% cpumask_next_and           [kernel.kallsyms]
              685.00  3.0% run_timer_softirq          [kernel.kallsyms]
              583.00  2.5% __rcu_process_callbacks    [kernel.kallsyms]
              472.00  2.1% debug_smp_processor_id     [kernel.kallsyms]
              469.00  2.0% scale_rt_power             [kernel.kallsyms]
              440.00  1.9% __wake_up_common           [kernel.kallsyms]
              383.00  1.7% _init                      /usr/bin/perf    
              323.00  1.4% check_for_new_grace_period [kernel.kallsyms]
              235.00  1.0% find_next_bit              [kernel.kallsyms]
              222.00  1.0% transmit_chars             [kernel.kallsyms]
              220.00  1.0% __might_sleep              [kernel.kallsyms]
              212.00  0.9% force_quiescent_state      [kernel.kallsyms]
              179.00  0.8% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5506 irqs/sec  kernel:93.2% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            11650.00 38.2% schedule                   [kernel.kallsyms]
             5899.00 19.3% ppc_wait                   [kernel.kallsyms]
             2496.00  8.2% load_balance               [kernel.kallsyms]
             1450.00  4.8% cpumask_next_and           [kernel.kallsyms]
              823.00  2.7% run_timer_softirq          [kernel.kallsyms]
              723.00  2.4% __rcu_process_callbacks    [kernel.kallsyms]
              674.00  2.2% scale_rt_power             [kernel.kallsyms]
              637.00  2.1% debug_smp_processor_id     [kernel.kallsyms]
              602.00  2.0% __wake_up_common           [kernel.kallsyms]
              460.00  1.5% _init                      /usr/bin/perf    
              391.00  1.3% check_for_new_grace_period [kernel.kallsyms]
              341.00  1.1% find_next_bit              [kernel.kallsyms]
              307.00  1.0% transmit_chars             [kernel.kallsyms]
              291.00  1.0% __might_sleep              [kernel.kallsyms]
              241.00  0.8% force_quiescent_state      [kernel.kallsyms]
              214.00  0.7% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5314 irqs/sec  kernel:96.0% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            14341.00 38.9% schedule                   [kernel.kallsyms]
             7179.00 19.5% ppc_wait                   [kernel.kallsyms]
             3249.00  8.8% load_balance               [kernel.kallsyms]
             2007.00  5.4% cpumask_next_and           [kernel.kallsyms]
             1000.00  2.7% run_timer_softirq          [kernel.kallsyms]
              813.00  2.2% __rcu_process_callbacks    [kernel.kallsyms]
              783.00  2.1% scale_rt_power             [kernel.kallsyms]
              753.00  2.0% debug_smp_processor_id     [kernel.kallsyms]
              737.00  2.0% __wake_up_common           [kernel.kallsyms]
              488.00  1.3% _init                      /usr/bin/perf    
              452.00  1.2% check_for_new_grace_period [kernel.kallsyms]
              399.00  1.1% find_next_bit              [kernel.kallsyms]
              378.00  1.0% transmit_chars             [kernel.kallsyms]
              320.00  0.9% force_quiescent_state      [kernel.kallsyms]
              305.00  0.8% __might_sleep              [kernel.kallsyms]
              252.00  0.7% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5297 irqs/sec  kernel:95.9% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            16695.00 39.4% schedule                   [kernel.kallsyms]
             8319.00 19.6% ppc_wait                   [kernel.kallsyms]
             3873.00  9.1% load_balance               [kernel.kallsyms]
             2432.00  5.7% cpumask_next_and           [kernel.kallsyms]
             1147.00  2.7% run_timer_softirq          [kernel.kallsyms]
              961.00  2.3% __rcu_process_callbacks    [kernel.kallsyms]
              946.00  2.2% scale_rt_power             [kernel.kallsyms]
              866.00  2.0% __wake_up_common           [kernel.kallsyms]
              832.00  2.0% debug_smp_processor_id     [kernel.kallsyms]
              522.00  1.2% _init                      /usr/bin/perf    
              506.00  1.2% check_for_new_grace_period [kernel.kallsyms]
              456.00  1.1% find_next_bit              [kernel.kallsyms]
              447.00  1.1% transmit_chars             [kernel.kallsyms]
              383.00  0.9% force_quiescent_state      [kernel.kallsyms]
              323.00  0.8% __might_sleep              [kernel.kallsyms]
              284.00  0.7% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5283 irqs/sec  kernel:95.9% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            18740.00 39.7% schedule                   [kernel.kallsyms]
             9288.00 19.7% ppc_wait                   [kernel.kallsyms]
             4461.00  9.4% load_balance               [kernel.kallsyms]
             2834.00  6.0% cpumask_next_and           [kernel.kallsyms]
             1307.00  2.8% run_timer_softirq          [kernel.kallsyms]
             1077.00  2.3% __rcu_process_callbacks    [kernel.kallsyms]
              994.00  2.1% scale_rt_power             [kernel.kallsyms]
              978.00  2.1% __wake_up_common           [kernel.kallsyms]
              922.00  2.0% debug_smp_processor_id     [kernel.kallsyms]
              556.00  1.2% check_for_new_grace_period [kernel.kallsyms]
              535.00  1.1% _init                      /usr/bin/perf    
              522.00  1.1% find_next_bit              [kernel.kallsyms]
              504.00  1.1% transmit_chars             [kernel.kallsyms]
              430.00  0.9% force_quiescent_state      [kernel.kallsyms]
              335.00  0.7% __might_sleep              [kernel.kallsyms]
              286.00  0.6% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5286 irqs/sec  kernel:95.9% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            20541.00 39.9% schedule                   [kernel.kallsyms]
            10155.00 19.7% ppc_wait                   [kernel.kallsyms]
             4978.00  9.7% load_balance               [kernel.kallsyms]
             3143.00  6.1% cpumask_next_and           [kernel.kallsyms]
             1438.00  2.8% run_timer_softirq          [kernel.kallsyms]
             1101.00  2.1% __rcu_process_callbacks    [kernel.kallsyms]
             1073.00  2.1% __wake_up_common           [kernel.kallsyms]
             1035.00  2.0% scale_rt_power             [kernel.kallsyms]
              986.00  1.9% debug_smp_processor_id     [kernel.kallsyms]
              605.00  1.2% check_for_new_grace_period [kernel.kallsyms]
              589.00  1.1% find_next_bit              [kernel.kallsyms]
              578.00  1.1% _init                      /usr/bin/perf    
              545.00  1.1% transmit_chars             [kernel.kallsyms]
              478.00  0.9% force_quiescent_state      [kernel.kallsyms]
              348.00  0.7% __might_sleep              [kernel.kallsyms]
              301.00  0.6% rcu_process_callbacks      [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5296 irqs/sec  kernel:95.9% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            22094.00 40.0% schedule                   [kernel.kallsyms]
            10896.00 19.7% ppc_wait                   [kernel.kallsyms]
             5396.00  9.8% load_balance               [kernel.kallsyms]
             3502.00  6.3% cpumask_next_and           [kernel.kallsyms]
             1512.00  2.7% run_timer_softirq          [kernel.kallsyms]
             1204.00  2.2% __rcu_process_callbacks    [kernel.kallsyms]
             1164.00  2.1% __wake_up_common           [kernel.kallsyms]
             1081.00  2.0% scale_rt_power             [kernel.kallsyms]
             1049.00  1.9% debug_smp_processor_id     [kernel.kallsyms]
              640.00  1.2% check_for_new_grace_period [kernel.kallsyms]
              630.00  1.1% find_next_bit              [kernel.kallsyms]
              590.00  1.1% transmit_chars             [kernel.kallsyms]
              581.00  1.1% _init                      /usr/bin/perf    
              515.00  0.9% force_quiescent_state      [kernel.kallsyms]
              369.00  0.7% __might_sleep              [kernel.kallsyms]
              329.00  0.6% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5252 irqs/sec  kernel:96.1% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            23338.00 40.0% schedule                   [kernel.kallsyms]
            11519.00 19.7% ppc_wait                   [kernel.kallsyms]
             5641.00  9.7% load_balance               [kernel.kallsyms]
             3643.00  6.2% cpumask_next_and           [kernel.kallsyms]
             1585.00  2.7% run_timer_softirq          [kernel.kallsyms]
             1262.00  2.2% __rcu_process_callbacks    [kernel.kallsyms]
             1220.00  2.1% __wake_up_common           [kernel.kallsyms]
             1195.00  2.0% scale_rt_power             [kernel.kallsyms]
             1111.00  1.9% debug_smp_processor_id     [kernel.kallsyms]
              652.00  1.1% find_next_bit              [kernel.kallsyms]
              623.00  1.1% transmit_chars             [kernel.kallsyms]
              620.00  1.1% check_for_new_grace_period [kernel.kallsyms]
              617.00  1.1% _init                      /usr/bin/perf    
              552.00  0.9% force_quiescent_state      [kernel.kallsyms]
              403.00  0.7% __might_sleep              [kernel.kallsyms]
              352.00  0.6% rt_spin_lock               [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    6037 irqs/sec  kernel:94.8% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                   DSO
             _______ _____ __________________________ _________________

            24647.00 39.4% schedule                   [kernel.kallsyms]
            11967.00 19.1% ppc_wait                   [kernel.kallsyms]
             6202.00  9.9% load_balance               [kernel.kallsyms]
             3891.00  6.2% cpumask_next_and           [kernel.kallsyms]
             1831.00  2.9% scale_rt_power             [kernel.kallsyms]
             1422.00  2.3% run_timer_softirq          [kernel.kallsyms]
             1276.00  2.0% debug_smp_processor_id     [kernel.kallsyms]
             1267.00  2.0% __rcu_process_callbacks    [kernel.kallsyms]
             1085.00  1.7% __wake_up_common           [kernel.kallsyms]
              659.00  1.1% find_next_bit              [kernel.kallsyms]
              635.00  1.0% _init                      /usr/bin/perf    
              630.00  1.0% transmit_chars             [kernel.kallsyms]
              547.00  0.9% check_for_new_grace_period [kernel.kallsyms]
              501.00  0.8% force_quiescent_state      [kernel.kallsyms]
              454.00  0.7% rcu_process_callbacks      [kernel.kallsyms]
              438.00  0.7% run_ksoftirqd              [kernel.kallsyms]





-------------------------------------------------------------------------------
   PerfTop:    5749 irqs/sec  kernel:96.1% [1000Hz L1-dcache-loads],  (all, 8 CPUs)
-------------------------------------------------------------------------------

             samples  pcnt function                DSO
             _______ _____ _______________________ _________________

            25907.00 39.4% schedule                [kernel.kallsyms]
            12206.00 18.6% ppc_wait                [kernel.kallsyms]
             6754.00 10.3% load_balance            [kernel.kallsyms]
             4218.00  6.4% cpumask_next_and        [kernel.kallsyms]
             2440.00  3.7% scale_rt_power          [kernel.kallsyms]
             1401.00  2.1% debug_smp_processor_id  [kernel.kallsyms]
             1286.00  2.0% __rcu_process_callbacks [kernel.kallsyms]
             1268.00  1.9% run_timer_softirq       [kernel.kallsyms]Oops: Kernel access of bad area, sig: 11 [#1]
PREEMPT SMP NR_CPUS=8 LTT NESTING LEVEL : 0 
P4080 DS
last sysfs file: /sys/devices/system/cpu/online
Modules linked in: binfmt_misc ipv6 [last unloaded: scsi_wait_scan]
NIP: 00000000 LR: c0032fa4 CTR: 00000000
REGS: ebcbdc70 TRAP: 0400   Not tainted  (2.6.34.9-rt-WR4.2.0.0_preempt_rt)
MSR: 00021002 <ME,CE>  CR: 42000084  XER: 20000000
TASK = ebc945c0[0] 'swapper' THREAD: ebcbc000 CPU: 2
GPR00: 00000000 ebcbdd20 ebc945c0 c146df00 ebcc1120 00000001 00000000 a1034786 
GPR08: 00000004 c060cf78 00000000 33899c3f 24000082 00000000 08002040 7fffffff 
GPR16: 80000000 ebcbded0 ebcbddf8 7fffff2e 00000000 7fffff2e ea6d10e8 ea6d1100 
GPR24: 00000000 00000001 0000001e c07ea458 00000000 ebcbc000 c146df00 ebcc1120 
NIP [00000000] (null)
LR [c0032fa4] enqueue_task+0x40/0x5c
Call Trace:
[ebcbdd20] [c0037bb8] task_rq_lock+0x50/0xa0 (unreliable)
[ebcbdd30] [c0033120] activate_task+0x40/0x60
[ebcbdd40] [c00407a8] try_to_wake_up+0x1b8/0x404
[ebcbdd80] [c0085be8] wakeup_next_waiter+0x15c/0x160
[ebcbdda0] [c05f5c90] rt_spin_lock_slowunlock+0x38/0x84
[ebcbddb0] [c0375210] atomic64_read+0x50/0x78
[ebcbddd0] [c00d597c] perf_event_update_userpage+0xa4/0x144
[ebcbddf0] [c00174a8] perf_event_interrupt+0x160/0x274
[ebcbdea0] [c000e7a0] performance_monitor_exception+0x6c/0x13c
[ebcbdec0] [c0012060] ret_from_except_full+0x0/0x4c
--- Exception: 2060 at ppc_wait+0x4/0x8
    LR = cpu_idle_simple+0x60/0xb4
[ebcbdf80] [c0009218] cpu_idle_simple+0x34/0xb4 (unreliable)
[ebcbdfa0] [c00092c4] cpu_idle+0x2c/0x174
[ebcbdfc0] [c05fc72c] start_secondary+0x324/0x33c
[ebcbdff0] [c0001a84] __secondary_start+0x30/0x84
Instruction dump:
XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX 
XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX 
Kernel panic - not syncing: Fatal exception in interrupt
Call Trace:
[ebcbdba0] [c0007fc8] show_stack+0x44/0x160 (unreliable)
[ebcbdbd0] [c05f6fc4] panic+0x12c/0x1a0
[ebcbdc20] [c000f0dc] die+0x13c/0x224
[ebcbdc50] [c0017d34] bad_page_fault+0x90/0xc8
[ebcbdc60] [c0011f14] handle_page_fault+0x7c/0x80
--- Exception: 400 at (null)
    LR = enqueue_task+0x40/0x5c
[ebcbdd20] [c0037bb8] task_rq_lock+0x50/0xa0 (unreliable)
[ebcbdd30] [c0033120] activate_task+0x40/0x60
[ebcbdd40] [c00407a8] try_to_wake_up+0x1b8/0x404
[ebcbdd80] [c0085be8] wakeup_next_waiter+0x15c/0x160
[ebcbdda0] [c05f5c90] rt_spin_lock_slowunlock+0x38/0x84
[ebcbddb0] [c0375210] atomic64_read+0x50/0x78
[ebcbddd0] [c00d597c] perf_event_update_userpage+0xa4/0x144
[ebcbddf0] [c00174a8] perf_event_interrupt+0x160/0x274
[ebcbdea0] [c000e7a0] performance_monitor_exception+0x6c/0x13c
[ebcbdec0] [c0012060] ret_from_except_full+0x0/0x4c
--- Exception: 2060 at ppc_wait+0x4/0x8
    LR = cpu_idle_simple+0x60/0xb4
[ebcbdf80] [c0009218] cpu_idle_simple+0x34/0xb4 (unreliable)
[ebcbdfa0] [c00092c4] cpu_idle+0x2c/0x174
[ebcbdfc0] [c05fc72c] start_secondary+0x324/0x33c
[ebcbdff0] [c0001a84] __secondary_start+0x30/0x84
Rebooting in 180 seconds..

Steps to Reproduce

configure --with-layer=/work/adietsch/ALU/alu_bcem_42_SDK_22/wrlinux-4/layers/wrll-analysis-1.0 --enable-board=fsl_p4080 --enable-kernel=preempt_rt --enable-rootfs=glibc_std --enable-jobs=8 --enable-test=yes --enable-force-add-depends=yes --enable-internet-download=yes --with-template=test/netperf 
make -C perf.addpkg
make -C build linux.menuconfig -> add CONFIG_PERF_EVENTS=y
make build-all

load kernel,dtb,fs

on the target :

perf top -e L1-dcache-loads


-> crash as symtoms

Other Downloads


Live chat
Online