Wind River Support Network

HomeDefectsOVP-443
Not to be fixed

OVP-443 : When running c_ray of phoronix, generate call trace

Created: Sep 20, 2013    Updated: Mar 11, 2016
Resolved Date: May 6, 2014
Found In Version: 5.0.1
Severity: Severe
Applicable for: Wind River Linux 5
Component/s: Kernel

Description

boot guest
-------------------
taskset -c 3 /usr/bin/qemu-system-x86_64 -enable-kvm -m 4096 -cpu qemu64,+x2apic -smp 2,sockets=1,cores=2,threads=1 -name rt,process=rt-kvm -no-reboot -no-hpet -nographic -kernel /boot/guest.kernel -append "root=/dev/vda rw console=ttyS0,115200 isolcpus=1 irqaffinity=0 clocksource=tsc tsc=perfect intel_idle.max_cstate=0 processor.max_cstate=1 idle=mwait highres=on selinux=0 enforcing=0 ip=dhcp" -net nic,macaddr=de:ef:be:74:ae:e4,model=virtio -net tap,script=/etc/qemu-ifup.br -drive file=/boot/guest_raw.test,if=virtio,cache=none -vcpu 0,affinity=0x2,prio=0 -vcpu 1,affinity=0x4,prio=80 -rtc clock=host -mlock

key logs
-------------------
Task dump for CPU 13:                                                                                         
swapper/13      R  running task        0     0     24 0x00000000                                              
 ffff8807fd93ded8 ffffffff8188a6b4 ffff8807fd93dde8 ffffffff81424d34                                          
 0000000000004000 00000000fffdd54e ffff8807fd93dfd8 ffffffff81e80890                                          
 ffff8807fd93c000 ffff8807fd93dfd8 00000000ffffffff 0000000000000000                                          
Call Trace:                                                                                                   
 [<ffffffff8188a6b4>] ? __schedule+0x514/0x9b0                                                                
 [<ffffffff81424d34>] ? timerqueue_add+0x74/0xc0                                                              
 [<ffffffff814134e8>] ? pm_idle_entry_callback+0x58/0x80                                                      
 [<ffffffff8189064d>] ? notifier_call_chain+0x4d/0x70                                                         
 [<ffffffff818906bf>] ? __atomic_notifier_call_chain+0x4f/0x70                                                
 [<ffffffff810d490a>] ? rcu_eqs_enter_common.isra.47+0x3a/0xf0                                                
 [<ffffffff8100b1cb>] ? poll_idle+0x2b/0x300                                                                  
 [<ffffffff8100c84e>] ? cpu_idle+0xee/0x120                                                                   
 [<ffffffff8187a5d3>] ? start_secondary+0x1ab/0x1b0
.....
INFO: rcu_preempt detected stalls on CPUs/tasks:                                                              
	2: (8530 GPs behind) idle=98e/0/0 softirq=32/33                                                              
	10: (0 ticks this GP) idle=53c/0/0 softirq=56190/56190                                                       
	11: (2 GPs behind) idle=49e/0/0 softirq=55678/55678                                                          
	(detected by 14, t=21002 jiffies, g=23089, c=23088, q=2696)                                                  
Task dump for CPU 2:                                                                                          
swapper/2       R  running task        0     0     24 0x00000800                                              
 ffff8807fd803db8 ffffffff8188c778 ffff8807fd803e48 ffffffff8106679f                                          
 0000000000004000 000000013ffb7ac9 0000000100003ef2 ffffffff81e80890                                          
 ffff8807fd802000 ffff8807fd803fd8 00000000ffffffff 0000000000000000                                          
Call Trace:                                                                                                   
 [<ffffffff8188c778>] ? _raw_spin_unlock_irqrestore+0x18/0x50                                                 
 [<ffffffff8106679f>] __hrtimer_start_range_ns+0x1ef/0x5e0                                                    
 [<ffffffff814134e8>] ? pm_idle_entry_callback+0x58/0x80                                                      
 [<ffffffff8189064d>] ? notifier_call_chain+0x4d/0x70                                                         
 [<ffffffff8100b206>] ? poll_idle+0x66/0x300                                                                  
 [<ffffffff8100b1cb>] ? poll_idle+0x2b/0x300                                                                  
 [<ffffffff8100c84e>] ? cpu_idle+0xee/0x120                                                                   
 [<ffffffff8187a5d3>] ? start_secondary+0x1ab/0x1b0                                                           
Task dump for CPU 10:                                                                                         
swapper/10      R  running task        0     0     24 0x00000000                                              
 ffff8807fd917ed8 ffffffff8188a6b4 ffff8807fd917de8 00000047f6f61380                                          
 0000000000004000 0000000000000000 ffff8807fd917fd8 ffffffff81e80890                                          
 ffff8807fd916000 ffff8807fd917fd8 00000000ffffffff 0000000000000000                                          
Call Trace:                                                                                                   
 [<ffffffff8188a6b4>] ? __schedule+0x514/0x9b0                                                                
 [<ffffffff814134e8>] ? pm_idle_entry_callback+0x58/0x80                                                      
 [<ffffffff8189064d>] ? notifier_call_chain+0x4d/0x70                                                         
 [<ffffffff818906bf>] ? __atomic_notifier_call_chain+0x4f/0x70                                                
 [<ffffffff810d490a>] ? rcu_eqs_enter_common.isra.47+0x3a/0xf0                                                
 [<ffffffff8100b1cb>] ? poll_idle+0x2b/0x300                                                                  
 [<ffffffff8100c84e>] ? cpu_idle+0xee/0x120                                                                   
 [<ffffffff8187a5d3>] ? start_secondary+0x1ab/0x1b0                    
....
Task dump for CPU 6:                                                                                          
swapper/6       R  running task        0     0     24 0x00000000                                              
 ffff8807fd8b3de8 ffffffff81065bc6 ffff8807fd8b3de8 ffff88083facbf00                                          
 ffff88083facbce0 ffff88083facbf00 ffff8807fd8b3de8 ffffffff81e80890                                          
 ffff8807fd8b2000 ffff8807fd8b3fd8 00000000ffffffff 0000000000000000                                          
Call Trace:                                                                                                   
 [<ffffffff81065bc6>] ? __remove_hrtimer+0xc6/0xe0                                                            
 [<ffffffff814134e8>] ? pm_idle_entry_callback+0x58/0x80                                                      
 [<ffffffff8189064d>] ? notifier_call_chain+0x4d/0x70                                                         
 [<ffffffff8100b1ff>] ? poll_idle+0x5f/0x300                                                                  
 [<ffffffff8100b1cb>] ? poll_idle+0x2b/0x300                                                                  
 [<ffffffff8100c84e>] ? cpu_idle+0xee/0x120                                                                   
 [<ffffffff8187a5d3>] ? start_secondary+0x1ab/0x1b0

Workaround

NA

Steps to Reproduce

1). git on Sep 20th

2).Host
--enable-board=intel-xeon-core --enable-kernel=preempt-rt --enable-rootfs=ovp-kvm --enable-addons=wr-ovp

3). Guest
--enable-board=x86-64-kvm-guest --enable-kernel=preempt-rt --enable-rootfs=ovp-guest --enable-addons=wr-ovp --with-layer=meta-webserver --with-template=feature/target-toolchain,feature/benchmark,feature/ovp-benchmark

3). boot host
# cat /proc/cmdline 
console=ttyS0,115200 root=/dev/sda1 nfsroot=128.224.165.20:/export/pxeboot/vlm-boards/21258/rootfs rw ip=dhcp ignore_loglevel rcu_nocbs=1-3 rcu_nocb_poll isolcpus=1-3 irqaffinity=0 tsc=perfect intel_idle.max_cstate=0 processor.max_cstate=1 idle=poll selinux=0 enforcing=0 highres=on kvm.allow_unsafe_assigned_interrupts=1
Live chat
Online