Visvanath Ratnaweera

I'm looking for the course of a sudden sharp rise in the load, ramping up many readings like number of threads, load average, interrupts vertically, It was during a busy morning with many tests and exams going on. But they are divided in to small classes, 10 to 20 students each, so the overall distribution is fairly even. Although one could argue that they all coincided in a time slot of a couple of minutes duration, I looked at the DB site and discovered that a massive slow query must have been run at this minute, blocking many things. Unfortunately slow query logging wasn't active. Now waiting for it to happen again I came across this SQL just now.

# Time: 251210  8:10:09
# User@Host: ...
# Thread_id: 379190  Schema: ...  QC_hit: No
# Query_time: 22.107945  Lock_time: 0.000235  Rows_sent: 1095  Rows_examined: 7283449
# Rows_affected: 0  Bytes_sent: 76333
use `....`;
SET timestamp=1765350609;
SELECT result.contextid, SUM(numquestions) AS numquestions, SUM(numhidden) AS numhidden, con.id AS ctxid, con.path AS ctxpath, con.depth AS ctxdepth, con.contextlevel AS ctxlevel, con.instanceid AS ctxinstance, con.locked AS ctxlocked
              FROM (SELECT data.contextid, data.versionid, COUNT(data.numquestions) AS numquestions,
                           (SELECT COUNT(qv.id)
                              FROM mdl_question_versions qv
                             WHERE qv.id = data.versionid
                                   AND qv.status = 'hidden') AS numhidden
                      FROM (SELECT qv.id as versionid, qc.contextid, 1 AS numquestions
                              FROM mdl_question q
                              JOIN mdl_question_versions qv ON qv.questionid = q.id
                              JOIN mdl_question_bank_entries qbe ON qbe.id = qv.questionbankentryid
                              JOIN mdl_question_categories qc ON qc.id = qbe.questioncategoryid
                              JOIN mdl_context con ON con.id = qc.contextid
                              
                                   AND qv.version = (SELECT MAX(v.version)
                                                       FROM mdl_question_versions v
                                                       JOIN mdl_question_bank_entries be
                                                         ON be.id = v.questionbankentryid
                                                      WHERE be.id = qbe.id)
                                   AND (q.parent = 0 OR q.parent = q.id)) data
                  GROUP BY data.contextid, data.versionid) result
              JOIN mdl_context con ON con.id = result.contextid
          GROUP BY result.contextid, con.id,con.path,con.depth,con.contextlevel,con.instanceid,con.locked
          ORDER BY numquestions DESC, numhidden ASC, con.contextlevel ASC, con.id ASC;

 Does anybody know the place where this SQL is generated?

Moodle 4.5 (4.5.7 till yesterday, 4.5.8 since today)

P.S. This Moodle instance has a history, e.g. What is the state of the duplicating questions in Moodle 4.5 LTS? and many more. Those details are still being discussed in the corresponding threads. This topic is about collecting slow queries and, hopefully, identifying their causes.

I'm in the process of catching a spurious slow query coming from the quiz corner. During that exercise came across these slow queries - if anybody is looking for a challenge (the same is attached as a file):

# Thread_id: 262574  Schema: xxxmoodle  QC_hit: No
# Query_time: 15.934880  Lock_time: 0.000214  Rows_sent: 1  Rows_examined: 5467487
# Rows_affected: 0  Bytes_sent: 68
SET timestamp=1765288201;
SELECT COUNT(1)
              FROM (SELECT GROUP_CONCAT(CONCAT(COALESCE(rbalias1.contextid, '<^>'), '<|>', COALESCE(rbalias2.id, '<^>'), '<|>', COALESCE(rbalias2.path, '<^>'), '<|>', COALESCE(rbalias2.depth, '<^>'), '<|>', COALESCE(rbalias2.contextlevel, '<^>'), '<|>', COALESCE(rbalias2.instanceid, '<^>'), '<|>', COALESCE(rbalias2.locked, '<^>')) ORDER BY CONCAT(COALESCE(rbalias1.contextid, '<^>'), '<|>', COALESCE(rbalias2.id, '<^>'), '<|>', COALESCE(rbalias2.path, '<^>'), '<|>', COALESCE(rbalias2.depth, '<^>'), '<|>', COALESCE(rbalias2.contextlevel, '<^>'), '<|>', COALESCE(rbalias2.instanceid, '<^>'), '<|>', COALESCE(rbalias2.locked, '<^>')) SEPARATOR '<,>') AS c0_contextid, rbalias4.firstname AS c1_firstname, rbalias4.lastname AS c1_lastname, rbalias1.filename AS c2_filename, rbalias1.mimetype AS c3_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c3_directory, rbalias1.filesize AS c4_filesize, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c4_directory, rbalias1.timecreated AS c5_timecreated, rbalias1.contextid AS c6_contextid, rbalias2.id AS c6_ctxid, rbalias2.path AS c6_ctxpath, rbalias2.depth AS c6_ctxdepth, rbalias2.contextlevel AS c6_ctxlevel, rbalias2.instanceid AS c6_ctxinstance, rbalias2.locked AS c6_ctxlocked, rbalias1.filename AS c7_filename, rbalias1.filename AS c8_filename, GROUP_CONCAT(DISTINCT rbalias1.filearea ORDER BY rbalias1.filearea SEPARATOR '<,>') AS c9_filearea, rbalias1.mimetype AS c10_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c10_directory
                      FROM mdl_files rbalias1 LEFT JOIN mdl_context rbalias2 ON rbalias2.id = rbalias1.contextid LEFT JOIN mdl_user rbalias4 ON rbalias4.id = rbalias1.userid
                     WHERE (CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END = '0') AND ( CAST((rbalias1.filesize) AS DECIMAL(65,7))  > 450)
                           GROUP BY c1_firstname, c1_lastname, c2_filename, c3_mimetype, c3_directory, c4_filesize, c4_directory, c5_timecreated, c6_contextid, c6_ctxid, c6_ctxpath, c6_ctxdepth, c6_ctxlevel, c6_ctxinstance, c6_ctxlocked, c7_filename, c8_filename, c10_mimetype, c10_directory
                   ) rbalias12;
 
# Thread_id: 262574  Schema: xxxmoodle  QC_hit: No
# Query_time: 25.699224  Lock_time: 0.000267  Rows_sent: 737373  Rows_examined: 6204860
# Rows_affected: 0  Bytes_sent: 234602233
SET timestamp=1765288217;
SELECT GROUP_CONCAT(CONCAT(COALESCE(rbalias1.contextid, '<^>'), '<|>', COALESCE(rbalias2.id, '<^>'), '<|>', COALESCE(rbalias2.path, '<^>'), '<|>', COALESCE(rbalias2.depth, '<^>'), '<|>', COALESCE(rbalias2.contextlevel, '<^>'), '<|>', COALESCE(rbalias2.instanceid, '<^>'), '<|>', COALESCE(rbalias2.locked, '<^>')) ORDER BY CONCAT(COALESCE(rbalias1.contextid, '<^>'), '<|>', COALESCE(rbalias2.id, '<^>'), '<|>', COALESCE(rbalias2.path, '<^>'), '<|>', COALESCE(rbalias2.depth, '<^>'), '<|>', COALESCE(rbalias2.contextlevel, '<^>'), '<|>', COALESCE(rbalias2.instanceid, '<^>'), '<|>', COALESCE(rbalias2.locked, '<^>')) SEPARATOR '<,>') AS c0_contextid, rbalias4.firstname AS c1_firstname, rbalias4.lastname AS c1_lastname, rbalias1.filename AS c2_filename, rbalias1.mimetype AS c3_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c3_directory, rbalias1.filesize AS c4_filesize, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c4_directory, rbalias1.timecreated AS c5_timecreated, rbalias1.contextid AS c6_contextid, rbalias2.id AS c6_ctxid, rbalias2.path AS c6_ctxpath, rbalias2.depth AS c6_ctxdepth, rbalias2.contextlevel AS c6_ctxlevel, rbalias2.instanceid AS c6_ctxinstance, rbalias2.locked AS c6_ctxlocked, rbalias1.filename AS c7_filename, rbalias1.filename AS c8_filename, GROUP_CONCAT(DISTINCT rbalias1.filearea ORDER BY rbalias1.filearea SEPARATOR '<,>') AS c9_filearea, rbalias1.mimetype AS c10_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c10_directory FROM mdl_files rbalias1 LEFT JOIN mdl_context rbalias2 ON rbalias2.id = rbalias1.contextid LEFT JOIN mdl_user rbalias4 ON rbalias4.id = rbalias1.userid WHERE (CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END = '0') AND ( CAST((rbalias1.filesize) AS DECIMAL(65,7))  > 450) GROUP BY c1_firstname, c1_lastname, c2_filename, c3_mimetype, c3_directory, c4_filesize, c4_directory, c5_timecreated, c6_contextid, c6_ctxid, c6_ctxpath, c6_ctxdepth, c6_ctxlevel, c6_ctxinstance, c6_ctxlocked, c7_filename, c8_filename, c10_mimetype, c10_directory ORDER BY c4_filesize DESC, c0_contextid ASC, c9_filearea ASC;

# Thread_id: 313994  Schema: xxxmoodle  QC_hit: No
# Query_time: 19.593351  Lock_time: 0.000143  Rows_sent: 1  Rows_examined: 5407935
# Rows_affected: 0  Bytes_sent: 68
SET timestamp=1765303141;
SELECT COUNT(1)
              FROM (SELECT rbalias1.contextid AS c0_contextid, rbalias2.id AS c0_ctxid, rbalias2.path AS c0_ctxpath, rbalias2.depth AS c0_ctxdepth, rbalias2.contextlevel AS c0_ctxlevel, rbalias2.instanceid AS c0_ctxinstance, rbalias2.locked AS c0_ctxlocked, rbalias4.firstname AS c1_firstname, rbalias4.lastname AS c1_lastname, rbalias1.filename AS c2_filename, rbalias1.mimetype AS c3_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c3_directory, rbalias1.filesize AS c4_filesize, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c4_directory, rbalias1.timecreated AS c5_timecreated, rbalias1.contextid AS c6_contextid, rbalias2.id AS c6_ctxid, rbalias2.path AS c6_ctxpath, rbalias2.depth AS c6_ctxdepth, rbalias2.contextlevel AS c6_ctxlevel, rbalias2.instanceid AS c6_ctxinstance, rbalias2.locked AS c6_ctxlocked, rbalias1.filearea AS c7_filearea, rbalias1.filearea AS c8_filearea
                      FROM mdl_files rbalias1 LEFT JOIN mdl_context rbalias2 ON rbalias2.id = rbalias1.contextid LEFT JOIN mdl_user rbalias4 ON rbalias4.id = rbalias1.userid
                     WHERE (CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END = '0')
                           GROUP BY c0_contextid, c0_ctxid, c0_ctxpath, c0_ctxdepth, c0_ctxlevel, c0_ctxinstance, c0_ctxlocked, c1_firstname, c1_lastname, c2_filename, c3_mimetype, c3_directory, c4_filesize, c4_directory, c5_timecreated, c6_contextid, c6_ctxid, c6_ctxpath, c6_ctxdepth, c6_ctxlevel, c6_ctxinstance, c6_ctxlocked, c7_filearea, c8_filearea
                   ) rbalias12;

# Thread_id: 313994  Schema: xxxmoodle  QC_hit: No
# Query_time: 15.618496  Lock_time: 0.000193  Rows_sent: 835487  Rows_examined: 4572448
# Rows_affected: 0  Bytes_sent: 187009519
SET timestamp=1765303161;
SELECT rbalias1.contextid AS c0_contextid, rbalias2.id AS c0_ctxid, rbalias2.path AS c0_ctxpath, rbalias2.depth AS c0_ctxdepth, rbalias2.contextlevel AS c0_ctxlevel, rbalias2.instanceid AS c0_ctxinstance, rbalias2.locked AS c0_ctxlocked, rbalias4.firstname AS c1_firstname, rbalias4.lastname AS c1_lastname, rbalias1.filename AS c2_filename, rbalias1.mimetype AS c3_mimetype, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c3_directory, rbalias1.filesize AS c4_filesize, CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END AS c4_directory, rbalias1.timecreated AS c5_timecreated, rbalias1.contextid AS c6_contextid, rbalias2.id AS c6_ctxid, rbalias2.path AS c6_ctxpath, rbalias2.depth AS c6_ctxdepth, rbalias2.contextlevel AS c6_ctxlevel, rbalias2.instanceid AS c6_ctxinstance, rbalias2.locked AS c6_ctxlocked, rbalias1.filearea AS c7_filearea, rbalias1.filearea AS c8_filearea FROM mdl_files rbalias1 LEFT JOIN mdl_context rbalias2 ON rbalias2.id = rbalias1.contextid LEFT JOIN mdl_user rbalias4 ON rbalias4.id = rbalias1.userid WHERE (CASE WHEN rbalias1.filename = '.' THEN 1 ELSE 0 END = '0') GROUP BY c0_contextid, c0_ctxid, c0_ctxpath, c0_ctxdepth, c0_ctxlevel, c0_ctxinstance, c0_ctxlocked, c1_firstname, c1_lastname, c2_filename, c3_mimetype, c3_directory, c4_filesize, c4_directory, c5_timecreated, c6_contextid, c6_ctxid, c6_ctxpath, c6_ctxdepth, c6_ctxlevel, c6_ctxinstance, c6_ctxlocked, c7_filearea, c8_filearea ORDER BY c4_filesize DESC;

Pl. note that the slow query limit is lowered to 1 sec. but for the whole working day these are the only slow queries.