diff --git a/admin/settings/development.php b/admin/settings/development.php index 46206fcc8f80f..3844fe9a01f88 100644 --- a/admin/settings/development.php +++ b/admin/settings/development.php @@ -41,6 +41,13 @@ $temp->add(new admin_setting_configcheckbox('debugdisplay', new lang_string('debugdisplay', 'admin'), new lang_string('configdebugdisplay', 'admin'), ini_get_bool('display_errors'))); $temp->add(new admin_setting_configcheckbox('perfdebug', new lang_string('perfdebug', 'admin'), new lang_string('configperfdebug', 'admin'), '7', '15', '7')); $temp->add(new admin_setting_configcheckbox('debugstringids', new lang_string('debugstringids', 'admin'), new lang_string('debugstringids_desc', 'admin'), 0)); + $temp->add(new admin_setting_configselect('debugsqltrace', + new lang_string('debugsqltrace', 'admin'), + new lang_string('debugsqltrace_desc', 'admin'), 0, array( + 0 => new lang_string('disabled', 'admin'), + 1 => new lang_string('debugsqltrace1', 'admin'), + 2 => new lang_string('debugsqltrace2', 'admin'), + 100 => new lang_string('debugsqltrace100', 'admin')))); $temp->add(new admin_setting_configcheckbox('debugvalidators', new lang_string('debugvalidators', 'admin'), new lang_string('configdebugvalidators', 'admin'), 0)); $temp->add(new admin_setting_configcheckbox('debugpageinfo', new lang_string('debugpageinfo', 'admin'), new lang_string('configdebugpageinfo', 'admin'), 0)); $ADMIN->add('development', $temp); diff --git a/lang/en/admin.php b/lang/en/admin.php index 9ee6a8b830cc1..2571bcac5048b 100644 --- a/lang/en/admin.php +++ b/lang/en/admin.php @@ -462,6 +462,11 @@ $string['debugnone'] = 'NONE: Do not show any errors or warnings'; $string['debugnormal'] = 'NORMAL: Show errors, warnings and notices'; $string['debugpageinfo'] = 'Show page information'; +$string['debugsqltrace'] = 'Show origin of SQL calls'; +$string['debugsqltrace1'] = 'Show only a single calling line'; +$string['debugsqltrace2'] = 'Show 2 lines of stack trace'; +$string['debugsqltrace100'] = 'Show full stack trace'; +$string['debugsqltrace_desc'] = 'If enabled adds either partial or full PHP stacktrace into the SQL as a comment'; $string['debugstringids'] = 'Show origin of languages strings'; $string['debugstringids_desc'] = 'If enabled, language string components and identifiers are displayed when ?strings=1 or &strings=1 is appended to the page URL.'; $string['debugvalidators'] = 'Show validator links'; diff --git a/lib/dml/moodle_database.php b/lib/dml/moodle_database.php index db0a31c9bb6f9..c46ed82d1386c 100644 --- a/lib/dml/moodle_database.php +++ b/lib/dml/moodle_database.php @@ -889,6 +889,9 @@ public function fix_sql_params($sql, array $params=null) { // convert table names $sql = $this->fix_table_names($sql); + // Optionally add debug trace to sql as a comment. + $sql = $this->add_sql_debugging($sql); + // cast booleans to 1/0 int and detect forbidden objects foreach ($params as $key => $value) { $this->detect_objects($value); @@ -1030,6 +1033,50 @@ public function fix_sql_params($sql, array $params=null) { } } + /** + * Add an SQL comment to trace all sql calls back to the calling php code + * @param string $sql Original sql + * @return string Instrumented sql + */ + protected function add_sql_debugging(string $sql): string { + global $CFG; + + if (!property_exists($CFG, 'debugsqltrace')) { + return $sql; + } + + $level = $CFG->debugsqltrace; + + if (empty($level)) { + return $sql; + } + + $callers = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); + + // Ignore moodle_database internals. + $callers = array_filter($callers, function($caller) { + return empty($caller['class']) || $caller['class'] != 'moodle_database'; + }); + + $callers = array_slice($callers, 0, $level); + + $text = trim(format_backtrace($callers, true)); + + // Convert all linebreaks to SQL comments, optionally + // also eating any * formatting. + $text = preg_replace("/(^|\n)\*?\s*/", "\n-- ", $text); + + // Convert all ? to 'unknown' in the sql coment so these don't get + // caught by fix_sql_params(). + $text = str_replace('?', 'unknown', $text); + + // Convert tokens like :test to ::test for the same reason. + $text = preg_replace('/(?assertSame(array_values($params), array_values($inparams)); } + /** + * Test the database debugging as SQL comment. + */ + public function test_add_sql_debugging() { + global $CFG; + $DB = $this->tdb; + + require_once($CFG->dirroot . '/lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php'); + $fixture = new test_dml_sql_debugging_fixture($this); + + $sql = "SELECT * FROM {users}"; + + $out = $fixture->four($sql); + + $CFG->debugsqltrace = 0; + $this->assertEquals("SELECT * FROM {users}", $out); + + $CFG->debugsqltrace = 1; + $out = $fixture->four($sql); + $expected = <<invoke() +EOD; + $this->assertEquals($expected, $out); + + $CFG->debugsqltrace = 2; + $out = $fixture->four($sql); + $expected = <<invoke() +-- line 74 of /lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php: call to test_dml_sql_debugging_fixture->one() +EOD; + $this->assertEquals($expected, $out); + + $CFG->debugsqltrace = 5; + $out = $fixture->four($sql); + $expected = <<invoke() +-- line 74 of /lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php: call to test_dml_sql_debugging_fixture->one() +-- line 83 of /lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php: call to test_dml_sql_debugging_fixture->two() +-- line 92 of /lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php: call to test_dml_sql_debugging_fixture->three() +-- line 476 of /lib/dml/tests/dml_test.php: call to test_dml_sql_debugging_fixture->four() +EOD; + $this->assertEquals($expected, $out); + + $CFG->debugsqltrace = 0; + } + public function test_strtok() { // Strtok was previously used by bound emulation, make sure it is not used any more. $DB = $this->tdb; diff --git a/lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php b/lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php new file mode 100644 index 0000000000000..2aba9dead4c7e --- /dev/null +++ b/lib/dml/tests/fixtures/test_dml_sql_debugging_fixture.php @@ -0,0 +1,95 @@ +. + +/** + * Test SQL debugging fixture + * + * @package core + * @category dml + * @copyright 2020 Brendan Heywood + * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later + */ + +defined('MOODLE_INTERNAL') || die(); + +/** + * Test SQL debugging fixture + * + * @package core + * @category dml + * @copyright 2020 Brendan Heywood + * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later + */ +class test_dml_sql_debugging_fixture { + /** @var db handle */ + private $db; + + /** + * constructor + * @param testcase $testcase test object + */ + public function __construct($testcase) { + $this->db = $testcase->getMockBuilder(\moodle_database::class) + ->getMockForAbstractClass(); + } + + /** + * Get db handle + * @return a db handle + */ + public function get_mock() { + return $this->db; + } + + /** + * Test caller in stacktrace + * @param string $sql original sql + * @return string sql with comments + */ + public function one(string $sql) { + $method = new \ReflectionMethod($this->db, 'add_sql_debugging'); + $method->setAccessible(true); + return $method->invoke($this->db, $sql); + } + + /** + * Test caller in stacktrace + * @param string $sql original sql + * @return string sql with comments + */ + public function two(string $sql) { + return $this->one($sql); + } + + /** + * Test caller in stacktrace + * @param string $sql original sql + * @return string sql with comments + */ + public function three(string $sql) { + return $this->two($sql); + } + + /** + * Test caller in stacktrace + * @param string $sql original sql + * @return string sql with comments + */ + public function four(string $sql) { + return $this->three($sql); + } + +}