This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

Blocked Task(s) on TMS320C6747

Other Parts Discussed in Thread: TMS320C6747, OMAP-L137

Hello,

I do not have any prior DSP design expierence so I apologize for my ignorance.  I am attempting to debug an issue with a design that uses a TMS320C6747 executing at 300MHz.  I believe the code was orginally written for a C6701 series DSP and then ported to work on the TMS320C6747.  I have been led to believe that it worked properly on the C6701 design. 

Basically, the design implements a 10 input by 10 output audio mixer.  Each output can be mixed with any number of inputs, therefore the maximum mixing potential would be 100 channels (i.e. each output mixed with every input).  The input streams are running at 44.1kbps and are generated by TVL320AIC3106 CODECs.  The design also includes external SRAM operating a 133MHz mainly for heap storage space.  A UART interface running at 115kbps is used to configure the channel mixing assignments.  I believe DMAs are used to receive and transmit the audio streams.

The original issue that was described to me was that after enabling approximately 68 channels, the UART communications is lost and the output channels audio hangs.  I confirmed this to be the case, and it is very repeateable.  There are basically 3 user defined tasks: 1) one handles the UART communications, 2) one handles all the mixing, 3) and one blinks a heart-beat LED.

Upon attempting to debug with CCS, one of the first things I found was that the UART's task was exceeding its allocated stack space, so I increased its size which seem to resolve that issue, but it still stopped communicating after enabling 68 channels.  Now, I notice that sometimes the mixing task is being blocked by some type of semaphore.  What I think is somewhat strange is that the mixer task is assigned the highest priority of 15 (the UART is assigned 14 and the heart-beat is assigned 1) yet the heart-beat LED appears to continue to toggle normally.  As a quick test I tried swapping the priorities of the UART task and mixing task, but I could not communicate with the UART at all in this case.  I also tried to speed up the processor from 300MHz to 372MHz via the AISgen, but again it still failed at the 68th channel (I'm not sure that the clock rate got change because I suspect that the code actually includes statements to set the clock rate which may have overwritten the AISgen settings).  Also, I assume if there was some type of bandwith issue, the heart-beat task would also be stalled as it is the lowest priority task, yet it seems to toggle periodically at the same rate.

One other thing I tried was to use a Release build instead of a Debug build which is what was being used.  When I tried to execute the Release build from the on board serial Flash device, it did not function and the heart-beat LED never toggled.  I was able to load it via CCS and it failed on the 68th channel in the same was as the Debug build.  This again seems to indicate that it is NOT a bandwith issue.  Also, since the failure is so repeatable upon creating the 68th channel is an indication to me that it is more likely to be some type of memory issue.

Any debugging tips and/or insight would be greatly appreciated.

  • I have also noticed that the stack peak associated with the Kernel shows a value of all F's (i.e. 0xFFFFFFFF).  Is this a tool error or does this indicate that the Kernel stack actually overflowed and is just displaying a bad value?  I tried doubling the allocated size, but got the same results.

  • cczvx Upon capture data using the Execution graph it appears that once my mixer starts malfunctioning, both the echoTask and TSK_UART tasks stop executing.  Additionally, it appears that alot of extra time is spent executing "Other Threads" as can be seen below in the screen capture (I have also appended the log results below and colored the text in red at the point the malfunction begins).  What would cause the tasks to spot executing completely?

    356779   CLK: current time = 44414 (0x0000ad7e)

    356780   PRD: tick count = 44414 (0x0000ad7e)

    356781   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356782   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356783   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356784   CLK: current time = 44415 (0x0000ad7f)

    356785   PRD: tick count = 44415 (0x0000ad7f)

    356786   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356787   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356788   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356789   SEM: post <unknown handle> (0xc00440a4) count = 0

    356790   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356791   SEM: post <unknown handle> (0xc0043f5c) count = 0

    356792   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356793   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356794   TSK: ready echoTask (0x1183569c)

    356795   TSK: running echoTask (0x1183569c)

    356796   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356797   CLK: current time = 44416 (0x0000ad80)

    356798   PRD: tick count = 44416 (0x0000ad80)

    356799   SWI: post  PRD_swi (0x11835af0)

    356800   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356801   SWI: begin PRD_swi (0x11835af0)

    356802   PRD: end

    356803   SWI: end   PRD_swi (0x11835af0) state = done

    356804   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356805   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356806   CLK: current time = 44417 (0x0000ad81)

    356807   PRD: tick count = 44417 (0x0000ad81)

    356808   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356809   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356810   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356811   CLK: current time = 44418 (0x0000ad82)

    356812   PRD: tick count = 44418 (0x0000ad82)

    356813   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356814   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356815   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356816   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356817   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    356818   TSK: running TSK_UART (0x1183575c)

    356819   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356820   CLK: current time = 44419 (0x0000ad83)

    356821   PRD: tick count = 44419 (0x0000ad83)

    356822   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356823   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356824   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356825   CLK: current time = 44420 (0x0000ad84)

    356826   PRD: tick count = 44420 (0x0000ad84)

    356827   SWI: post  PRD_swi (0x11835af0)

    356828   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356829   SWI: begin PRD_swi (0x11835af0)

    356830   PRD: end

    356831   SWI: end   PRD_swi (0x11835af0) state = done

    356832   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356833   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356834   CLK: current time = 44421 (0x0000ad85)

    356835   PRD: tick count = 44421 (0x0000ad85)

    356836   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356837   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356838   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356839   SEM: post <unknown handle> (0xc00440a4) count = 0

    356840   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356841   SEM: post <unknown handle> (0xc0043f5c) count = 0

    356842   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356843   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356844   TSK: ready echoTask (0x1183569c)

    356845   TSK: running echoTask (0x1183569c)

    356846   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356847   CLK: current time = 44422 (0x0000ad86)

    356848   PRD: tick count = 44422 (0x0000ad86)

    356849   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356850   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356851   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356852   CLK: current time = 44423 (0x0000ad87)

    356853   PRD: tick count = 44423 (0x0000ad87)

    356854   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356855   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356856   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356857   CLK: current time = 44424 (0x0000ad88)

    356858   PRD: tick count = 44424 (0x0000ad88)

    356859   SWI: post  PRD_swi (0x11835af0)

    356860   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356861   SWI: begin PRD_swi (0x11835af0)

    356862   PRD: end

    356863   SWI: end   PRD_swi (0x11835af0) state = done

    356864   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356865   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356866   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356867   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    356868   TSK: running TSK_UART (0x1183575c)

    356869   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356870   CLK: current time = 44425 (0x0000ad89)

    356871   PRD: tick count = 44425 (0x0000ad89)

    356872   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356873   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356874   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356875   CLK: current time = 44426 (0x0000ad8a)

    356876   PRD: tick count = 44426 (0x0000ad8a)

    356877   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356878   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356879   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356880   CLK: current time = 44427 (0x0000ad8b)

    356881   PRD: tick count = 44427 (0x0000ad8b)

    356882   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356883   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356884   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356885   SEM: post <unknown handle> (0xc00440a4) count = 0

    356886   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356887   SEM: post <unknown handle> (0xc0043f5c) count = 0

    356888   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356889   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356890   TSK: ready echoTask (0x1183569c)

    356891   TSK: running echoTask (0x1183569c)

    356892   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356893   CLK: current time = 44428 (0x0000ad8c)

    356894   PRD: tick count = 44428 (0x0000ad8c)

    356895   SWI: post  PRD_swi (0x11835af0)

    356896   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356897   SWI: begin PRD_swi (0x11835af0)

    356898   PRD: end

    356899   SWI: end   PRD_swi (0x11835af0) state = done

    356900   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356901   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    356902   CLK: current time = 44429 (0x0000ad8d)

    356903   PRD: tick count = 44429 (0x0000ad8d)

    356904   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    356905   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    356906   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427282   PRD: tick count = 53186 (0x0000cfc2)

    427283   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427284   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427285   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427286   CLK: current time = 53187 (0x0000cfc3)

    427287   PRD: tick count = 53187 (0x0000cfc3)

    427288   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427289   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427290   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427291   CLK: current time = 53188 (0x0000cfc4)

    427292   PRD: tick count = 53188 (0x0000cfc4)

    427293   SWI: post  PRD_swi (0x11835af0)

    427294   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427295   SWI: begin PRD_swi (0x11835af0)

    427296   PRD: end

    427297   SWI: end   PRD_swi (0x11835af0) state = done

    427298   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427299   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427300   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427301   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    427302   TSK: running TSK_UART (0x1183575c)

    427303   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427304   CLK: current time = 53189 (0x0000cfc5)

    427305   PRD: tick count = 53189 (0x0000cfc5)

    427306   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427307   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427308   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427309   CLK: current time = 53190 (0x0000cfc6)

    427310   PRD: tick count = 53190 (0x0000cfc6)

    427311   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427312   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427313   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427314   CLK: current time = 53191 (0x0000cfc7)

    427315   PRD: tick count = 53191 (0x0000cfc7)

    427316   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427317   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427318   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427319   SEM: post <unknown handle> (0xc00440a4) count = 0

    427320   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427321   SEM: post <unknown handle> (0xc0043f5c) count = 0

    427322   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427323   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427324   TSK: ready echoTask (0x1183569c)

    427325   TSK: running echoTask (0x1183569c)

    427326   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427327   CLK: current time = 53192 (0x0000cfc8)

    427328   PRD: tick count = 53192 (0x0000cfc8)

    427329   SWI: post  PRD_swi (0x11835af0)

    427330   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427331   SWI: begin PRD_swi (0x11835af0)

    427332   PRD: end

    427333   SWI: end   PRD_swi (0x11835af0) state = done

    427334   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427335   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427336   CLK: current time = 53193 (0x0000cfc9)

    427337   PRD: tick count = 53193 (0x0000cfc9)

    427338   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427339   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427340   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427341   CLK: current time = 53194 (0x0000cfca)

    427342   PRD: tick count = 53194 (0x0000cfca)

    427343   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427344   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427345   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427346   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427347   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    427348   TSK: running TSK_UART (0x1183575c)

    427349   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427350   CLK: current time = 53195 (0x0000cfcb)

    427351   PRD: tick count = 53195 (0x0000cfcb)

    427352   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427353   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427354   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427355   CLK: current time = 53196 (0x0000cfcc)

    427356   PRD: tick count = 53196 (0x0000cfcc)

    427357   SWI: post  PRD_swi (0x11835af0)

    427358   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427359   SWI: begin PRD_swi (0x11835af0)

    427360   PRD: end

    427361   SWI: end   PRD_swi (0x11835af0) state = done

    427362   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427363   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427364   CLK: current time = 53197 (0x0000cfcd)

    427365   PRD: tick count = 53197 (0x0000cfcd)

    427366   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427367   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427368   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427369   SEM: post <unknown handle> (0xc00440a4) count = 0

    427370   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427371   SEM: post <unknown handle> (0xc0043f5c) count = 0

    427372   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427373   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427374   TSK: ready echoTask (0x1183569c)

    427375   TSK: running echoTask (0x1183569c)

    427376   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427377   CLK: current time = 53198 (0x0000cfce)

    427378   PRD: tick count = 53198 (0x0000cfce)

    427379   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427380   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427381   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427382   CLK: current time = 53199 (0x0000cfcf)

    427383   PRD: tick count = 53199 (0x0000cfcf)

    427384   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427385   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427386   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427387   CLK: current time = 53200 (0x0000cfd0)

    427388   PRD: tick count = 53200 (0x0000cfd0)

    427389   SWI: post  PRD_swi (0x11835af0)

    427390   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427391   SWI: begin PRD_swi (0x11835af0)

    427392   PRD: end

    427393   SWI: end   PRD_swi (0x11835af0) state = done

    427394   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427395   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427396   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427397   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    427398   TSK: running TSK_UART (0x1183575c)

    427399   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427400   CLK: current time = 53201 (0x0000cfd1)

    427401   PRD: tick count = 53201 (0x0000cfd1)

    427402   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427403   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427404   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    427405   CLK: current time = 53202 (0x0000cfd2)

    427406   PRD: tick count = 53202 (0x0000cfd2)

    427407   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    427408   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    427409   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536081   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536082   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536083   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    536084   TSK: running TSK_UART (0x1183575c)

    536085   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536086   CLK: current time = 66726 (0x000104a6)

    536087   PRD: tick count = 66726 (0x000104a6)

    536088   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536089   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536090   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536091   CLK: current time = 66727 (0x000104a7)

    536092   PRD: tick count = 66727 (0x000104a7)

    536093   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536094   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536095   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536096   CLK: current time = 66728 (0x000104a8)

    536097   PRD: tick count = 66728 (0x000104a8)

    536098   SWI: post  PRD_swi (0x11835af0)

    536099   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536100   SWI: begin PRD_swi (0x11835af0)

    536101   PRD: end

    536102   SWI: end   PRD_swi (0x11835af0) state = done

    536103   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536104   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536105   SEM: post <unknown handle> (0xc00440a4) count = 0

    536106   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536107   SEM: post <unknown handle> (0xc0043f5c) count = 0

    536108   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536109   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536110   TSK: ready echoTask (0x1183569c)

    536111   TSK: running echoTask (0x1183569c)

    536112   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536113   CLK: current time = 66729 (0x000104a9)

    536114   PRD: tick count = 66729 (0x000104a9)

    536115   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536116   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536117   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536118   CLK: current time = 66730 (0x000104aa)

    536119   PRD: tick count = 66730 (0x000104aa)

    536120   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536121   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536122   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536123   CLK: current time = 66731 (0x000104ab)

    536124   PRD: tick count = 66731 (0x000104ab)

    536125   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536126   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536127   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536128   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536129   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    536130   TSK: running TSK_UART (0x1183575c)

    536131   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536132   CLK: current time = 66732 (0x000104ac)

    536133   PRD: tick count = 66732 (0x000104ac)

    536134   SWI: post  PRD_swi (0x11835af0)

    536135   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536136   SWI: begin PRD_swi (0x11835af0)

    536137   PRD: end

    536138   SWI: end   PRD_swi (0x11835af0) state = done

    536139   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536140   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536141   CLK: current time = 66733 (0x000104ad)

    536142   PRD: tick count = 66733 (0x000104ad)

    536143   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536144   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536145   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536146   CLK: current time = 66734 (0x000104ae)

    536147   PRD: tick count = 66734 (0x000104ae)

    536148   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536149   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536150   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536151   SEM: post <unknown handle> (0xc00440a4) count = 0

    536152   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536153   SEM: post <unknown handle> (0xc0043f5c) count = 0

    536154   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536155   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536156   TSK: ready echoTask (0x1183569c)

    536157   TSK: running echoTask (0x1183569c)

    536158   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536159   CLK: current time = 66735 (0x000104af)

    536160   PRD: tick count = 66735 (0x000104af)

    536161   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536162   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536163   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536164   CLK: current time = 66736 (0x000104b0)

    536165   PRD: tick count = 66736 (0x000104b0)

    536166   SWI: post  PRD_swi (0x11835af0)

    536167   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536168   SWI: begin PRD_swi (0x11835af0)

    536169   PRD: end

    536170   SWI: end   PRD_swi (0x11835af0) state = done

    536171   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536172   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536173   CLK: current time = 66737 (0x000104b1)

    536174   PRD: tick count = 66737 (0x000104b1)

    536175   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536176   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536177   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536178   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536179   TSK: blocked echoTask (0x1183569c) on <unknown handle> SEM

    536180   TSK: running TSK_UART (0x1183575c)

    536181   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536182   CLK: current time = 66738 (0x000104b2)

    536183   PRD: tick count = 66738 (0x000104b2)

    536184   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536185   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536186   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536187   CLK: current time = 66739 (0x000104b3)

    536188   PRD: tick count = 66739 (0x000104b3)

    536189   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536190   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536191   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536192   CLK: current time = 66740 (0x000104b4)

    536193   PRD: tick count = 66740 (0x000104b4)

    536194   SWI: post  PRD_swi (0x11835af0)

    536195   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536196   SWI: begin PRD_swi (0x11835af0)

    536197   PRD: end

    536198   SWI: end   PRD_swi (0x11835af0) state = done

    536199   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536200   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    536201   SEM: post <unknown handle> (0xc00440a4) count = 0

    536202   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536203   SEM: post <unknown handle> (0xc0043f5c) count = 0

    536204   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    536205   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    536206   TSK: ready echoTask (0x1183569c)

    536207   TSK: running echoTask (0x1183569c)

    536208   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826608   PRD: tick count = 363524 (0x00058c04)

    2826609   SWI: post  PRD_swi (0x11835af0)

    2826610   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826611   SWI: begin PRD_swi (0x11835af0)

    2826612   PRD: end

    2826613   SWI: end   PRD_swi (0x11835af0) state = done

    2826614   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826615   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826616   CLK: current time = 363525 (0x00058c05)

    2826617   PRD: tick count = 363525 (0x00058c05)

    2826618   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826619   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826620   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826621   CLK: current time = 363526 (0x00058c06)

    2826622   PRD: tick count = 363526 (0x00058c06)

    2826623   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826624   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826625   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826626   CLK: current time = 363527 (0x00058c07)

    2826627   PRD: tick count = 363527 (0x00058c07)

    2826628   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826629   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826630   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826631   CLK: current time = 363528 (0x00058c08)

    2826632   PRD: tick count = 363528 (0x00058c08)

    2826633   SWI: post  PRD_swi (0x11835af0)

    2826634   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826635   SWI: begin PRD_swi (0x11835af0)

    2826636   PRD: end

    2826637   SWI: end   PRD_swi (0x11835af0) state = done

    2826638   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826639   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826640   CLK: current time = 363529 (0x00058c09)

    2826641   PRD: tick count = 363529 (0x00058c09)

    2826642   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826643   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826644   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826645   CLK: current time = 363530 (0x00058c0a)

    2826646   PRD: tick count = 363530 (0x00058c0a)

    2826647   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826648   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826649   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826650   CLK: current time = 363531 (0x00058c0b)

    2826651   PRD: tick count = 363531 (0x00058c0b)

    2826652   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826653   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826654   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826655   CLK: current time = 363532 (0x00058c0c)

    2826656   PRD: tick count = 363532 (0x00058c0c)

    2826657   SWI: post  PRD_swi (0x11835af0)

    2826658   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826659   SWI: begin PRD_swi (0x11835af0)

    2826660   PRD: end

    2826661   SWI: end   PRD_swi (0x11835af0) state = done

    2826662   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826663   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826664   CLK: current time = 363533 (0x00058c0d)

    2826665   PRD: tick count = 363533 (0x00058c0d)

    2826666   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826667   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826668   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826669   CLK: current time = 363534 (0x00058c0e)

    2826670   PRD: tick count = 363534 (0x00058c0e)

    2826671   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826672   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826673   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826674   CLK: current time = 363535 (0x00058c0f)

    2826675   PRD: tick count = 363535 (0x00058c0f)

    2826676   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826677   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826678   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826679   CLK: current time = 363536 (0x00058c10)

    2826680   PRD: tick count = 363536 (0x00058c10)

    2826681   SWI: post  PRD_swi (0x11835af0)

    2826682   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826683   SWI: begin PRD_swi (0x11835af0)

    2826684   PRD: end

    2826685   SWI: end   PRD_swi (0x11835af0) state = done

    2826686   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826687   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826688   CLK: current time = 363537 (0x00058c11)

    2826689   PRD: tick count = 363537 (0x00058c11)

    2826690   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826691   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826692   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826693   CLK: current time = 363538 (0x00058c12)

    2826694   PRD: tick count = 363538 (0x00058c12)

    2826695   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826696   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826697   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826698   CLK: current time = 363539 (0x00058c13)

    2826699   PRD: tick count = 363539 (0x00058c13)

    2826700   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826701   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826702   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826703   CLK: current time = 363540 (0x00058c14)

    2826704   PRD: tick count = 363540 (0x00058c14)

    2826705   SWI: post  PRD_swi (0x11835af0)

    2826706   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826707   SWI: begin PRD_swi (0x11835af0)

    2826708   PRD: end

    2826709   SWI: end   PRD_swi (0x11835af0) state = done

    2826710   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826711   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826712   CLK: current time = 363541 (0x00058c15)

    2826713   PRD: tick count = 363541 (0x00058c15)

    2826714   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826715   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826716   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826717   CLK: current time = 363542 (0x00058c16)

    2826718   PRD: tick count = 363542 (0x00058c16)

    2826719   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826720   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826721   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826722   CLK: current time = 363543 (0x00058c17)

    2826723   PRD: tick count = 363543 (0x00058c17)

    2826724   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826725   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826726   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

    2826727   CLK: current time = 363544 (0x00058c18)

    2826728   PRD: tick count = 363544 (0x00058c18)

    2826729   SWI: post  PRD_swi (0x11835af0)

    2826730   SWI: post  KNL_swi (TSK scheduler) (0x11835ac4)

    2826731   SWI: begin PRD_swi (0x11835af0)

    2826732   PRD: end

    2826733   SWI: end   PRD_swi (0x11835af0) state = done

    2826734   SWI: begin KNL_swi (TSK scheduler) (0x11835ac4)

    2826735   SWI: end   KNL_swi (TSK scheduler) (0x11835ac4) state = done

     

     

  • Does increasing stack size help to make your program run longer and then hang? If that's the case, probably you have a recursive loop which keeps calling some function.

    I would also suggest to keep the system "minimal" to debug. For example, just having the UART_TASK to run to see if your system still hangs.

  • Check out the Kernel Object Viewer (KOV/ROV) when you get to this point where it's no longer working.  Besides looking at the system stack and task stacks you should also look at the tasks and semaphores.  It should tell you whether they are blocked or running and what they are pending on.  Perhaps you have an issue where an ISR stopped firing for some reason and as a result SEM_post is no longer being called.

    Are you doing any dynamic memory allocation?  For example, do you dynamically allocate a filter object?  If so, perhaps your heap isn't big enough and you run out of space.  If you're doing any dynamic allocation make sure you always check the return argument to see if you got a NULL pointer.  Otherwise you can spend lots of time debugging an easy issue!

  • Increasing the stack size does not appear to make the program run longer, but it does cause it to change when it hangs.  In fact, it appears making slight code changes that should be unrelated cause the point at which it hangs vary.  This indicates some type of memory allocation issue to me.

    thanks for your response

  • Hi Brad,

    I used the KOV to view the task s and semaphores.  As I had seen before, it appears that the UART task is running and the Echo task is blocked by a semaphore.  Looking at the thread execution graph, it appears that SEM_POST has stopped being called as you mentioned in your reply.  What would cause this to happen and how would I go about debugging it?

    Also, the program does use dynamic memory allocation and I went back and added NULL checks in a few places that it was missing (along with some printfs to let me know if a NULL was returned), but no NULLs were detected.  Just for the heck of it, I also doubled the size of the mem_calloc requests, but the issue remains.  The point at which the hang occurs appears to vary, but the sympton seems to be the same (i.e. SEM_POST stops being called).

    One more thing, as I mentioned above, is it normal KOV to indicate 0xFFFFFFFF for the peak system stack usage?

    thanks for your help, I really appreciate it

  • Eric Hereford said:
    it appears that SEM_POST has stopped being called as you mentioned in your reply.  What would cause this to happen and how would I go about debugging it?

    Where does SEM_post get called?  Is it in an ISR?  if so, I would recommend looking at the associated peripheral configuration to see if something turned it off, corrupted a register, stopped a clock, etc.

    Eric Hereford said:
    lso, the program does use dynamic memory allocation and I went back and added NULL checks in a few places that it was missing (along with some printfs to let me know if a NULL was returned), but no NULLs were detected. 

    Be careful with those printf's (assuming "real" printf and not LOG_printf).  The standard printf requires heap space in order to print anything so if you already have one failure it's very possible that your printf will fail too!  You may want to try something like LOG_error or even setting a breakpoint there.

    Eric Hereford said:
    One more thing, as I mentioned above, is it normal KOV to indicate 0xFFFFFFFF for the peak system stack usage?

    That's weird.  I recommend that you install both the latest version of BIOS and the latest version of xdctools from here:

    http://processors.wiki.ti.com/index.php/Updating_BIOS

    To update the xdctools you will need to do the following:

    • Go to Window -> Preferences
    • Drill down to CCS -> RTSC -> Products
    • Click "Add"
    • Point to the newly installed xdctools

    Here's a screenshot of what I mean:

     

  • Hey Brad,

    I am trying to locate what function is posting the semaphores, but I believe it is related to an interrupt generated by the EDMA.  Our code is strongly based on the audio project from the OMAP-L137/TMS320C6747 Floating-Point Starter Kit.  We are mainly just adding more audio inputs/outputs.  Instead of having a single input and a single output, we have 10 of each.  I believe it would be the same interrupt mechanism as used in the example.

    Are there other simple things I could do to determine if the interrupt is some how getting turned off such as reassining where various code/data is stored (i.e. IRAM or external DSRAM) or do I need to do something like dump the memory associated with the DMA code before and after the failure?  If so do I use the map file to determine where the DMA (and possibly McASP) code is stored?

    I am going to review the audio example as much as possible to understand how the DMA and McASP are setup so I can see if the changes we made make sense.  Is there anyone that could take a quick look at our project to see if they see anything obviously incorrect with the DSP BIOS settings?

    I have not upgraded my DSP version or xdctools yet because the design has already been released to the field and I am trying to maintain the same versions if at all possible.

  • I was able to resolve my immediate need by getting a Release build to compile and execute properly!!!

    I modified the code to illuminate a spare LED when a certain function (that did most of the processing or called other functions that did) was entered and turn it off when the function was complete.  I could see that as each additional channel was enabled, the function time incremented slightly until it almost was exectuing the entire time.  After building a Release version of the code I observed that after all channels were enabled, the function was consuming a much lower percentage of the total time.

    One thing that seems a bit odd to me is that this code seems to work fine on an older DSP (mentioned in my thread above) which I assume has much lower processing capabilities than this one, but I am not sure if it was build as a Debug or Release version.

     

    thanks for all your help

    Eric

  • Thanks for reporting back.  I'm glad it was just a simple matter of turning on the optimizer!  For the purpose of being able to debug your code you might go back to your Debug build and change the optimization to -o0 or -o1.  Hopefully one of those is enough to get you into the realm of real-time but while still maintaining the ability to single-step through code, etc.

  • Well, even though turning on the optimizer reduced the amount of time that was being spent within the function, I'm not sure that I still understand the root cause.  It still seems like the system should fail more gracefully.  I think possibly the McASP has stopped generating interrupts such as described by http://e2e.ti.com/support/dsp/tms320c6000_high_performance_dsps/f/115/t/39441.aspx and therefore the EDMA stops retrieving data.  I have to verify this, but if it is the case, it seems like a very poor driver design to me (though I am not a SW person).

    thanks