Printf Statement Considered Harmful

All technical discussions and projects around startKIT
Post Reply
User avatar
ahenshaw
Experienced Member
Posts: 96
Joined: Mon Mar 22, 2010 8:55 pm

Printf Statement Considered Harmful

Post by ahenshaw »

I thought that a separate topic might make the issues of printf stand out for new users. I ran into the problem recently, and I should know better

In the XMOS toolchain, console I/O is often handled with a JTAG operation. This means that normal real-time operation cannot be expected. If you have console I/O, be prepared for timers to get totally wonked.

I just ran into this problem in an unusual way while using the PWM library. I knew that the printf statement could be a problem, so I restricted myself to printing some startup info, before the main loop was entered. Unfortunately, I had already started up the PWM manager in another thread. Even though I wasn't actively using it, it got borked by the JTAG/printf before I even sent it a command.

On the startKit, the best workaround for this problem seems to be to use the xSCOPE printf redirection facilities : How to redirect printing functions via xSCOPE.


User avatar
infiniteimprobability
XCore Legend
Posts: 1126
Joined: Thu May 27, 2010 10:08 am
Contact:

Post by infiniteimprobability »

I thought that a separate topic might make the issues of printf stand out for new users. I ran into the problem recently, and I should know better

In the XMOS toolchain, console I/O is often handled with a JTAG operation. This means that normal real-time operation cannot be expected. If you have console I/O, be prepared for timers to get totally wonked.

I just ran into this problem in an unusual way while using the PWM library. I knew that the printf statement could be a problem, so I restricted myself to printing some startup info, before the main loop was entered. Unfortunately, I had already started up the PWM manager in another thread. Even though I wasn't actively using it, it got borked by the JTAG/printf before I even sent it a command.

On the startKit, the best workaround for this problem seems to be to use the xSCOPE printf redirection facilities : How to redirect printing functions via xSCOPE.
This is a good point - printing to the stderr or stdout invokes a system call which halts the entire tile whilst the JTAG transaction takes place. Definitely not real-time and will break software peripherals on that tile on different logical cores.. Xscope fixes that and causes a very short pause on only the logical core doing the printing - much nicer.

Actually it's not printf that's the problem, it's the underlying mechanism for printing. You'd see the same issue with the lightweight debug_printf in module_logging in sc_util https://github.com/xcore/sc_util. ACtually as a side note, debug_printf will save you several KB of memory due to removing the formatted write libraries.

You're not the first to come across this - perhaps it should even be made obvious in the run configurations of the GUI.. What would have avoided this for you?

See http://www.xcore.com/forum/viewtopic.ph ... tag#p17452
User avatar
ahenshaw
Experienced Member
Posts: 96
Joined: Mon Mar 22, 2010 8:55 pm

Post by ahenshaw »

That's a good idea - make it a config option that you would have to have to check to allow JTAG transactions. Otherwise, you'd get a warning or maybe even an error if those system calls would be invoked.

Thanks for clarifying, but I did realize that it's not just printf that is the problem. I just wanted to highlight the most probable cause of this problem for new users. Hopefully, this topic will be easier to find.
Hagrid
Active Member
Posts: 44
Joined: Mon Jul 29, 2013 4:33 am

Post by Hagrid »

Thanks for the headsup. I have been trying to decode DMX512 data on a startkit and things were going out of sync on me for reasons I couldn't see. It was printf that was doing it. Applying this fix has worked perfectly.
Post Reply