From d44e5ac935ec50ec48dd3f1599e5fbba39b3278a Mon Sep 17 00:00:00 2001 From: Brion Vibber Date: Mon, 29 Mar 2010 12:57:16 -0700 Subject: [PATCH] Add $config['db']['annotate_queries'] option to include caller ID comments into queries. Comment can then be seen in process list, slow query logs on the server, aiding in tracking down unexpected slow queries. SELECT /* queuedaemon.php Ostatus_profile->processPost */ * FROM notice WHERE ( notice.uri = 'http://stormcloud.local/mublog2/notice/479' ) INSERT /* POST Notice::saveNew */ INTO notice (profile_id , content .... --- classes/Memcached_DataObject.php | 68 ++++++++++++++++++++++++++++++++ lib/default.php | 1 + 2 files changed, 69 insertions(+) diff --git a/classes/Memcached_DataObject.php b/classes/Memcached_DataObject.php index bc4c3a000c..8d54e1f0f0 100644 --- a/classes/Memcached_DataObject.php +++ b/classes/Memcached_DataObject.php @@ -330,6 +330,10 @@ class Memcached_DataObject extends Safe_DataObject */ function _query($string) { + if (common_config('db', 'annotate_queries')) { + $string = $this->annotateQuery($string); + } + $start = microtime(true); $result = parent::_query($string); $delta = microtime(true) - $start; @@ -342,6 +346,70 @@ class Memcached_DataObject extends Safe_DataObject return $result; } + /** + * Find the first caller in the stack trace that's not a + * low-level database function and add a comment to the + * query string. This should then be visible in process lists + * and slow query logs, to help identify problem areas. + * + * Also marks whether this was a web GET/POST or which daemon + * was running it. + * + * @param string $string SQL query string + * @return string SQL query string, with a comment in it + */ + function annotateQuery($string) + { + $ignore = array('annotateQuery', + '_query', + 'query', + 'get', + 'insert', + 'delete', + 'update', + 'find'); + $ignoreStatic = array('staticGet', + 'pkeyGet', + 'cachedQuery'); + $here = get_class($this); // if we get confused + $bt = debug_backtrace(); + + // Find the first caller that's not us? + foreach ($bt as $frame) { + $func = $frame['function']; + if (isset($frame['type']) && $frame['type'] == '::') { + if (in_array($func, $ignoreStatic)) { + continue; + } + $here = $frame['class'] . '::' . $func; + break; + } else if (isset($frame['type']) && $frame['type'] == '->') { + if ($frame['object'] === $this && in_array($func, $ignore)) { + continue; + } + if (in_array($func, $ignoreStatic)) { + continue; // @fixme this shouldn't be needed? + } + $here = get_class($frame['object']) . '->' . $func; + break; + } + $here = $func; + break; + } + + if (php_sapi_name() == 'cli') { + $context = basename($_SERVER['PHP_SELF']); + } else { + $context = $_SERVER['REQUEST_METHOD']; + } + + // Slip the comment in after the first command, + // or DB_DataObject gets confused about handling inserts and such. + $parts = explode(' ', $string, 2); + $parts[0] .= " /* $context $here */"; + return implode(' ', $parts); + } + // Sanitize a query for logging // @fixme don't trim spaces in string literals function sanitizeQuery($string) diff --git a/lib/default.php b/lib/default.php index 10f3f1a97e..7b0d08e4ca 100644 --- a/lib/default.php +++ b/lib/default.php @@ -72,6 +72,7 @@ $default = 'quote_identifiers' => false, 'type' => 'mysql', 'schemacheck' => 'runtime', // 'runtime' or 'script' + 'annotate_queries' => false, // true to add caller comments to queries, eg /* POST Notice::saveNew */ 'log_queries' => false, // true to log all DB queries 'log_slow_queries' => 0), // if set, log queries taking over N seconds 'syslog' => -- 2.39.5