Logging all database queries

Ever find yourself in a situation where CakePHP executes a handful of database queries but the controller immediately redirects you, effectively throwing away the log of everything that happened during that request? What about trying to see "behind the scenes" of an AJAX request? Well, here's a little tidbit to help sneak a peak under the hood..

First off, yes, I am aware of things like FirePHP and how to use it within CakePHP and... well... I don't like Firefox. There. I said it. I'm quite at home with my Chrome browser, thank you very much. Now, hopefully before a full-on browser war starts, here's a solution to log all queries to the database into something a bit more universal, a log file.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45

<?php/** * Called after the controller action is run, but before the view is rendered. * * @return void * @access public */public function beforeRender() { if (Configure::read()) { foreach (ConnectionManager::sourceList() as $datasource) { $this->_logDataSourceQueries( ConnectionManager::getDataSource($datasource) ); } } parent::beforeRender();}/** * Logs the queries from a `DataSource` object. The optional `$log` * parameter denotes where to send the logs. * * @param DataSource $datasource * @param string $log * @return void * @access protected */protected function _logDataSourceQueries(DataSource $datasource, $log = 'sql') { if ($datasource->isInterfaceSupported('getLog')) { $queries = $datasource->getLog(false, false); foreach ($queries['log'] as $query) { CakeLog::write($log, sprintf( '%3s %3s %3s %s', $query['affected'], $query['numRows'], $query['took'], $query['query'] )); if (!empty($query['error'])) { CakeLog::write('sql', $query['error']); } } }}

You'll notice that inside the beforeRender we're checking to make sure we're in debug mode. By default none of the DataSource objects will log any queries if we're not debugging. From there it loops over all available DataSource objects and kicks them out to our _logDataSourceQueries method.
From there it's a pretty simple hop, skip and a jump to logging with CakeLog. We make sure the DataSource supports logging before grabbing out all of the queries and sprintfing them out to our log.
If you're feeling fancy you can mix-up the display of the queries, here's some ideas I'm too lazy to implement.

  • Adding warnings when a query exceeds a time threshold.
  • Organizing the queries by model.
  • Creating a summary of all queries. 
  • Logging the time took by controller, action for observation.

Permalink

| Leave a comment  »