Debug outputs

Sometimes, the simplest thing we can do is just to add some printfs reporting times spend in critical parts of the code as debug outputs (that is, they will disappear in your Release build). This is the simplest form of manual instrumentation we can have—no sophisticated output formats; just simple human-readable log lines.

We can use it in two ways: first, when investigating some incumbent performance problem, and, second, for an overview of the general timing of our application when it is evolving. 

Qt can support us in that endeavor because it provides a C++ class that can be used to measure short-time intervals—the QElapsedTimer class. We can use it like this:

QElapsedTimer timer;
timer.start();
// work, work ... 
qDebug() << QString("work-work took %1 msecs").arg(timer.elapsed());

When working with QML, we can use the console's support for time measurements in our JavaScript code, for example:

console.timeStart("moreWork");
// more JS work ...
console.timeEnd("moreWork");

This would print the following line to the JavaScript console:

moreWork: XXX ms

XXX stands for the measured time. You can also nest time measurements, as in the following example:

console.timeStart("totalWork");
console.timeStart("firstPart");
// JS work ...
console.timeEnd("firstPart");
// even more JS work ...
console.timeEnd("totalWork");