[#4820] stack info will show up 2 mins after run oprofile test
Submitted By: Vivi Li
Open Date
2009-01-19 03:55:33 Close Date
2009-03-02 05:36:26
Priority:
Medium Assignee:
Graf Yang
Status:
Closed Fixed In Release:
N/A
Found In Release:
N/A Release:
Category:
N/A Board:
N/A
Processor:
ALL Silicon Revision:
Is this bug repeatable?:
Yes Resolution:
Rejected
Uboot version or rev.:
Toolchain version or rev.:
gcc4.1-2008_Dec_12
App binary format:
N/A
Summary: stack info will show up 2 mins after run oprofile test
Details:
Run oprofile test, stack info will show up after 2 mins.
Bellow is the log:
--
Linux version 2.6.28-ADI-2009R1-pre-svn6027 (test@107-local) (gcc version 4.1.2 (ADI svn)) #351 Mon9
console [early_BFuart0] enabled
early printk enabled on early_BFuart0
Warning: limiting memory to 56MB due to hardware anomaly 05000263
Board Memory: 64MB
Kernel Managed Memory: 64MB
Memory map:
fixedcode = 0x00000400-0x00000490
text = 0x00001000-0x0010d3d0
rodata = 0x0010d3d0-0x00160380
bss = 0x00160380-0x0016ef08
data = 0x0016ef08-0x00180000
stack = 0x0017e000-0x00180000
init = 0x00180000-0x00eeb000
available = 0x00eeb000-0x037ff000
DMA Zone = 0x03f00000-0x04000000
Hardware Trace Active and Enabled
Boot Mode: 0
Blackfin support (C) 2004-2008 Analog Devices, Inc.
Compiled for ADSP-BF537 Rev 0.2
Blackfin Linux support by blackfin.uclinux.org/
Processor Speed: 500 MHz core clock and 100 MHz System Clock
NOMPU: setting up cplb tables
Instruction Cache Enabled for CPU0
Data Cache Enabled for CPU0 (write-through)
Built 1 zonelists in Zone order, mobility grouping off. Total pages: 14223
Kernel command line: root=/dev/mtdblock0 rw earlyprintk=serial,uart0,57600 console=ttyBF0,57600 ip=f
Configuring Blackfin Priority Driven Interrupts
PID hash table entries: 256 (order: 8, 1024 bytes)
console handover: boot [early_BFuart0] -> real [ttyBF0]
Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Memory available: 41484k/65536k RAM, (13740k init code, 1072k kernel code, 460k data, 1024k dma, 77)
Calibrating delay loop... 995.32 BogoMIPS (lpj=1990656)
Security Framework initialized
Mount-cache hash table entries: 512
Blackfin Scratchpad data SRAM: 4 KB
Blackfin L1 Data A SRAM: 16 KB (15 KB free)
Blackfin L1 Data B SRAM: 16 KB (16 KB free)
Blackfin L1 Instruction SRAM: 48 KB (41 KB free)
PDA for CPU0 reserved at 00161468
net_namespace: 288 bytes
NET: Registered protocol family 16
Blackfin GPIO Controller
Blackfin DMA Controller
stamp_init(): registering device resources
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 2048 (order: 2, 16384 bytes)
TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
TCP: Hash tables configured (established 2048 bind 2048)
TCP reno registered
NET: Registered protocol family 1
msgmni has been set to 81
io scheduler noop registered
io scheduler anticipatory registered (default)
io scheduler cfq registered
Serial: Blackfin serial driver
bfin-uart.1: ttyBF0 at MMIO 0xffc00400 (irq = 18) is a BFIN-UART
brd: module loaded
bfin_mac_mdio: probed
bfin_mac: attached PHY driver [SMSC LAN83C185] (mii_bus:phy_addr=0:01, irq=-1, mdc_clk=2500000Hz(md)
bfin_mac bfin_mac.0: Blackfin on-chip Ethernet MAC driver, Version 1.1
bfin-spi bfin-spi.0: Blackfin on-chip SPI Controller Driver, Version 1.0, regs_base@ffc00500, dma c7
rtc-bfin rtc-bfin: rtc core: registered rtc-bfin as rtc0
bfin-wdt: initialized: timeout=20 sec (nowayout=0)
oprofile: using timer interrupt.
TCP cubic registered
NET: Registered protocol family 17
rtc-bfin rtc-bfin: setting system clock to 1970-01-01 03:20:37 UTC (12037)
IP-Config: Complete:
device=eth0, addr=10.100.4.50, mask=255.255.255.0, gw=10.100.4.174,
host=bf537-stamp, domain=, nis-domain=(none),
bootserver=10.100.4.174, rootserver=10.100.4.174, rootpath=
Freeing unused kernel memory: 13740k freed
dma_alloc_init: dma_page @ 0x00ee7000 - 256 pages at 0x03f00000
_____________________________________
a8888b. / Welcome to the uClinux distribution \
d888888b. / _ _ \
8P"YP"Y88 / | | |_| __ __ (TM) |
8|o||o|88 _____/ | | _ ____ _ _ \ \/ / |
8' .88 \ | | | | _ \| | | | \ / |
8`._.' Y8. \ | |__ | | | | | |_| | / \ |
d/ `8b. \ \____||_|_| |_|\____|/_/\_\ |
dP . Y8b. \ For embedded processors including |
d8:' " `::88b \ the Analog Devices Blackfin /
d8" 'Y88b \___________________________________/
:8P ' :888
8a. : _a88P For further information, check out:
._/"Yaa_: .| 88P| - blackfin.uclinux.org/
\ YP" `| 8P `. - docs.blackfin.uclinux.org/
/ \.___.d| .' - www.uclinux.org/
`--..__)8888P`._.' jgs/a:f - www.analog.com/blackfin
Have a lot of fun...
BusyBox v1.13.2 (2009-01-19 11:36:02 CST) built-in shell (msh)
Enter 'help' for a list of built-in commands.
root:/> PHY: 0:01 - Link is Up - 100/Full
root:/>
root:/>
root:/> /usr/bin/bfin_opcontrol --init
root:/> /usr/bin/bfin_opcontrol --start-daemon &
Using 2.6+ OProfile kernel interface.
Reading module info.
Using log file /var/lib/oprofile/oprofiled.log
164
root:/> /usr/bin/bfin_opcontrol --start
root:/> /usr/bin/bfin_opcontrol --dump
root:/>
root:/> /usr/bin/opreport -l
CPU: CPU with timer interrupt, speed 500 MHz (estimated)
Profiling through timer interrupt
warning: /bin/busybox is not in a usable binary format.
warning: could not check that the binary file /vmlinux has not been modified since the profile was .
samples % app name symbol name
2 50.0000 busybox (no symbols)
1 25.0000 vmlinux _bfin_get_addr_from_rp
1 25.0000 vmlinux _calc_reloc
root:/> INFO: task oprofiled:165 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
oprofiled D ffa008c8 0 165 1
Stack info:
SP: [0x02773db8] <0x02773db8> /* kernel dynamic memory */
FP: (0x02773dd4)
Memory from 0x02773db0 to 02774000
02773db0: 037c598c 001629ec [02729060] 037c5960 0378a0a0 027291e0 001629ec 00000002
02773dd0: 02772000 (02773df4)<ffa0145e> 02773e2c <0003e700> 00000000 <0010c298> 02772000
02773df0: 02772000 (02773e6c)<0010c298> 02772000 02772000 02773eac 7fffffff 00000000
02773e10: 00000002 00170490 003d08bd 02773e48 <0000ac06> 02773e44 <0010c078> 0378a6a0
02773e30: 7fffffff 00000000 00000000 <0010c100> 02772000 7fffffff 00000000 02773e80
02773e50:<0000dc14> 001629ec 00000001 0378a0a0 0000afe4 02773eb0 02773eb0 (00000000)
02773e70:<0000f0a6> 0378a6a0 00004000 000000a6 02772000 00000000 00000000 00000000
02773e90: 037f32a0 00cbddf4 02773f24 00000000 00000000 00000000 00000000 00000000
02773eb0: 02773e64 02773e64 00000000 00cbde00 <00001638> ffa000e0 000000be 00cbdf18
02773ed0: 00000000 ffffe000 00000004 00ca07c8 0003f958 <0003f816> 037ea5c0 00000000
02773ef0: 00000000 00000000 <ffa000ec><ffa00804><ffa00804> 0003f7b0 <ffa00804> 00cac7d8
02773f10: 00cac7d8 00cbddb8 00d80ff4 00ca07c8 00000004 00ca8052 00008000 00000000
02773f30: 00000000 02774000 00ca8052 00ca8052 <00ca07a0><ffa00d6c> 02003025 00ca315d
02773f50: 00caaadd 00ca3158 00caaadc 00000000 00000000 00000000 00000000 00000000
02773f70: 00000000 00000000 00000000 00000000 00cbd9a8 00000000 00000000 00000000
02773f90: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 19000000
02773fb0: 00cbcb55 00cbddf4 00cbde00 00cb39bc 00cb39b4 00cbdf18 00d80008 00000400
02773fd0: 000000be 00cb3720 02766004 00000004 00ca07c8 00d80ff4 00000000 00000001
02773ff0: 00000000 00000000 000000be 00000006 0378a6a0
Return addresses in stack:
frame 1 : <0xffa0145e> { _schedule + 0x19e }
address : <0x0003e700> { _kmem_cache_alloc + 0x54 }
address : <0x0010c298> { _schedule_timeout + 0x70 }
frame 2 : <0x0010c298> { _schedule_timeout + 0x70 }
address : <0x0000ac06> { _enqueue_task_fair + 0x36 }
address : <0x0010c078> { __cond_resched + 0x34 }
address : <0x0010c100> { _wait_for_common + 0x84 }
address : <0x0000dc14> { _wake_up_new_task + 0x84 }
frame 3 : <0x0000f0a6> { _do_fork + 0x10a }
address : <0x00001638> { _bfin_vfork + 0x18 }
address : <0x0003f816> { _sys_close + 0x66 }
address : <0xffa000ec> { _sys_vfork + 0xc }
address : <0xffa00804> { _system_call + 0x68 }
address : <0xffa00804> { _system_call + 0x68 }
address : <0xffa00804> { _system_call + 0x68 }
address : <0x00ca07a0> [ /usr/bin/oprofiled + 0x7a0 ]
address : <0xffa00d6c> { _evt_system_call + 0x64 }
INFO: task oprofiled:166 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
oprofiled D ffa008c8 0 166 165
Stack info:
SP: [0x02775db8] <0x02775db8> /* kernel dynamic memory */
FP: (0x02775dd4)
Memory from 0x02775db0 to 02776000
02775db0: 0378a3cc 001629ec [02729de0] 0378a3a0 0378a6a0 027291e0 001629ec 00000002
02775dd0: 02774000 (02775df4)<ffa0145e> 02775e2c <0003e700> 00000000 <0010c298> 02774000
02775df0: 02774000 (02775e6c)<0010c298> 02774000 02774000 02775eac 7fffffff 00000000
02775e10: 00000002 00170490 003d08bd 02775e48 <0000ac06> 02775e44 <0010c078> 037af640
02775e30: 7fffffff 00000000 00000000 <0010c100> 02774000 7fffffff 00000000 <0000dc14>
02775e50: 001629ec 037af640 00000001 0378a6a0 0000afe4 02775eb0 02775eb0 (00000000)
02775e70:<0000f0a6> 037af640 00004000 000000a7 02774000 00000000 00000000 00000000
02775e90: 00000000 00cbddf4 02775f24 00000000 00000000 00000000 00000000 00000000
02775eb0: 02775e64 02775e64 00000000 00cbde00 <00001638> ffa000e0 000000be 00cbdf18
02775ed0: 00000000 ffffe000 00000004 00ca07c8 <0001b12e><0001b134> 0378a6a0 00000000
02775ef0: 00000000 00000000 <ffa000ec><ffa00804> 0001b0cc 00000000 <ffa00804> 027291e0
02775f10: 027291e0 001629ec 00d80ff4 00ca07c8 00000004 00ca8052 00008000 00000000
02775f30: 00000000 02776000 00ca8052 00ca8052 <00ca07a0><ffa00d6c> 02003004 00ca315d
02775f50: 00caaadd 00ca3158 00caaadc 00000000 00000000 00000000 00000000 00000000
02775f70: 00000000 00000000 00000000 00000000 00cbd9a8 00000000 00000000 00000000
02775f90: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 19000000
02775fb0: 00cbcb55 00cbddf4 00cbde00 00cb39bc 00cb39b4 00cbdf18 00d80008 00000400
02775fd0: 000000be 00cb3720 02766004 00000004 00ca07c8 00d80ff4 00000000 00000001
02775ff0: 000000a6 000000a6 000000be 00000006 037af640
Return addresses in stack:
frame 1 : <0xffa0145e> { _schedule + 0x19e }
address : <0x0003e700> { _kmem_cache_alloc + 0x54 }
address : <0x0010c298> { _schedule_timeout + 0x70 }
frame 2 : <0x0010c298> { _schedule_timeout + 0x70 }
address : <0x0000ac06> { _enqueue_task_fair + 0x36 }
address : <0x0010c078> { __cond_resched + 0x34 }
address : <0x0010c100> { _wait_for_common + 0x84 }
address : <0x0000dc14> { _wake_up_new_task + 0x84 }
frame 3 : <0x0000f0a6> { _do_fork + 0x10a }
address : <0x00001638> { _bfin_vfork + 0x18 }
address : <0x0001b12e> { _sys_setsid + 0x62 }
address : <0x0001b134> { _sys_setsid + 0x68 }
address : <0xffa000ec> { _sys_vfork + 0xc }
address : <0xffa00804> { _system_call + 0x68 }
address : <0xffa00804> { _system_call + 0x68 }
address : <0x00ca07a0> [ /usr/bin/oprofiled + 0x7a0 ]
address : <0xffa00d6c> { _evt_system_call + 0x64 }
--
Follow-ups
--- Graf Yang 2009-02-04 04:50:10
Not be afraid of it. It not a bug.
Daemon oprofiled always wait on reading the sample buffer, and it may take a
long time until the sample buffer is full.
When opened CONFIG_DETECT_SOFTLOCKUP, the stack info will be dumped.
Try "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" to disable
it.
Files
Changes
Commits
Dependencies
Duplicates
Associations
Tags
File Name File Type File Size Posted By
No Files Were Found