18 Oct 2019 - Richard Horridge
I write this while waiting for my work PC to finish its job.
From my supervisor I have inherited a MATLAB codebase and, for the past few days, I have been refactoring, debugging and testing the code.
I've done several things:
[ERRO]logging levels to all printed statements
- Documented every function and script I encounter using MATLAB's slightly janky documentation framework
- Using and extending a library I wrote, added debugging statements, assertions and timers.
These timers are the subject of the remainer of the blog post. The function code is fairly simple:
function [time] = debug_timer (start_time) %% DEBUG_TIMER Start and stop a timer for debugging % TIME = DEBUG_TIMER() called with no arguments % starts a new timer and returns the TIME at % which it was started. % % TIME = DEBUG_TIMER(START_TIME) stops the timer % started at START_TIME and returns the elapsed % TIME in seconds. % % See also: tic, toc [~, ws] = dbstack (); str(1:ws) = ' '; if exist ('start_time', 'var') time = toc (start_time); msg = sprintf ('[DEBG]%sTimer stopped : %.4f s.', str, time); else time = tic (); msg = sprintf ('[DEBG]%sTimer started.', str); end disp (msg); end
The main interesting thing here is the use of the
WS variable -
the index number of the workspace we are currently in. This allows
nested function calls to be timed both internally and externally -
the debug message is indenting an increasing amount for an
increasing stack depth.
Otherwise, when called with no arguments a timer is started, and when called with a previous time argument the timer is stopped and the result both printed and returned from the function.
some time later…
The program has finally stopped!
|OS||CPU||Memory / GiB||Time / s|
Comparison of the algorithm runtime on my work machine (Windows) and laptop (GNU/Linux)
The algorithm, which is noted to be slow, took just under 18 seconds on my Gentoo machine but almost 700 seconds on Windows (more than 11 minutes!), a 3800% increase!
While it was running I did some rudimentary profiling. On Gentoo, the CPU usage was going over 400% with over 12 GiB of memory allocated. My machine is a Dell Precision M4800, which is a powerful workstation laptop, so it is on the high end of what is available.
On Windows, however, it appears that only a single CPU core is being utilised. CPU usage drifts from around 30% usually up to 100%, with only around 3.4 GB of memory being used.
Two things are notable here - first, on GNU/Linux, the same code is being parallelised when it isn't on Windows, and second, MATLAB is not being allocated anywhere near as high a proportion of memory on Windows as on GNU/Linux. I suspect that both of these may be the operating system, not MATLAB - the first due to Windows being a poor environment for scientific computing, and the second due to the high overhead of Windows itself, which does not even seem to show up in Task Manager!
I was expecting my Gentoo machine to run faster but even I am surprised by how much it has improved! I was planning on explicitly vectorising and parallelising the MATLAB code as much as possible, after profiling the troublesome sections, but the main barrier is, as always, an operating system that is seriously unfit for purpose.