DaDebug

Does anyone know why output using DADebug would disappear or become corrupt and then correct itself?

example:

EtherUSB: net_attempt_transmit (845) (3841): quard=1
USBDriver: 201d8914 resume ep = 2
USBDriver: 201d8914 start_write
USBDriver: no more data to write
USBDriver:  start_write(2818)
USBDriver: 201d8914 start_write
USBDriver: no more data to write
USBDriver:  start_write(2818)
quard=1
pt_transEtherUSB: mit (845) (3841): DWCDriver: softc_device_start (117) (3845): xfer=201cd174 pipe=201cd554 urb=201cd1f8 active=0 nframes=0
DWCDriver: softc_device_start (212) (3845): enqueue finished
DWCDriver: hcd_op_complete (445) (3845): xfer 201cd174 DWC status 0

The line starting guard=1 doesn’t have the module and function printed before it and the next line is a complete jumble. The 3841 is 3841csecs and when it corrects itself on the same line it’s 4csecs later (3845)

Im trying to track the networking problem. I’m finding when doing a ‘dadprint’ there are several corruptions of the output. I believe that they correspond in some cases to the hourglass appearing during a transfer because seconds can dissappear from the output and while the hourglass is on taskwindows and desktop freeze – mouse continues to work.

Anyone know what will make a taskwindow freeze?

I’m fairly sure at the moment that it isn’t a problem with the DWCDriver as I can reproduce the problem in an Iyonix and a Beagle if I use an USB Ethernet dongle on either. So it’s either the USB front end – but that works with non USB ethernet on an Iyonix – or the EtherUSB front end.

Hmmmm…..

Does anyone know why output using DADebug would disappear or become corrupt and then correct itself?

DebugLib (which is where the usb driver debug output goes before it arrives in DADebug) uses a static buffer to format the strings before sending them off to DADebug. So it’s possible for debug output which occurs from an interrupt to corrupt debug output being produced by the foreground. The fix for this I use locally is just to go into DebugLib.c.debug, delete the static debug_buffer, and add local, non-static versions to the functions that were using it. After doing that you’ll need to do a lib export phase. I might check this change in, since I think we’ve generally got enough stack space spare to cope with an extra (IIRC) 512 bytes for a debug buffer every so often.

Other possibilities are that DADebug is receiving text faster than *DADPrint can print it out – because DADebug uses a circular buffer this will cause it to write straight over the bit which is being printed out and you’ll get a big jump in whatever timestamps you’re using. Fixes for this are to use a larger buffer size (tweakable in the DADebug sources), log the output to something with a bit more throughput (redirect the output to a file in the RAM disc?), tweak the debug levels to reduce the amount of output that things are producing, or go for the extreme approach of halting the system entirely (e.g. HangWatch)

Anyone know what will make a taskwindow freeze?

Most likely a callback taking a long time to execute. I’d guess the network FS (lanman was it?) is sat inside a callback waiting for something to happen with the hourglass up.

If you want a high-level overview of what’s going on then it might be worth giving fiqprof a try. It uses a high-frequency timer to sample the CPU state over a period of time and spits out a log file which can then be analysed. E.g. with the graph view you can usually spot pretty quickly which module is responsible for the blocking delay with the hourglass. Or you might get lucky and discover that your performance problems are caused by something using the 100Hz ticker to schedule its USB requests

Iyonix or Beagle are probably best for running fiqprof on, as using it on the Pi will force the Pi’s USB driver to fall back to using IRQs and may cause more issues. And sadly it won’t run on OMAP4 because we don’t have any FIQs :-(

Thanks Jeffrey.

I think I’ve found the problem.

The ticker thread you pointed out coincides with my findings. I had expected transmitting the next packet directly from the upcall handler not to work – as I had problems with doing that elsewhere. I had used callbacks from the upcall handler before but that didn’t work when I tried it with EtherUSB. However if I disable the transmitting of the packet from the upcall handler and rely on the prod mechanism (which is a timer event there as an insurance against the transfer stalling) to transmit packets then everything seems to work normally. With writes being about twice as long as read (16 – 32 secs for 15MB)

Hopefully a proper solution should speed up writes.

Thanks for your help.