I have accidently discovered that some Moodle code is written with little consideration for the amount of database traffic it generates.
While some/most php files fetch isadmin() into a local variable if they need it multiple times, for example, moodle/course/scales.php calls isadmin() 6 times. The main moodle/index.html has 3 calls to isadmin(), 2 of them in the same if. forum/index.html and forum/post.php each has 2 calls. But user/edit.php is a record-holer with 9 calls.
I suspect that other functions of this sort are similarly misused. It woud be great if all authors reviewed their code while fixing things for 1.6 and address such obvious inefficiencies.
just so you know, isadmin does actually keep a cache of admins vs non admins in arrays so 6 calls to isadmin within the same page won't ask the database each time.
Exactly. 
Robert, a lot of Moodle functions cache themselves using static variables this way - it works well. We do it that way for readability.
Robert, a lot of Moodle functions cache themselves using static variables this way - it works well. We do it that way for readability.
I should have known better or at least checked it out all the way through. 
I'm error_log():ing all of the SQL queries to a text file (on a test site) for analysis, and it would seem that many pages call SELECT * FROM mdl_config multiple times, despite it being a Moodle global?
For example my test course front page calls that query five times. MySQL and PostgreSQL might both have query caching to make this less a problem, but this is something to keep an eye on.
Disclaimer: We have some customisations (this is 1.5.3+), and I didn't check this on a vanilla Moodle 1.6 dev yet!, but FYI: My test course has around 50 or so modules and resources. Viewing the course front page in a non-edit mode generates one insert (log) and 75 selects. Of these there are several multiples, like:
SELECT * FROM mdl_config (x5)
SELECT * FROM mdl_course WHERE category = '0' LIMIT 1 (x5)
SELECT * FROM mdl_course WHERE id = '2' LIMIT 1 (x9)
SELECT * FROM mdl_user WHERE id = '1' AND username = 'guest' LIMIT 1 (x2)
SELECT DISTINCT g.* FROM mdl_groups g WHERE g.courseid = '2' (x2)
SELECT id, groupmode, groupmodeforce FROM mdl_course WHERE id IN ( 2) (x2)
Next stop: I have to check that our customisations are not responsible, and/or if this is the case with 1.6dev too.
I'm logging the queries from the adodb driver sql with the following in _query():
$one_row_sql = preg_replace("/\n/", "", $sql);
$one_row_sql = preg_replace("/\s\s+/", " ", $sql);
$one_row_sql = "\"" . trim($one_row_sql) . "\"\n";
error_log($one_row_sql, 3, "d:/root/moodle/sql_queries.txt");
It's trying to make the queries to be on a single line, no excess whitespace, wrapped in quotes for easier CSV handling.
For example my test course front page calls that query five times. MySQL and PostgreSQL might both have query caching to make this less a problem, but this is something to keep an eye on.
Disclaimer: We have some customisations (this is 1.5.3+), and I didn't check this on a vanilla Moodle 1.6 dev yet!, but FYI: My test course has around 50 or so modules and resources. Viewing the course front page in a non-edit mode generates one insert (log) and 75 selects. Of these there are several multiples, like:
SELECT * FROM mdl_config (x5)
SELECT * FROM mdl_course WHERE category = '0' LIMIT 1 (x5)
SELECT * FROM mdl_course WHERE id = '2' LIMIT 1 (x9)
SELECT * FROM mdl_user WHERE id = '1' AND username = 'guest' LIMIT 1 (x2)
SELECT DISTINCT g.* FROM mdl_groups g WHERE g.courseid = '2' (x2)
SELECT id, groupmode, groupmodeforce FROM mdl_course WHERE id IN ( 2) (x2)
Next stop: I have to check that our customisations are not responsible, and/or if this is the case with 1.6dev too.
| SELECT * FROM
mdl_config |
$one_row_sql = preg_replace("/\n/", "", $sql);
$one_row_sql = preg_replace("/\s\s+/", " ", $sql);
$one_row_sql = "\"" . trim($one_row_sql) . "\"\n";
error_log($one_row_sql, 3, "d:/root/moodle/sql_queries.txt");
It's trying to make the queries to be on a single line, no excess whitespace, wrapped in quotes for easier CSV handling.
Something is wrong there. All the config variables should be loaded exactly once in lib/setup.php. I just checked this on a 1.6 dev front page and indeed that's the case.
An accurate way to check is to add this line about line 165 of lib/setup.php:
$db->debug = true;
On this topic, though, I just today discovered that the timezone lookups weren't being cached properly, so that's one more optimisation. I'm sure there are plenty more to be found.
An accurate way to check is to add this line about line 165 of lib/setup.php:
$db->debug = true;
On this topic, though, I just today discovered that the timezone lookups weren't being cached properly, so that's one more optimisation. I'm sure there are plenty more to be found.
I see... Investigating a bit more...
About the $db->debug: is there a "Moodle way" to redirect these to a file, instead of the browser? I notice that it triggers adodb outp() which can take a custom handler via define "ADODB_OUT", but Moodle doesn't have that anywhere?
About the $db->debug: is there a "Moodle way" to redirect these to a file, instead of the browser? I notice that it triggers adodb outp() which can take a custom handler via define "ADODB_OUT", but Moodle doesn't have that anywhere?
No, not really.
It depends on why you're logging them. For debugging/optimising, in the page is more useful.
For performance and detecting slow queries, try this in config.php:
$CFG->logsql = true;
then visit http://yoursite/admin/dbperformance.php
You'll also find all those queries in the local table called adodb_logsql, which you could dump I suppose.
It depends on why you're logging them. For debugging/optimising, in the page is more useful.
For performance and detecting slow queries, try this in config.php:
$CFG->logsql = true;
then visit http://yoursite/admin/dbperformance.php
You'll also find all those queries in the local table called adodb_logsql, which you could dump I suppose.
I'm logging the queries to get a profile of what kind of queries are the most popular, by what ratio etc. Also to keep an eye on those "SELECT *"s and so on. I have to play around with the "logsql" still, I'm not familiar with what it produces. Initially I couldn't get it (moodle/adodb) to log anything, but it's just an option I'm missing somewhere...
There is something very odd
going on in somewhere, I'm disconnecting from reality with this one:
I put these two lines in the very beginning of get_config() in moodlelib.php:
print("-- GET CONFIG plugin:$plugin name:$name --<br />");
error_log("-- GET CONFIG plugin:$plugin name:$name --\n", 3, "d:/root/moodle15/sql_queries.txt");
The string is only once on the screen, but four times in the error_log file. What's up with that? Whatever it is, it's most likely the same thing that causes my logs to have multiples that the $db->debug doesn't show.
There is something very odd
going on in somewhere, I'm disconnecting from reality with this one:I put these two lines in the very beginning of get_config() in moodlelib.php:
print("-- GET CONFIG plugin:$plugin name:$name --<br />");
error_log("-- GET CONFIG plugin:$plugin name:$name --\n", 3, "d:/root/moodle15/sql_queries.txt");
The string is only once on the screen, but four times in the error_log file. What's up with that? Whatever it is, it's most likely the same thing that causes my logs to have multiples that the $db->debug doesn't show.
This was driving me nuts, but after capturing debug_backtrace() info and writing that to the error_log file, I got it (should have been obvious!): the extra queries per one (perceived) page load are generated by:
<link rel="stylesheet" type="text/css" href="http://moodle.org/theme/standard/styles.php?lang=en" />
<link rel="stylesheet" type="text/css" href="http://moodle.org/theme/moodleorange/styles.php?lang=en" />
<script language="JavaScript" type="text/javascript" src="http://moodle.org/lib/javascript-mod.php"></script>
Furthermore, got the adodb_logsql to work, but it doesn't seem to log all of the Moodle queries. The "select * from config" doesn't show up at all, so I'm sticking to my "log _everything_" as those queries generated by the included files are not seen by the browser.
<link rel="stylesheet" type="text/css" href="http://moodle.org/theme/standard/styles.php?lang=en" />
<link rel="stylesheet" type="text/css" href="http://moodle.org/theme/moodleorange/styles.php?lang=en" />
<script language="JavaScript" type="text/javascript" src="http://moodle.org/lib/javascript-mod.php"></script>
Furthermore, got the adodb_logsql to work, but it doesn't seem to log all of the Moodle queries. The "select * from config" doesn't show up at all, so I'm sticking to my "log _everything_" as those queries generated by the included files are not seen by the browser.