New CPU profiling tool

For the past couple of days I’ve been playing around with some code I’ve written that uses a custom FIQ handler to sample the CPU state every time one of the HAL timers generates an interrupt. This has resulted in two tools – FIQProf and profanal – which can both be downloaded from my site here

A few notes:

• Currently only the Iyonix and OMAP3 are supported. There’s no support for the IOMD HAL (and I don’t even know if timers can be configured to generate FIQs on IOMD), and there’s no support for ROL’s branch of the OS (although there’s no reason it can’t be added if someone knows how to configure a spare timer to generate FIQs)
• The profanal tool, which is used to analyse the log files, should run on almost any RISC OS machine. Just be aware that it loads the entire log into the wimpslot, so it may not work on old machines if you create large logs.
• profanal uses the module list that was embedded in the log buffer to determine where the CPU was at each sample point. It’s also able to load GPA debug files as produced by Acorn/Castle/ROOL C/C++, so you can track down the exact file/function/line number.
• The current code is geared more towards profiling of module code than profiling of WIMP tasks – FIQProf currently has no way of determining the current WIMP task, so in the log output all WIMP tasks will appear as the same ‘module’.
• The code is in the public domain, so feel free to pull it apart and put it back together however you wish. I’m sure I’ll be gradually improving it over time as I use it to track down performance issues with the OMAP3 port, but if anyone has any other improvements they’ve made then feel free to send them my way.
• I’ll admit that I haven’t actually tested the current version on my Beagleboard! But as far as I know I haven’t done anything to break it since the last time I tried.

So far I’ve used it to determine that the long delay when starting the WIMP on the beagleboard is due to almost all the CPU time being spent flushing the caches due to dynamic areas being resized – which either means there’s a bug or some serious optimisation is needed! Hopefully we can also use this tool to help track down exactly what’s going on with the poor performance of USB mass storage.

who let you out of the basement? Get back down there and carry on with your coding. ;)

All well over my head unfortunately, but certainly sounds impressive – and more importantly very useful for the future.

There’s no support for the IOMD HAL (and I don’t even know if timers can be configured to generate FIQs on IOMD)

In IOMD, the assignment of each given interrupt as an IRQ or FIQ is fixed, so no you won’t be able to support IOMD with this scheme.

I suppose it might just be possible to abuse the floppy controller into generating a FIQ (after a timeout, say), though it probably wouldn’t be too accurate.

Otherwise, if you really want to do this, a little bit of podule hardware would be required. It probably only needs 1-3 chips if you design it carefully (and take liberties with the podule specification ;-)

I’ve now released a new version with fixed GPA handling, and added a page to my website where all future releases will be announced: http://www.phlamethrower.co.uk/riscos/fiqprof.php

For anyone taking notes, I’ve just released a new version, which supports the sampling of the IOP & Cortex-A8 performance counters. Admittedly I’m not sure just how useful this new feature will be, but at least it’s there now just in case.

It’s finally time for another new version. This fixes some (years-old) bugs and compatibility issues, allowing FIQProf to once again run correctly on current ROMs (assuming they support routing timer interrupts to FIQ – i.e. Iyonix, OMAP3 and iMx6. Pi also works in theory, but I believe it clashes with DWCDriver’s use of FIQs). profanal now also has a ‘hist’ command for plotting a histogram.

http://www.phlamethrower.co.uk/riscos/fiqprof.php

The next release is likely to remove support for the performance counters, since there’s now a better tool for those (I was thinking about removing them for this release, until I saw that I’d actually prepared this new FIQProf release back in February but had neglected to upload it)

Hopefully we can also use this tool to help track down exactly what’s going on with the poor performance of USB mass storage.

Out of interest, did anything come of that? And has it been used to uncover anything else?

Hopefully we can also use this tool to help track down exactly what’s going on with the poor performance of USB mass storage.

Out of interest, did anything come of that?

Yes. Using profanal to look at the timeline made it easy to spot that there were regular bursts of CPU activity followed by (relatively) long stretches of inactivity. Conclusion: we had poor performance because SCSISoftUSB was scheduling all the USB transfers using TickerV, and the transfers were too small to max out the bandwidth of USB2.

https://www.riscosopen.org/forum/forums/5/topics/253

And has it been used to uncover anything else?

Other things I can remember using it for:

• Investigating some network performance/stability issues: https://www.riscosopen.org/forum/forums/4/topics/10266 (lots of time is spent copying things in & out of MBufs)
• Profiling NBlood; the histogram feature made it easy to see where/why the audio was slow. I also used it a bit for the rendering code, but it’s not as useful for that kind of task. I should probably extend FIQProf to add support for custom metrics/events, so that it can be used to analyse (e.g.) how much time is spent rendering walls per frame, rather than how much time is spent rendering walls per second.
• I think I also tried using it to diagnose some audio CD playback stuttering on iMx6, but I can’t remember how useful it was

I also use profanal a lot just for it’s ability to do an addr2line lookup for ROM images (it can load the symbol files from a ROM build tree)

Thanks, those were interesting! Looks like the USB performance issues were fixed, and the network one is still open.