Create your own MySQL query profiler in PHP






Do you know how many times your PHP scripts are calling the database or how long time the queries take to execute? Maybe it’s time to create your own query profiler? It’s simpler than you might think. There are several ways of doing it but we’ll look into one example here based upon a previous post where I showed how to add extra functionality to the mysqli connection by extending it.

The basic idea is that we start a timer just before the query is executed and stop it when the result is received. Then we store the result, together with the query and some data of where the query call was made from, in an array. We also add a function to display the data is a simple way. To simplify it all integrity checks have been removed from the code.

We start by defining the class to hold the timing results.

class queryLogItem
{
  public $callerData;	// Info about calling function
  public $sqlQuery; // SQL Query
  public $scriptStartTime; // Time when the whole script started
  private $queryStartTime; // Time when query started
  private $queryEndTime; // Time when query ended
	
  public function __construct($sqlQuery,$scriptStartTime,$callerData)
  {
    $this->scriptStartTime = $scriptStartTime;
    $this->sqlQuery = $sqlQuery;
    $this->callerData = $callerData;
    $this->queryStartTime = microtime(true); // Set start time
    $this->queryEndTime = microtime(true); // Default stop time
  }
  public function setComplete() // Call function when timer should stop
  {
    $this->queryEndTime = microtime(true);
  }
  public function startTime() // Time when query started during script execution
  {
    return round(($this->queryStartTime - $this->scriptStartTime),4);
  }
  public function timeLength() // Length of query
  {
    return round($this->queryEndTime - $this->queryStartTime,4);
  }
}

We also define the class we’ll use to store all the timings in as well as functions to initiate a new log item and to display result from the log list.

class queryLogList 
{
  private $queryLog;
  private $initialTime;
	
  function __construct() 
  {
    $this->initialTime = microtime(true); // Set script start time
    $this->queryLog = array();
  }
  function initiateNewLogItem($sql,$caller) // Initiate a log item
  {
    $item = new queryLogItem($sql,$this->initialTime,$caller);
    $this->queryLog[] = $item;
    return $item;
  }
  function getDbQueryLogAsHtml()  // Create a simple data table with data from the list
  {
    $num = 0;
    $data = "<table border=1><tr><td>Num</td><td>Time</td><td>Length</td><td>Caller</td><td>Query</td></tr>";
    foreach ($this->queryLog as $queryLogItem) 
    {
      if ($queryLogItem != null) 
      {
        $num++;
        $data .= "<td>$num</td><td>".$queryLogItem->startTime()."</td><td>".$queryLogItem->timeLength()."</td><td>".$queryLogItem->callerData."</td><td>".$queryLogItem->sqlQuery."</td></tr>";
      }
    }
    $data .= "</table>";
    return $data;
  }
}

Now to the extended mysqli class where the magic happens. Besides adding two new variables (doTimeQueries and queryLogList) the main things happen in the query function.

class extMysqli extends mysqli {
  private $host;
  private $user;
  private $pass;
  private $db;
  
  private $doTimeQueries = true;
  public $queryLogList;
  
  public function __construct($host, $user, $pass, $db, $doTimeQueries = false) {
    parent::init();
    $this->host = $host;
    $this->user = $user;
    $this->pass = $pass;
    $this->db = $db;
    $this->doTimeQueries = $doTimeQueries;
    $this->queryLogList = new queryLogList();
    
    if (!parent::options(MYSQLI_INIT_COMMAND, 'SET AUTOCOMMIT = 0')) {
      die('Setting MYSQLI_INIT_COMMAND failed');
    }

    if (!parent::options(MYSQLI_OPT_CONNECT_TIMEOUT, 5)) {
      die('Setting MYSQLI_OPT_CONNECT_TIMEOUT failed');
    }

    $this->intConnect();
  }
  function query($sql)
  {
    // Reconnect to server if needed
    if(!parent::ping()) {
      $this->intConnect();
    }

    // Initiate logging
    $queryLogItem;
    if ($this->doTimeQueries)
    {
      // Backtrace to get caller class, function and line number
      list(, $traceList) = debug_backtrace(false);
      $caller = $traceList["class"]."->".$traceList["function"]." (".$traceList["line"].")";
      $queryLogItem = $this->queryLogList->initiateNewLogItem($sql,$caller);
    }

    // Make the query
    $val = parent::query($sql);
    
    // Finish logging 
    if ($this->doTimeQueries)
      $queryLogItem->setComplete();

    return $val;
  }
  private function intConnect()
  {
    if (!parent::real_connect($this->host, $this->user, $this->pass, $this->db)) {
      die('Connect Error (' . mysqli_connect_errno() . ') ' . mysqli_connect_error());
    }
  }
}

So, to use all of this all we have to do is initiate the extended mysqli class and set $doTimeQueries = true. When all queries are made we call getDbQueryLogAsHtml() to print it on screen.

$db = new extMysqli('localhost','my_user','my_password','my_db');
// Do a lot of queries
// Print result on screen
echo $db->queryLogList->getDbQueryLogAsHtml();






The result when printing it will be a table with the following information:

  • A numerator
  • Start time relative to when script started
  • Execution time for the sql query
  • Class, function and line that called the query function
  • The SQL query