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.

LoggerBuf will only output to "printf logs" when stepping, not in real time

Other Parts Discussed in Thread: SYSBIOS

I am doing some logging using xdc.runtime.LoggerBuf.  I have serveral Log_print1 commands followed by a LoggerBuf_flush(logger_handle) call.  If I run the code, I get no log outputs, although System_printf() does go to the console correctly.  If I place a breakpoint right before the LoggerBuf_flush call, then it will print the log commands to the Printf Logs tab, but only one print out per each time I click go.  If I let it run free then there are no prints.  Shouldn't this update and print in real time?  The flush statement is called about once per second.  Thanks.

  • Hi Evan,

    I don't think LoggerBuf_flush is what you want--that API is used to print out the log records to your console using System_printf. 

    If you want to see the Log records in real time, you need to add the ti.sysbios.rta.Agent to your application. Try removing your LoggerBuf_flush calls (these clear the buffers), and adding the Agent to your application, and I think that will get you what you're looking for.

    See the following article for more details on configuring your application for RTA.

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

    Thanks,

    Chris

  • I'm getting some very odd behavior.  My code is set up such that I have a clock which runs once per second.  I also have a task set up which does some initialization, then enters a while(1) loop which waits for a semaphore to run.  In the function call for this clock, it clears the semaphore once per second.  That allows my task to run through the loop once and it re-sets the semaphore.  By adding ti.sysbios.rta.Agent to my application, the program stops functioning.  I tried placing a break point in the clock function as well as in the initialization stage of my task process, but neither of them are reached.  The main function runs until the bios_start() call, but then nothing else happens.

  • What target are you working on?

    Can you try taking a look at ROV, under Tools -> ROV? Look at the Task view (ti.sysbios.knl.Task) to see what Tasks are running in the system and what their current state is.

    Thanks,

    Chris

  • I'm running on a TMS320C6472.  The tasks listed are:

    DopProc_task, priority 1, mode - Running, fxn - DopProc

    ti.sysbios.knl.Task.IdleTask, priority 0, mode - Ready, fxn - ti_sysbios_knl_Idle_loop__E

    RTA Agent, priority 1, mode - Ready, fxn - ti_sysbios_rta_Agent_taskFxn__E

  • What about the Clock view (ti.sysbios.knl.Clock)? How many ticks does it say have passed, and what's your Clock function's period in ticks?

  • There are 2 clocks listed:

     

    ti.sysbions.knl.Clock@819e38, timeout - 1000000, period - 1000000, fxn - PRITime, tRemaining - 4285505159

    ti.sysbios.knl.Clock@819e58:RTA Clock, timeout - 100000, period - 100000, fxn - ti_sysbios_rta_Agent_clockFxn__E, tRemaining - 4285505159

     

    Each time I run and then pause the system, tRemaining decreases.  Obviously tRemaining is far too large for some reason...right?

  • All of those values seem really large--timeout, period, and tRemaining are specified in Clock ticks.

    Have you changed the Clock.tickPeriod to something really small?

    Can you take a look at the 'Module' tab in ROV for the Clock module? That will show you the tick period and how many ticks have expired.

    Thanks,

    Chris

     

  • In my .cfg file, the tick period is 1 (microsecond I assume).  So with a period and timeout value of 1,000,000, it should time out once per second.  The only value that seems abnormal to me is tRemaining.  In the Module tab it shows the tick period is 1, and ticks expired advances as I would expect, at a rate of about 1000000 per second I let it run.

  • I think that's an extremely short tick period; probably what's happening is that your system is being overwhelmed by the clock tick interrupts. Try leaving the tickPeriod at its default value, which I think is supposed to give you a 1ms tick period. Then configure your Clock instance to run every 1000 ticks to make it run once a second. 

    Thanks,

    Chris

  • This does make the system run as expected with the RTA module enabled.  I didn't realize that a clock period of 1us was an issue since it was working for me until I tried to use the RTA module.

    However, this creates some new issues for me.  Well, one isn't new, the print statements still aren't coming out in real time.  Nothing shows up until I pause the system, at which point all of the buffered up commands appear in the Printf Logs display.

    Also, I'm doing some benchmarking with clock ticks, however, i'm measuring how long events take which are on the order of 1 to 10 microseconds, so now that I have my clock tick set to 1ms, I loose all the information on how long those algorithms are taking.  Should I be using something other than Clock_getTicks() to do my benchmarking?

     

    I appreciate all the help, sorry that one answer keeps leading to another question!

  • I'll take a stab at answering one of my own questions...I'm guessing I should be using Timestamp_get32() for my benchmarking.  It looks like that gives me plenty of resolution to measure those algorithms while still keeping a clock tick of 1ms.

  • Yes, the Timestamp module is a better choice for benchmarking.

    For the logs not coming out in real-time:

    • Are you using a simulator or actual hardware?
    • Can you confirm that Agent.transport is set to Agent.Transport_RTDX?
    • You can look at the Agent view in ROV to see how many records it has sent ('totalRecordsSent').
    • You can put a breakpoint on the Agent's clock function and ensure that it's being reached ('ti_sysbios_rta_Agent_clockFxn__E')

    Hopefully one of those gets us somewhere.

    Thanks,

    Chris

  • I'm using the EVM hardware.  I'm not sure what caused this to start working, but I got into work this morning and now the debug statements are printing out in real time...I wish I knew what I changed to cause it to start working, but everything seems to be working fine now.

  • I'm going to open this issue back up.  I've continued on my project and now am using 3 cores with notifications between the three.  They are all running their own code.  I have some output expected from using the Log_print1 command, however I'm not seeing anything printed to the Printf logs output.  Nothing shows up when the cores are running, nor do they show up when the cores are paused.  If I look a totalRecordsSent under Agent, it does increase each time I run and then pause the system.  Any idea why I can't get any print outs?  Does anything work differently when using multiple cores?

  • There are a couple gotchas with using RTA on multiple cores.

    http://processors.wiki.ti.com/index.php/BIOS_6_Real-Time_Analysis_(RTA)_in_CCSv4#Multi-Core_RTA

    The main one being that the data is not correlated, and you will only see RTA data for the currently selected core.

    Another, which it sounds like you're running into, is that you need to manually enable the 'Stream RTA data' button, found in the top right of the view. (Only the first core that you open RTA on will have this button enabled by default).

    Thanks,

    Chris