Kohana & firePHP: nginx выдаёт 502 при включённом debugToolbar

Те, кто следит за количеством запросов, потребляемой памяти, временем выполнения и другими важными показателями при использовании debugToolbar также наверняка используют firePHP – плагин к плагину fireBug для Firefox позволяющий дебажить работу своего веб-приложения.

По понятным причинам, на сайте после apache поставлен nginx. Наверное кто нибудь пытался сделать дамп большого объекта или массива и запихать его в firePHP. PHP скрипт отрабатывает удачно, в логах также всё нормально(код 200):

123.123.123.123 - - [31/Jan/2010:15:08:44 +0300] "GET /somepage/o.O HTTP/1.0" 200 66939 "-" "Mozilla/5.0 (X11; U; Linux x86_64; ru; rv:1.9.1.6) Gecko/20091216 Iceweasel/3.5.6 (like Firefox/3.5.6; Debian-3.5.6-1) FirePHP/0.4"

А вот nginx в браузер выдаёт

502 Bad Gateway

nginx

Так и в моём случае: всё работало нормально, казалось бы изменил совсем чуть-чуть: добавил ещё один вызов метода у модели. И на тебе – 502 Bad Gateway.

Что я только не пробовал. Дело в том, что у меня вызывался один и тот же метод дважды с разными аргументами, что приводило к 502 странице. 1 вызов $episode->getAll() работал нормально.
Код выглядил так:

$episode = new Episode_Model();
$opts = array();
$frames = array();

$opts['count'] = $this->tubeConfig->comboCount;
$opts['from'] = 0;
$opts['interval'] = $this->tubeConfig->popularInterval;
$opts['orderby'] = 'top';
$popular = $episode->getAll($opts);
$opts['orderby'] = 'id';
$opts['orderby_type'] = 'desc';
$recent = $episode->getAll($opts);
$recent['data'] = array();
$this->movies->bind('popular', $popular['data']);
$this->movies->bind('recent', $recent['data']);

Также можно было добавить другую работу с бд, тоже всё выполнялось. Сначала грешил на ORM – но там его фактически не было – запрос писался руками(надо отметить что довольно сложный, по крайней мере невыполнимый в ORM от kohana).

Попытка вынести этот кусок кода в отдельный тестовый контроллер также оказалась безуспешна. По крайней мере из этого можно сделать вывод что на уровне своего контроллера косяков не должно быть.

Следующий этап – внимательное вкуривание классов Database, Database_Result, Database_Driver. Тоже вроде ничего интересного. Стал грешить на память(хотя ошибок в апачевском error_log небыло). Расставил get_memory_usage() – но из за 502 не посмотреть что пишет. Решил сделать die() после отработки этого куска кода с выводом количества используемой памяти. Оказалось вполне приемлимо – 4Mb после первого getAll(), 5.3Mb после второго вызова. Для интереса сделал так же вывод $popular и $recent – там оказались вытаскиваемые данные – т.е. запросы выполняются успешно.

Круг подозреваемых сузился – нужно ещё проверить View(который Smarty кстати). Хотя раньше проблем такого рода с ним не было. Решил оставить на потом и сначала проверить – может косяк в реализации определённых SQL запросов в драйвере?

Сделал запросы в моделе в методе getAll() не через $this->db->query($sql)->result_array(), а через mysql_query() и mysql_fetch_result() – и ПОЛУЧИЛОСЬ. Значит что то криво в классах kohana Database*, наверное.

Смотрим метод Database::query():

public function query($sql = '')
{
if ($sql == '') return FALSE;

// No link? Connect!
$this->link or $this->connect();

// Start the benchmark
$start = microtime(TRUE);

if (func_num_args() > 1) //if we have more than one argument ($sql)
{
$argv = func_get_args();
$binds = (is_array(next($argv))) ? current($argv) : array_slice($argv, 1);
}

// Compile binds if needed
if (isset($binds))
{
$sql = $this->compile_binds($sql, $binds);
}

// Fetch the result
$result = $this->driver->query($this->last_query = $sql);

// Stop the benchmark
$stop = microtime(TRUE);

if ($this->config['benchmark'] == TRUE)
{
// Benchmark the query
Database::$benchmarks[] = array('query' => $sql, 'time' => $stop - $start, 'rows' => $result->count());
}

return $result;
}

Ага.. Попробовать чтоли выполнить запрос напрямую к драйверу?
$this->db->driver->query($sql)->result_array()
Ай, ругается что $driver – это приватное поле. Ну ладно, всё таки PHP5 :)
Добавлю метод к Database

/**
* Get database driver
* @return Database_Driver
*/
public function getDriver() {
return $this->driver;
}

И снова пробую выполнять SQL в моём методе getAll().
$this->db->getDriver()->query($sql)->result_array()
Выполнилось!

Теперь явно видно, что с методом Database::query косяк, наверное.
Первое что приходит в голову начать комментировать условия, до тех пор пока не отработает. Парсинг аргументов(строки 3-20) пока оставляю, т.к использовал где-то плейсхолдеры. Коменчу сохранение бенчмарков и…. Снова выполнилось!

Причина

Теперь немного подумать.. Как сохранение бенчмарков может создавать ошибку при повторном вызове одного и того же метода?.. Видимо они где то выводятся.. Ну конечно же в модуле debugToolbar. А там по умолчанию запросы выводятся в firePHP. Как я и указал ранее запросы длинные – а у заголовков(именно через них общаются “клиент” и “сервер” firePHP) ограниченная длина, от чего nginx негодует, о чём я написал в начале.

Решение

Добавив в application/config/debug_toolbar.php строчку
$config['firephp_enabled'] = FALSE;
и убрав недавно поставленные комментарии на сохранение бенчмарка БД – эта злополучная страница снова заработала. УРЯ :)


Как же я запарился с
этой проблеммой. На её поиски ушло
несколько дней.