One way to troubleshoot a poor performing Moodle installation is to use the built-in “performance information” tool. It won’t always help to find the root cause but it’s often helpful in pointing you in the right direction for further investigation.
To enable it, login as an admin user to Site administration -> Development -> Debugging ( <moodle_url>/admin/settings.php?section=debugging ) and enable “perfdebug):
After doing it, login as a typical user (usually a student), and navigate to main entry point for the the user (eg. course view) and scroll to the bottom.
You should see extra performance information rendered:
If you don’t see it, then your theme may not be displaying it. As an admin, set “Allow theme changes in the URL” to “yes” under Site administration -> Appearance -> Themes -> Theme settings ( /admin/settings.php?section=themesettings ). Then open the URL again but append “theme=boost” to the URL. For example I would open course 86 and force theme switch by entering: https://moodle38.enovation.ie/course/view.php?id=86&theme=boost .
The most important values from the performance information are:
- In the top left corner “0.929473 secs” – this is the time it took to render the current page. It will be the same time as “ticks: ” in the third column. 100 “ticks” is 1 second. In the example above we see 0.929 sec and ticks: 93.
- “DB reads/writes” tells us how many database reads (ie SELECT) and writes (ie INSERT, UPDATE, DELETE) were issued during the request. Here we have “DB reads/writes: 230/1”.
- DB queries time: 0.07642 secs – this tells us that out of 0.93 second spent on rendering the page, 0.07 sec was spent handling 230 read + 1 write SQL queries.
- ticks: 93 user: 27 sys: 3 csuser: 0 csys: 0. Pay attention to the first 3 values (ticks = 93, user = 27 and sys = 3), csuser and csys will usually be 0s. Assume simply that 1 “tick” means 0.1 second.
ticks: 93 – tells us that it took 0.93 seconds between your web server started and finished the execution of the script we’ve checked (ie course.php).
user: 27 – means that the PHP script has used 0.27 seconds of the CPU running in the “user mode”.
sys: 3 – tells us it also used 0.03 seconds of CPU “system time”.
The difference between “user time” and “system time” is usually not that important for the investigation. Let’s sum those up: 0.27 + 0.03 = 0.30 (sec).
The above means that start-to-end it took our script 0.93 seconds to execute but out of those, the CPU spent only 0.30 seconds working for us.
What was going on during the remaining time of 0.93 – 0.30 = 0.63 seconds?
Time spent issuing DB queries is not taken into account for user and sys ticks, so we have “missing” 0.07 here. That sums up now to 0.30 + 0.07 = 0.37. We still have “missing” time of 0.93 – 0.37 = 0.56 seconds.
The performance information won’t give a direct answer about that missing time. Usually this time was spent on some kind of wait – for example:
- input / output
- network call
- locking
It is a good idea to provide this information when you’re looking for a help – for example on the Moodle performance forum.
