Реальные запросы в phalconphp

C самого первого дня использования phalconphp меня начал волновать вопрос: какие запросы реально приходят на выполнение в базу данных mysql от phalconphp.
Официальную документацию я прочел от корки до корки. В ней в разделе Logging Low-Level SQL Statements (название раздела звучит очень обнадеживающе) предлагается повесить обработчик на событие beforeQuery базы данных и из этого события записывать low-lewel запросы в лог. Дальше — больше: прямо сразу в следующем же разделе «Profiling SQL Statements» нам предлагают использовать профайлер, который запишет наш запрос в стек и засечет время начала выполнения запроса, в обработчике события afterQuery останавливаем профайл. И после формирования страницы пробегаемся по всем профайлам и записываем все в лог.
Как же велико было мое разочарование когда я увидел лог:

SELECT `users`.`id`, `users`.`email`, `users`.`name` FROM `users` WHERE `users`.`email` LIKE :email: LIMIT :2;
INSERT INTO `users` (`email`,`name`) VALUES (?, ?);

Какой же это б**ть low-lewel sql?? Прям lower больше уже некуда %)
Такое положение вещей меня не устраивает, поэтому пришлось придумывать решение. Спешу поделиться тем, что у меня получилось.
Все сервисы, кроме роутера для удобства я инициализирую в одном файле app/config/services.php

< ?php 
/**
 * @return \Phalcon\DI\FactoryDefault
 */
function getDi() {
  static $di = null;
  if (!$di) {
    $di = new \Phalcon\DI\FactoryDefault();
  }
  return $di;
}
getDi()->setShared('config', include __DIR__ . '/config.php');
getDi()->setShared('logger', function() {
  $logger = new \Phalcon\Logger\Adapter\File(__DIR__ . '/../logs/' . date('Y-m-d') . '.log');
  return $logger;
});
getDi()->setShared('profiler', '\Phalcon\Db\Profiler');
getDi()->setShared('db', function() {
  $db = new \Phalcon\Db\Adapter\Pdo\Mysql(array(
    "host"   => getDi()->getConfig()->database->host,
    "username" => getDi()->getConfig()->database->username,
    "password" => getDi()->getConfig()->database->password,
    "dbname"   => getDi()->getConfig()->database->dbname,
    "charset"  => getDi()->getConfig()->database->charset,
    "options"  => array(
      PDO::MYSQL_ATTR_INIT_COMMAND => 'SET NAMES' . getDi()->getConfig()->database->charset,
    )
  ));
  getDi()->getEventsManager()->attach('db', function($event, $db) {
    $sql = $db->getSQLStatement();
    // service questions for clarification of structure of a database disturb me
    // you can remove the following block to see all queries
    if (strpos($sql, 'DESCRIBE') === 0) {
      return true;
    }
    static $profileStarted = false;
    if ($event->getType() == 'beforeQuery') {
      // Just in case we will deny queries on change and cleaning of a database.
      if (preg_match('/(drop|alter|truncate) /i', $sql, $operation)) {
        throw new \Exception('Operation '.$operation[1].' was denied', 405);
      }
      if ($profileStarted) {
        getDi()->getProfiler()->stopProfile();
      }
      $vars = $db->getSQLVariables();
      $keys       = array();
      $values     = array();
      $myKeys     = array();
      $pregMyKeys = array();
      if ($vars) {
        foreach ($vars as $placeHolder=>$var) {
          // fill array of placeholders
          if (is_string($placeHolder)) {
            $keys[] = '/:'.ltrim($placeHolder, ':').'/';
          } else {
            $keys[] = '/[\?]/';
          }
          $myKeys[] = '::myKey'.(++$num).'::';
          $pregMyKeys[] = '/::myKey'.$num.'::/';
          // fill array of values
          // It makes sense to use RawValue only in INSERT and UPDATE queries and only as values
          // in all other cases it will be inserted as a quoted string
          if ((strpos($sql, 'INSERT') === 0 || strpos($sql, 'UPDATE') === 0) && $var instanceof \Phalcon\Db\RawValue) {
            $var = $var->getValue();
          } elseif (is_null($var)) {
            $var = 'NULL';
          } elseif (is_numeric($var)) {
            $var = $var;
          } else {
            $var = getDi()->getDb()->escapeString(mb_substr($var, 0, 500));
          }
          $values[] = $var;
        }
        $sql = preg_replace($keys, $myKeys, $sql, 1);
        $sql = preg_replace($pregMyKeys, $values, $sql, 1);
      }
      $sql = preg_replace('/ (WHERE|FROM|LEFT JOIN|SET|GROUP BY|HAVING|ORDER BY|LIMIT)/', PHP_EOL . str_repeat(' ', 8) . '$1', $sql);
      $sql = PHP_EOL . str_repeat(' ', 8) . $sql;
      $memoryUsage = round(memory_get_peak_usage(true)/1024/1024, 2).'MB';
      getDi()->getProfiler()->startProfile($memoryUsage.' '.$sql);
      $profileStarted = true;
    }
    if ($event->getType() == 'afterQuery') {
      getDi()->getProfiler()->stopProfile();
      $profileStarted = false;
    }
  });
  $db->setEventsManager(getDi()->getEventsManager());
  return $db;
});

Подключаем все необходимые сервисы, подключаем ивент-менеджер к базе данных и непосредственно перед запросом заменяем все плейсхолдеры на соответствующие им значения с учетом типов значений, после чего у нас есть тот запрос, что уходит на выполнение в базу данных.
Сначала попробовал заменять ключи сразу на значения, но, тогда, если значение — строка и в ней есть по-какой-то причине знаки вопросов, то замена происходит коряво, вместо замены последующих плейсхолдеров в искомом SQLStatement значения подставляются внутрь уже вставленной строки. Ничего лучше, чем сначала заменить исходные плейсхолдеры на свои, вида «::myKey{Num}::», а потом уже заменить эти плейсхолдеры на реальные зачения — на скорую руку не придумалось. Решение работает, поэтому дальше заморачиваться не стал. Если знаете решение изящнее — предложите, буду благодарен.

Ну и осталось теперь сохранить все профайлы в лог в bootstrap файле public/index.php

< ?php
try {
  if (!isset($_GET['_url']) || $_GET['_url'] == '/index.html') {
    $_GET['_url'] = '/';
    $_SERVER['REQUEST_URI'] = '/index.php?_url=/';
  }
  include __DIR__ . '/../app/config/services.php';
  $application = new \Phalcon\Mvc\Application();
  $application->setDI(getDi());
  getDi()->getProfiler()->startProfile($_SERVER['REQUEST_METHOD'].' '.$_SERVER['HTTP_HOST'].$_SERVER['REQUEST_URI']);
  getDi()->getProfiler()->stopProfile();
  echo $application->handle()->getContent();
} catch (Exception $e) {
  include 'error.php';
}
foreach (getDi()->getProfiler()->getProfiles() as $profile) {
  $time = sprintf('%01.4f', $profile->getTotalElapsedSeconds());
  getDi()->getLogger()->info($time.' sec: '.$profile->getSQLStatement());
}
$time = sprintf('%01.4f', getDi()->getProfiler()->getTotalElapsedSeconds());
getDi()->getLogger()->info($time.' sec: total' . PHP_EOL . PHP_EOL);

Сначала создаем профайл, котором запоминаем метод текущего запроса и запрошенный адрес и уже после формирования всей страницы пробегаем по всем итемам в профайлере и записываем в лог: время обработки каждого запроса, сам (настоящий low-lewel) запрос и потребляемую сайтом память на момент выполнения запроса.
Наконец-то теперь в логах именно те запросы, что приходят в базу данных. Их уже можно скопировать в phpmyadmin, поиграться с параметрами, проанализировать и при необзодимости внести правки в код. Надеюсь, что кому-то еще это решение будет полезным.

Добавить комментарий