[#4820] stack info will show up 2 mins after run oprofile test

Document created by Aaronwu Employee on Aug 30, 2013
Version 1Show Document
  • View in full screen mode

[#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

Attachments

    Outcomes