We have an application running on ARM (Critex-A8) of DM3730 and an algorithm executing remotely on the DSP under the Codec Engine (2.26.02.11) framework. Under normal execution the application runs for a preset amount time and then deletes the algorithm, does Engine_close and exits. We are able to do multiple run of the application in this way.
However if the application terminates abruptly (say through Ctrl-c) and thus unable to execute the normal shutdown of DSP, we sometime run into situation whereby we are unable to re-run the application. We get following error
@1,158,020us: [+0 T:0x41a93490] OP - doCmd> Enter (cmdId=1, proc=0x62840)@1,158,081us: [+0 T:0x41a93490] ti.sdo.ce.osal.Sem - Entered Sem_post> sem[0x621c0]@1,158,234us: [+0 T:0x40c49490] ti.sdo.ce.osal.Sem - Leaving Sem_pend> sem[0x621c0] status[0]@1,158,295us: [+0 T:0x40c49490] OP - getCmd_d> Exit (result=1)@1,158,356us: [+0 T:0x40c49490] OP - Processor_create_d> Enter(proc=0x62840)@1,158,417us: [+0 T:0x40c49490] ti.sdo.ce.ipc.Power - Power_on> Enter(handle=0x6285c)@1,158,448us: [+2 T:0x40c49490] ti.sdo.ce.ipc.Power - Power_on> Opening Local Power Manager for the DSP on /dev/lpm0...@1,158,570us: [+2 T:0x40c49490] ti.sdo.ce.ipc.Power - Power_on> Turning on DSP power...@1,365,479us: [+7 T:0x40c49490] ti.sdo.ce.ipc.Power - Power_on> Turning on DSP power FAILED@1,365,540us: [+2 T:0x40c49490] ti.sdo.ce.ipc.Power - Power_on> return (1)@1,365,601us: [+6 T:0x40c49490] OP - Processor_create_d> Power_on failed.@1,365,631us: [+2 T:0x40c49490] OP - Processor_create_d> return (0)@1,365,692us: [+0 T:0x40c49490] ti.sdo.ce.osal.Sem - Entered Sem_post> sem[0x621d8]@1,365,784us: [+0 T:0x40c49490] ti.sdo.ce.osal.Sem - Leaving Sem_post> sem[0x621d8]@1,365,815us: [+0 T:0x40c49490] OP - getCmd_d> Enter (proc=0x40c48dec)@1,365,876us: [+0 T:0x40c49490] ti.sdo.ce.osal.Sem - Entered Sem_pend> sem[0x621c0] timeout[0xffffffff]@1,365,937us: [+0 T:0x41a93490] ti.sdo.ce.osal.Sem - Leaving Sem_post> sem[0x621c0]@1,365,967us: [+0 T:0x41a93490] ti.sdo.ce.osal.Sem - Entered Sem_pend> sem[0x621d8] timeout[0xffffffff]
We thought one way around this issue is to explicitly call lpmOFF followed by lpmON and then rerun the application. But the lpmOFF itself fails wiht folowing o/p
==== LPM OFF Test ====app: LPM_openapp: LPM_set(LPM_CTRL_REFCOUNTOVR)app: LPM_offapp: Error: LPM_off failedapp: LPM_close==== LPM OFF test completed ====
We have following questions
1) How can we debug/fix this issue?
2) Our idea is to have signal handler installed in our application that will actually turn off/on the DSP core in the event of unexpected termination of the application. Is that doable?
3) Does LPM use DSPLink?
Sachin
If you enable trace in the LPM driver, do the trace logs provide any more details why LPM_off() is failing?
Chris
The lpm is built with debug and the trace is turned on. I have put the trace in the posting as well. Are you expecting to see more trace?
I have received some suggestion asking me to unloading/reloading LPM and DSPLINK before executing the lpmOFF/ON. On trying unload/load I get an error with unloading of dsplink
root@dm37x-evm:~/afe# rmmod lpm_omap3530.ko
root@dm37x-evm:~/afe# rmmod cmemk.ko
[80146.277343] cmemk unregistered
root@dm37x-evm:~/afe# rmmod dsplinkk.ko
ERROR: Module dsplinkk is in use
Note that I am able to unload all the modules if the application terminates correctly.
After searching the forum I found this posting http://e2e.ti.com/support/dsp/omap_applications_processors/f/447/t/156125.aspx. Comparing the o/p listed there with our o/p when the application is improperly terminated shows striking similarities.
STATUS: DEVNODE streamConfig done[ 60.157257] BUG: sleeping function called from invalid context at arch/arm/mm/fault.c:295[ 60.165863] in_atomic(): 0, irqs_disabled(): 128, pid: 1846, name: devnodeApp.xv7A[ 60.173797] INFO: lockdep is turned off.[ 60.177917] irq event stamp: 0[ 60.181091] hardirqs last enabled at (0): [< (null)>] (null)[ 60.187408] hardirqs last disabled at (0): [<c0074618>] copy_process+0x370/0xea4[ 60.195190] softirqs last enabled at (0): [<c0074618>] copy_process+0x370/0xea4[ 60.202972] softirqs last disabled at (0): [< (null)>] (null)[ 60.209320] [<c004aaf8>] (unwind_backtrace+0x0/0xec) from [<c040b198>] (do_page_fault+0xc0/0x2d0)[ 60.218627] [<c040b198>] (do_page_fault+0xc0/0x2d0) from [<c003a29c>] (do_DataAbort+0x34/0x98)[ 60.227691] [<c003a29c>] (do_DataAbort+0x34/0x98) from [<c04093ac>] (__dabt_svc+0x4c/0x60)[ 60.236358] Exception stack(0xc3803dd0 to 0xc3803e18)[ 60.241668] 3dc0: c7695008 00000000 00000000 c40760c0[ 60.250244] 3de0: c7695018 c7695008 c0092240 00000013 fffffe00 c7695008 ffffffff c00721a0[ 60.258819] 3e00: c3802000 c3803e18 c0408a58 c0219f50 60000093 ffffffff[ 60.265777] [<c04093ac>] (__dabt_svc+0x4c/0x60) from [<c0219f50>] (do_raw_spin_trylock+0x4/0x4c)[ 60.275024] [<c0219f50>] (do_raw_spin_trylock+0x4/0x4c) from [<c0408a58>] (_raw_spin_lock_irqsave+0x50/0x84)[ 60.285339] [<c0408a58>] (_raw_spin_lock_irqsave+0x50/0x84) from [<c0092240>] (remove_wait_queue+0x14/0x50)[ 60.295715] [<c0092240>] (remove_wait_queue+0x14/0x50) from [<bf01c15c>] (SYNC_WaitSEM+0x1c0/0x1f8 [dsplinkk])[ 60.306365] [<bf01c15c>] (SYNC_WaitSEM+0x1c0/0x1f8 [dsplinkk]) from [<bf012134>] (LDRV_MSGQ_get+0x8c/0xcc [dsplinkk])[ 60.317657] [<bf012134>] (LDRV_MSGQ_get+0x8c/0xcc [dsplinkk]) from [<bf01f444>] (DRV_Ioctl+0x1cc/0x7ac [dsplinkk])[ 60.328643] [<bf01f444>] (DRV_Ioctl+0x1cc/0x7ac [dsplinkk]) from [<c0113858>] (do_vfs_ioctl+0x4e0/0x54c)[ 60.338592] [<c0113858>] (do_vfs_ioctl+0x4e0/0x54c) from [<c0113914>] (sys_ioctl+0x50/0x74)[ 60.347381] [<c0113914>] (sys_ioctl+0x50/0x74) from [<c0044cc0>] (ret_fast_syscall+0x0/0x3c)[ 60.356231] Unable to handle kernel paging request at virtual address c7695008[ 60.363800] pgd = c38bc000[ 60.366638] [c7695008] *pgd=83b41011, *pte=00000000, *ppte=00000000[ 60.373229] Internal error: Oops: 7 [#1][ 60.377349] last sysfs file: /sys/kernel/uevent_seqnum[ 60.382751] Modules linked in: lpm_omap3530 dsplinkk cmemk[ 60.388519] CPU: 0 Not tainted (2.6.37-00005-g3daed69 #1)[ 60.394561] PC is at do_raw_spin_trylock+0x4/0x4c[ 60.399505] LR is at _raw_spin_lock_irqsave+0x50/0x84[ 60.404785] pc : [<c0219f50>] lr : [<c0408a58>] psr: 60000093[ 60.404815] sp : c3803e18 ip : c3802000 fp : c00721a0[ 60.416839] r10: ffffffff r9 : c7695008 r8 : fffffe00[ 60.422332] r7 : 00000013 r6 : c0092240 r5 : c7695008 r4 : c7695018[ 60.429168] r3 : c40760c0 r2 : 00000000 r1 : 00000000 r0 : c7695008[ 60.436004] Flags: nZCv IRQs off FIQs on Mode SVC_32 ISA ARM Segment user[ 60.443603] Control: 10c5387d Table: 838bc019 DAC: 00000015[ 60.449615] Process devnodeApp.xv7A (pid: 1846, stack limit = 0xc38022f0)[ 60.456756] Stack: (0xc3803e18 to 0xc3804000)[ 60.461303] 3e00: c7695018 c0408a58[ 60.469909] 3e20: 00000002 00000000 c0092240 c7695008 40000013 c3803e5c c7695008 c3802000[ 60.478485] 3e40: c3803e5c c0092240 c3802000 00000001 c7695000 bf01c15c 22222222 00000001[ 60.487060] 3e60: c40760c0 c00721a0 c7695030 c7695030 c6902000 00000000 00008000 c3803f04[ 60.495666] 3e80: c768f000 ffffffff 80008051 bf0230cc 80040800 bf012134 bf0230cc c018e03a[ 60.504241] 3ea0: c4164e80 c018e03a 0000000a 418aabcc c3802000 418aabcc 418aabb4 bf01f444[ 60.512817] 3ec0: 00000001 00000000 00000000 c0134d9c 00000000 c4164380 00000000 c0134d9c[ 60.521423] 3ee0: 00000002 00000000 00000002 00008000 40cd6880 00010001 ffffffff 00000000[ 60.529998] 3f00: 00000002 00000000 00000000 00000000 c4164e80 c018e03a 0000000a 418aabcc[ 60.538574] 3f20: 00000000 c0113858 00000000 c0106398 00000000 00000000 00000001 c38deac0[ 60.547149] 3f40: 0000000a c4164e80 0000000a 00000000 c3803f8c c0044e88 00000000 c010642c[ 60.555755] 3f60: 00000001 00000000 00000000 418aabcc c018e03a 0000000a c4164e80 c3802000[ 60.564331] 3f80: 00000000 c0113914 00000000 00000001 401f9000 00000001 000002f0 00000036[ 60.572906] 3fa0: c0044e88 c0044cc0 401f9000 00000001 0000000a c018e03a 418aabcc 0000000a[ 60.581512] 3fc0: 401f9000 00000001 000002f0 00000036 00000000 0005ff24 00061a44 418aabb4[ 60.590087] 3fe0: 00000280 418aaa98 000382a0 4032345c 80000010 0000000a 00001b02 00000018[ 60.598693] [<c0219f50>] (do_raw_spin_trylock+0x4/0x4c) from [<c0408a58>] (_raw_spin_lock_irqsave+0x50/0x84)[ 60.609008] [<c0408a58>] (_raw_spin_lock_irqsave+0x50/0x84) from [<c0092240>] (remove_wait_queue+0x14/0x50)[ 60.619323] [<c0092240>] (remove_wait_queue+0x14/0x50) from [<bf01c15c>] (SYNC_WaitSEM+0x1c0/0x1f8 [dsplinkk])[ 60.629974] [<bf01c15c>] (SYNC_WaitSEM+0x1c0/0x1f8 [dsplinkk]) from [<bf012134>] (LDRV_MSGQ_get+0x8c/0xcc [dsplinkk])[ 60.641265] [<bf012134>] (LDRV_MSGQ_get+0x8c/0xcc [dsplinkk]) from [<bf01f444>] (DRV_Ioctl+0x1cc/0x7ac [dsplinkk])[ 60.652221] [<bf01f444>] (DRV_Ioctl+0x1cc/0x7ac [dsplinkk]) from [<c0113858>] (do_vfs_ioctl+0x4e0/0x54c)[ 60.662200] [<c0113858>] (do_vfs_ioctl+0x4e0/0x54c) from [<c0113914>] (sys_ioctl+0x50/0x74)[ 60.670959] [<c0113914>] (sys_ioctl+0x50/0x74) from [<c0044cc0>] (ret_fast_syscall+0x0/0x3c)[ 60.679809] Code: c0517225 c05171a0 c05171ac e92d4010 (e5903000)[ 60.686340] ---[ end trace 2002f53a4aa51445 ]---[ 60.697875] Function : aic32xx_mute mute 1root@dm37x-evm:~/afe#
what does this call trace indicate?
For the archives, this issue was caused by a DSP-side driver that had enabled a DSP-side resource and left it on. As a result, the ARM-side LPM driver was unable to power off the DSP domain (until that DSP-side driver disabled the resource).