Версия для печати

Архив документации на OpenNet.ru / Раздел "Базы данных, SQL" (Многостраничная версия)

Методы выявления ошибок в SQL приложении

Автор: Светлана Смирнова (sveta_гав_js-client_точка_com)
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
Источник: http://sql-error.microbecal.com

Содержание
От Автора Часть 1. Одиночные запросы. Глава 1. Запрос. Глава 2. Получены неверные данные. Глава 3. В базе неверные данные или что делать с проблемным DML запросом. Глава 4. Смешанные случаи. Промежуточные итоги. Глава 5. Альтернативные способы поиска проблемного запроса. Итоги. Часть 2. Конкурентные запросы. Глава 6. Взаимные блокировки. Глава 7. Конкурентные транзакции. Итоги. Часть 3. Другие случаи. Глава 8. Большие объёмы данных. Глава 9. Загадочное исчезновение сервера. Глава 10. Lost connection to MySQL server during query Итоги. Часть 4. Техники, применяющиеся для отладки Production приложений. Глава 11. Техники, применяющиеся для отладки Production приложений. Итоги. Приложение. Способы копирования и переноса MySQL и баз данных. Послесловие. Ссылки.

Содержание

От Автора
Часть 1. Одиночные запросы.
Часть 2. Конкурентные запросы.
Часть 3. Другие случаи.
Часть 4. Техники, применяющиеся для отладки Production приложений.
- Глава 11. Техники, применяющиеся для отладки Production приложений.
- Итоги.
Приложение. Способы копирования и переноса MySQL и баз данных.
Послесловие.
Ссылки.

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Приложение. Способы копирования и переноса MySQL и баз данных.

В данном приложении хотелось бы осветить основные способы при помощи которых вы сможете осуществить backup и перенос MySQL баз данных.

Рекомендованный и простейший способ переноса данных при помощи утилиты mysqldump. Скопировать данные вы можете при помощи следующей команды:


$mysqldump dbname [tblname ...] >dump.sql

Загрузить данные в базу можно при помощи команды:


$mysql dbname <dump.sql

Смотрите MySQL user manual для информации о дополнительных опциях.

mysqldump делает дамп таблиц в формате запросов SQL. Он добавляет запросы LOCK TABLES, поэтому вы можете не беспокоиться о целостности данных. Но в случае больших объёмов mysqldump работает слишком медленно, что может вас не устраивать.

Альтернативный вариант использование простого копирования. Просто скопируйте MySQL datadir при помощи средств операционной системы таких как cp. Так как данные в таблицах MySQL бинарно совместимы между версиями и платформами простое копирование отличный выход. Но в этом случае вы должны заботиться о блокировках вручную.

Также вы можете использовать средства ОС такие как LVM Snapshots, но, опять-таки, придётся заботиться о блокировках вручную.

Существуют утилиты для копирования данных, использующих определённую storage engine. Например, mysqlhotbackup для MyISAM, InnoDB Hot Backup и xtrabackup для InnoDB.

Ожидается выпуск MySQL Backup, который совместит удобство mysqldump и скорость специальных средств в одной из ближайших версий. Также MySQL Backup работает со всеми storage engine. Следите за анонсами!

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Часть 1. Одиночные запросы.

Глава 1. Запрос.

Наверное многие из вас знают, хотя бы из школьного курса математики, что любая сложная задача может быть сведена к набору простых. Тот же приём можно применить и к проблемам SQL приложения.

Для начала посмотрим пример с простым запросом. Ошибка в этом случае находится очень просто.


select * fro t1 where f1 in (1,2,1);

Я думаю, большинство читателей уже заметили в чём проблема. Если выполнить этот запрос в mysql cli ошибка стнает ещё заметней:


mysql> select * fro t1 where f1 in (1,2,1);

ERROR 1064 (42000): You have an error in your SQL syntax;

check the manual that corresponds to your MySQL server version

for the right syntax to use near 'fro t1 where f1 in (1,2,1)' at line 1

То есть это синтаксическая ошибка: опущена поледняя буква o в предикате from. Просто, не правда ли?

Возьмём пример посложнее. Это код на PHP. (Для любителей холиворов повторю, что код был подготовлен для PHP конференции в Москве. Аналогичную путаницу можно написать и на любом другом вашем любимом языке программирования.)


$query = 'SELECT * FROM t4 WHERE f1 IN(';

for ($i = 1; $i < 101; $i ++)

$query .= "'row$i,";

$query = rtrim($query, ',');

$query .= ')';

$result = mysql_query($query);

В данном случае вычленить ошибку уже труднее. А что будет в случае ещё более сложного запроса?

В случае с PHP нам поможет простой операто echo, который осуществляет вывод:


$query = 'SELECT * FROM t4 WHERE f1 IN(';

for ($i = 1; $i < 101; $i ++)

$query .= "'row$i,";

$query = rtrim($query, ',');

$query .= ')';

echo $query;

//$result = mysql_query($query);

Запустим скрипт:


$php phpconf2009_1.php

SELECT * FROM t4 WHERE f1 IN('row1,'row2,'row3,'row4,'row5,'row6,'row7,'row8,'row9,'row10,'row11,

'row12,'row13,'row14,'row15,'row16,'row17,'row18,'row19,'row20)

И тут нам ошибка становится более очевидной: пропущен закрывающий апостроф в выражении


$query .= "'row$i,";

Достаточно заменить его выражением


$query .= "'row$i',";

и запрос будет выполняться верно.

Обратите внимание, что мы выводили запрос именно в том виде, в котором его получает СУБД. Намного проще найти ошибку в готовом запросе, чем в строке, которая собирается из разных частей или содержит переменные.

Использование оператора вывода для выявления проблемного запроса простейший, но эффективный приём.

Приём 1: используйте оператор вывода для вывода запроса в том виде, в котором его получает СУБД.

К сожалению мы не всегда можем использовать echo. Например в случае поддержки существующего сложного приложения.

Посмотрим на следующий пример.

Проблема возникла на web-странице со следущим интерфейсом:


Имеющиеся системы



    * Учебник

    * Тест

    * test2

    * test2

    * test2

    * test2

    * test2



Введите название новой системы:



<>



Описание:



<>



<Go!>

Проблема в том, что у нас каким-то образом образовалось несколько систем с одинаковым именем.

Посмотрим на код, который за это отвечает:


$system = System::factory()

->setName($this->form->get(Field::NAME))

->setDescription(

$this->form->get(Field::DESCRIPTION)

);

DAO::system()->take($system);

Что-нибудь понятно? Я думаю опытный человек может предположить в чём проблема, но в любом случае это только гипотеза, которую необходимо подтвердить или опровергнуть. Ещё менее понятно где в этом примере добавить вывод и вывод чего именно: у нас нет ни обращения к базе, ни запроса.

В PHP достаточно легко изменить код библиотеки, который отвечает за компиляцию запроса, чтобы он печатал его (запрос) в файл или на stderr перед тем, как отправить базе, но в случае с компилируемыми языками, например, с Java, библиотеку придётся перекомпилировать. Да и не всегда код библиотеки открыт.

Что же делать? В случае с MySQL мы можем применить general query log:


mysql> set global log_output='table';

Query OK, 0 rows affected (0.00 sec)


mysql> select * from mysql.general_log;

Empty set (0.09 sec)


mysql> set global general_log='on';

Query OK, 0 rows affected (0.00 sec)

Запускаем приложение.


mysql> select * from mysql.general_log order by event_time desc limit 25\G

*************************** 1. row ***************************

  event_time: 2009-10-19 13:00:00

   user_host: root[root] @ localhost []

   thread_id: 10323

   server_id: 60

command_type: Query

    argument: select * from mysql.general_log order by event_time desc limit 25

...

*************************** 22. row ***************************

  event_time: 2009-10-19 12:58:20

   user_host: root[root] @ localhost [127.0.0.1]

   thread_id: 10332

   server_id: 60

command_type: Query

    argument: INSERT INTO `system` (`id`, `name`, `description`) VALUES ('', 'test2', '')

...

mysql> set global general_log='off';

Query OK, 0 rows affected (0.08 sec)

В 22 строке мы видим наш запрос. Он не выглядит проблемным: обычный INSERT.

Посмотрим что мы имеем в таблице system:


mysql> select * from system;

+----+---------+------------------------------------------+

| id | name    | description                              |

+----+---------+------------------------------------------+

|  1 | Учебник  | Конструирование мужской и женской одежды      |

|  2 | Тест     | Тестовый геометрический набор                 |

|  3 | test2   | New test                                 |

|  4 | test2   | foobar                                   |

|  8 | test2   |                                          |

+----+---------+------------------------------------------+

5 rows in set (0.00 sec)

Посмотрим её определение:


mysql> show create table system\G

*************************** 1. row ***************************

       Table: system

Create Table: CREATE TABLE `system` (

  `id` int(11) NOT NULL AUTO_INCREMENT,

  `name` varchar(255) NOT NULL,

  `description` tinytext NOT NULL,

  PRIMARY KEY (`id`)

) ENGINE=InnoDB AUTO_INCREMENT=9 DEFAULT CHARSET=utf8

1 row in set (0.09 sec)

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


(alter table system add unique(name))

либо изменить приложение таким образом, чтобы эта проблема обрабатывалась не на уровне SQL.

Мы только что рассмотрели следующий приём: используйте general query log для выявления запроса, который вызывает неправильное поведение.

Приём 2: используйте general query log, если вам нужно определить какой именно запрос вызывает неправильное поведение вашего приложения.

Мы убедились, что практически всегда можно выделить запрос, вызвавший проблему в приложении. В большинстве случаев этого достаточно, чтобы найти и устранить ошибку. Это объясняет, почему большую часть данного текста я отвела именно для поиска проблемного запроса. Конечно, существуют ситуации, когда нахождением единичного запроса не отделаться. Эти ситуации будут рассмотрены отдельно. Я хотела бы обратить ваше внимание на следующие запросы:


mysql> select * from mysql.general_log;

Empty set (0.09 sec)


mysql> set global general_log='on';

Query OK, 0 rows affected (0.00 sec)


...


mysql> set global general_log='off';

Query OK, 0 rows affected (0.08 sec)

Зачем нам нужно изменять значение глобальной переменной, если мы можем влдючить general query log в конфигурационном файле?

Дело в том, что general query log сам по себе весьма дорогостоящ: он увеличивает нагрузку на сервер и так как он содержит все запросы, то вам также придётся следить за местом на диске. Начиная же с версии 5.1 его можно включать-выключать в режиме реального времени тем самым сводя дополнительную нагрузку на MySQL сервер к минимуму.

Следующий запрос включает вывод не в файл, а в таблицу. Вывод в таблицу хорош для выявления таких проблемных запросов как в последних 2-ух примерах, так как таблицу легко отсортировать: вы обращаетесь к ней также как к любой другой таблице.


mysql> set global log_output='table';

Query OK, 0 rows affected (0.00 sec)

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 10. Lost connection to MySQL server during query

Вы можете увидеть ошибку Lost connection to MySQL server не только по причине слишком маленького connect_timeout, но и по ряду других причин. В настоящей главе мы рассмотрим эти причины.


$php phpconf2009_4.php 

string(44) "Lost connection to MySQL server during query"

Чаще всего error log покажет что произошло:


Version: '5.1.39'  socket: '/tmp/mysql_sandbox5139.sock'  port: 5139  MySQL Community Server (GPL)

091002 14:56:54 - mysqld got signal 11 ;

This could be because you hit a bug. It is also possible that this binary

or one of the libraries it was linked against is corrupt, improperly built,

or misconfigured. This error can also be caused by malfunctioning hardware.

We will try our best to scrape up some info that will hopefully help diagnose

the problem, but since we have already crashed, something is definitely wrong

and this may fail.

key_buffer_size=8384512

read_buffer_size=131072

max_used_connections=1

max_threads=151

threads_connected=1



It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338301 K

bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

thd: 0x69e1b00

Attempting backtrace. You can use the following information to find out

where mysqld died. If you see no messages after this, something went

terribly wrong...

stack_bottom = 0x450890f0 thread_stack 0x40000

/users/ssmirnova/blade12/5.1.39/bin/mysqld(my_print_stacktrace+0x2e)[0x8ac81e]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(handle_segfault+0x322)[0x5df502]

/lib64/libpthread.so.0[0x3429e0dd40]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN6String4copyERKS_+0x16)[0x5d9876]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN14Item_cache_str5storeEP4Item+0xc9)[0x52ddd9]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN26select_singlerow_subselect9send_dataER4ListI4ItemE+0x45)[0x5ca145]

/users/ssmirnova/blade12/5.1.39/bin/mysqld[0x6386d1]

/users/ssmirnova/blade12/5.1.39/bin/mysqld[0x64236a]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN4JOIN4execEv+0x949)[0x658869]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN30subselect_single_select_engine4execEv+0x36c)[0x596f3c]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN14Item_subselect4execEv+0x26)[0x595d96]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN24Item_singlerow_subselect8val_realEv+0xd)[0x595fbd]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN14Arg_comparator18compare_real_fixedEv+0x39)[0x561b89]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN12Item_func_ne7val_intEv+0x23)[0x568fb3]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN4JOIN8optimizeEv+0x12ef)[0x65208f]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0xa0)[0x654850]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z13handle_selectP3THDP6st_lexP13select_resultm+0x16c)[0x65a1cc]

/users/ssmirnova/blade12/5.1.39/bin/mysqld[0x5ecbda]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z21mysql_execute_commandP3THD+0x602)[0x5efdd2]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z11mysql_parseP3THDPKcjPS2_+0x357)[0x5f52f7]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xe93)[0x5f6193]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_Z10do_commandP3THD+0xe6)[0x5f6a56]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(handle_one_connection+0x246)[0x5e93f6]

/lib64/libpthread.so.0[0x3429e061b5]

/lib64/libc.so.6(clone+0x6d)[0x34292cd39d]`)

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort...

thd->query at 0x6a39e60 = select 1 from `t1` where `c0` <>  (select geometrycollectionfromwkb(`c3`) from `t1`)

thd->thread_id=2

thd->killed=NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains

information that should help you find out what

Мы видим, что MySQL сервер упал по причине системной ошибки 11 ( mysqld got signal 11). То есть MySQL сервер запросил у операционной системы ресурс (например, доступ к файлу или оперативной памяти), но получил отказ с кодом 11. Эта ошибка чаще всего обозначает Segmentation fault - отказ в доступе к оперативной памяти.

Номера ошибок операционной системы не универсальны и могут отличаться. Если вы хотите быть уверены, что данный код имеет в вашей операционной системе определённое значение или вам встретилась менее распространённая ошибка используйте утилиту perror, которая находится в директории bin директории куда вы установили MySQL. Вот, например, что показывает perror для моей инсталляции MacOSX:


$perror 11

OS error code  11:  Resource deadlock avoided

Далее мы видим backtrace (начиная с Attempting backtrace.) Мы вернёмся к backtace позже.

Ещё ниже мы видим запрос, который вызвал эту проблему:


Trying to get some variables.

Some pointers may be invalid and cause the dump to abort...

thd->query at 0x6a39e60 = select 1 from `t1` where `c0` <>  (select geometrycollectionfromwkb(`c3`) from `t1`)

Проблема в запросе

select 1 from `t1` where `c0` <> (select geometrycollectionfromwkb(`c3`) from `t1`)

Попытаемся воспроизвести в mysql cli


$./my sql

mysql [localhost] {msandbox} ((none)) > use test

Database changed

mysql [localhost] {msandbox} (test) > select 1 from `t1` where `c0` <>  (select geometrycollectionfromwkb(`c3`) from `t1`);

ERROR 2013 (HY000): Lost connection to MySQL server during query

mysql [localhost] {msandbox} (test) > \q

Bye

То есть это регулярно повторяющийся баг. Нужно изменить приложение таким образом, чтобы оно не сталкивалось с этим багом пока он не будет исправлен.

Для этого посмотрим backtrace


/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN14Item_subselect4execEv+0x26)[0x595d96]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN24Item_singlerow_subselect8val_realEv+0xd)[0x595fbd]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN14Arg_comparator18compare_real_fixedEv+0x39)[0x561b89]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN12Item_func_ne7val_intEv+0x23)[0x568fb3]

/users/ssmirnova/blade12/5.1.39/bin/mysqld(_ZN4JOIN8optimizeEv+0x12ef)[0x65208f]

Он содержит следующие вызовы: Item_subselect и Item_singlerow_subselect. Отсюда даже не заглядывая в код MySQL мы можем сделать вывод, что виноват подзапрос.

Попробуем переписать запрос


$./my sql

mysql [localhost] {msandbox} (test) > select 1 from `t1` where `c0` <> geometrycollectionfromwkb(`c3`);

Empty set (0.00 sec)

MySQL сервер работает нормально! Мы можем пользоваться переписанным запросом до тех пор, пока баг не будет исправлен.

Приём 18: всегда используйте error log

Но иногда в error log нет нужной информации

Тот же запрос, но на Mac-е


091002 16:49:48 - mysqld got signal 10 ;

This could be because you hit a bug. It is also possible that this binary

or one of the libraries it was linked against is corrupt, improperly built,

or misconfigured. This error can also be caused by malfunctioning hardware.

We will try our best to scrape up some info that will hopefully help diagnose

the problem, but since we have already crashed, something is definitely wrong 

and this may fail. 



key_buffer_size=8384512

read_buffer_size=131072

max_used_connections=1

max_connections=100

threads_connected=1

It is possible that mysqld could use up to 

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 225784 K

Как видим, ни backtrace, ни запроса в error log нет. Что же делать?

В этом случае, как и раньше, нам поможет general query log. MySQL сначала пишет запрос в general query log и только потом выполняет его. Поэтому вполне логично использовать этот метод для повторяющихся проблемных запросов.


mysql> set global general_log=1;

Query OK, 0 rows affected (0.00 sec)

mysql> set global log_output='table';

Query OK, 0 rows affected (0.00 sec)

Запускаем тест. После перезапуска сервера проверяем general query log:


mysql> select argument from mysql.general_log order by event_time desc limit 10;

+--------------------------------------------+

| argument                                   |

+--------------------------------------------+

| Access denied for user 'MySQL_Instance_Manager'@'localhost' (using password: YES)                             |

| select 1 from `t1` where `c0` <>  (select geometrycollectionfromwkb(`c3`) from `t1`) |

Запрос, вызвавший крушение, обнаружен!

Приём 19: используйте general query log если error log не содержит информации о причинах крушения сервера.

При использовании этого приёма существует вероятность, что таблица mysql.general_log будет повреждена во время крушения MySQL сервера. В этом случае попробуйте запись в файл.

Также существует вероятность, что MySQL сервер перестанет работать во время записи запроса в general query log. В таком случае пользуйтесь либо логами вашего приложения, либо прокси.

Пример, который мы только что рассмотрели, произошёл из бага MySQL сервера. Но MySQL сервер может быть аварийно остановлен и по причине нехватки ресурсов в системе.

Первое, на что стоит обратить внимание это RAM

Цитата из реального лога:


key_buffer_size=235929600

read_buffer_size=4190208

max_used_connections=17

max_connections=2048

threads_connected=13

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 21193712 K

-----

21193712K ~= 20G

То есть MySQL может использовать до 20G RAM! Сейчас мощные машины, но стоит проверить действительно ли у вас 20G RAM.

Приём 20: всегда проверяйте достаточно ли у вас RAM для выделенных буферов.

Также обратите внимание на значение переменной max_connections.

В предыдущем примере max_connections=2048. Это достаточно много. Проверьте, хватит ли у вас ресурсов на такое количество одновременных соединений.

Я встречала в практике случаи, когда пользователи устанавливали значение max_connections значительно больше, чем их сервера могли обслужить. Это приводило к непредсказуемым крушениям MySQL сервера при резко возросших нагрузках на обслуживаемые веб-ресурсы.

Приём 21: устанавливайте значение max_connections таким какое вы сможете обслужить.

Также MySQL сервер может испытывать нехватку других ресурсов. Обычно информация об ошибке содержится в error log. Анализируйте эту информацию и устраните проблему.

Однако не всегда сам MySQL сервер виноват в нехватке ресурсов. Может так случиться, что их заняло другое приложение. В таком случае используйте системные средства для мониторинга, чтобы выявить виновника.

Приём 22: используйте средства мониторинга вашей операционной системой чтобы установить что потребляет избыточное количество ресурсов, которое приводит к крушению MySQL сервера.

Как мы ранее рассмотрели сообщение Lost connection to MySQL server может также обозначать timeout. Если error log не содержит других ошибок или вы подозреваете именно этот случай, добавьте опцию log_warnings=2 в конфигурационный файл и проверьте error log после получения сообщения.

Приём 23: Используйте опцию log_warnings=2 чтобы отследить имеются ли у вас отклонённые соединения.

Иногда ошибка повторяется только при конкурентных запросах. Используйте дополнительное програмное обеспечение и general log, чтобы понять каких именно. Я не буду здесь останавливаться на данной теме подробнее, поскольку она достаточно сложна и требует индивидуального решения.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Часть 4. Техники, применяющиеся для отладки Production приложений.

Глава 11. Техники, применяющиеся для отладки Production приложений.

К сожалению не всегда можно отловить ошибку на стадии тестирования. Часто они проявляют себя только при реальной нагрузке.

Как вы о них узнаете?

Один из важнейших источников информации о проблемах error log file. Там вы найдёте информацию о таких проблемах как падение сервера, ошибки соединений (если включена опция log_warnings=2), опциях, которые были указаны в конфигурационном файле, но не были включены из-за ошибки и ряде других. Правило работы с error log такое: если творится что-то непонятное, первым делом проверьте записи в error log. Error log file в том числе содержит информацию об ошибках сервера, которые недоступны клиентам. Поэтому желательно его держать всегда включённым даже если у вас включено логирование на уровне приложения.

Приём 25: если творится что-то непонятное, первым делом проверьте записи в error log.

Также вы можете настроить InnoDB Monitor, который будет писать всю информацию об InnoDB транзакцих в error log file.

Приём 26: насторйте InnoDB Monitor чтобы иметь в error log информацию о всех транзакциях с применением InnoDB таблиц.

Другой важный источник информации slow query log. Он содержит все запросы, которые выполняются более чем long_query_time секунд. Дефолтное значение long_query_time 10 секунд, но вы можете его изменить. Используйте slow query log для поиска медленных запросов. Также его можно настроить на запись всех запросов, не использующих индексы.

Приём 27: используйте slow query log чтобы выявить медленные запросы.

После того как ошибка найдена бывает необходимость протестировать её в командной строке. Не всегда это можно сделать на production сервере. Например, если найден запрос, приводящий к падению сервера. Или запрос, выполняющийся очень медленно и теебующий много ресурсов: нужно упростить такой запрос или попробовать не лучше ли его разбить на несколько более простых, так как часто такой приём приводит к улучшению производительности.

В этом случае нужно создать окружение, максимально приближённое к реальному, на тестовой машине.

В общем случае вам нужно запустить на отдельной, например, девелоперской машине, MySQL сервер той же версии, что и на рабочем сервере. Также вам нужно скопировать настройки из конфигурационного файла и загрузить данные. Проще всего сделать дамп при помощи команды mysqldump, но это не всегда удобно, так как может занять слишком много времени при большом объёме данных. MySQL поддерживает бинарную совместимость данных между платформами, поэтому можно просто скопировать файлы нужных таблиц. Смотрите приложение о способах backup и переноса данных между MySQL серверами.

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

Иногда нужно протестировать запрос на разных версиях. Это может понадобиться, если вы столкнулись с багом в MySQL коде, который был исправлен позднее, и хотите проверить, будут ли остальные запросы вашего приложения равботать на этой новой версии. Это может быть не обязательно баг, но новая возможность.

Иногда стоит протестировать несколько минорных версий, чтобы выбрать наиболее для вас подходящую.

Проще всего это сделать при помощи MySQL Sandbox. MySQL Sandbox это кросс-платформенное приложение, написанное на Perl. Загрузить его можно с https://launchpad.net/mysql-sandbox

Загрузите *tar.gz пакет с нужной вам версией, затем установите MySQL Sandbox и запустите команду:


$make_sandbox mysql-5.4.2-beta-linux-x86_64-glibc23.tar.gz

unpacking /users/ssmirnova/blade12/mysql-5.4.2-beta-linux-x86_64-glibc23.tar.gz

Executing low_level_make_sandbox --basedir=/users/ssmirnova/blade12/5.4.2 \

        --sandbox_directory=msb_5_4_2 \

        --install_version=5.4 \

        --sandbox_port=5420 \

        --no_ver_after_name \

        --my_clause=log-error=msandbox.err

    The MySQL Sandbox,  version 3.0.05

    (C) 2006,2007,2008,2009 Giuseppe Maxia

installing with the following parameters:

upper_directory                = /users/ssmirnova/sandboxes

sandbox_directory              = msb_5_4_2

sandbox_port                   = 5420

check_port                     = 0

no_check_port                  = 0

datadir_from                   = script

install_version                = 5.4

basedir                        = /users/ssmirnova/blade12/5.4.2

my_file                        = 

operating_system_user          = ssmirnova

db_user                        = msandbox

db_password                    = msandbox

my_clause                      = log-error=msandbox.err

prompt_prefix                  = mysql

prompt_body                    =  [\h] {\u} (\d) > '

force                          = 0

no_ver_after_name              = 1

verbose                        = 0

load_grants                    = 1

no_load_grants                 = 0

no_run                         = 0

no_show                        = 0

do you agree? ([Y],n) Y

091101 11:47:44 [Warning] Forcing shutdown of 2 plugins

091101 11:47:44 [Warning] Forcing shutdown of 2 plugins

loading grants

........ sandbox server started

Your sandbox server was installed in $HOME/sandboxes/msb_5_4_2

Замените mysql-5.4.2-beta-linux-x86_64-glibc23.tar.gz нужной вам версией.

Выше вы увидели, что sandbox server был инсталлирован в директории $HOME/sandboxes/msb_5_4_2. Также он был запущен:


$cd $HOME/sandboxes/msb_5_4_2



$./my

syntax my sql{dump|binlog|admin} arguments



$./my sql

Welcome to the MySQL monitor.  Commands end with ; or \g.

Your MySQL connection id is 3

Server version: 5.4.2-beta MySQL Community Server (GPL)



Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.



mysql [localhost] {msandbox} ((none)) > select version();

+------------+

| version()  |

+------------+

| 5.4.2-beta |

+------------+

1 row in set (0.00 sec)



mysql [localhost] {msandbox} ((none)) > \q

Bye

Остановите сервер при помощи команды


$./stop

Внесите необходимые изменения в конфигурационный файл, скопируйте данные, затем запустите сервер:


$./start 

. sandbox server started

Песочница ( а sandbox переводится с английского как песочница) готова! Можете начинать тестировать.

Приём 28: используйте MySQL Sandbox, чтобы быстро и удобно оттестировать ваше приложение на нескольких версиях MySQL.

Не всегда удобно выявлять ошибку, используя все данные. Например, вы получаете неверный результат, запрашивая несколько строк из таблицы с миллионами строк. Если по каким-либо причинам этот запрос выполняется медленно вы будете достаточно долго ждать результата каждого из тестовых запросов.

Чаще всего неверные результаты возникают при использовании предиката WHERE в совокупности с другими предикатами, такими как LIMIT, ORDER BY, GROUP BY, HAVING или же если в WHERE содержится несколько условий.

Вы можете минимизировать test case используя только часть данных.

Создайте таблицу с теми же полями, что и исходная:


CREATE TABLE test_problem LIKE problem;

Затем загрузите в эту таблицу только часть данных:


INSERT INTO test_problem SELECT FROM problem WHERE [условие, которое присутствует в оригинальном запросе, но выполняется верно]

Далее работайте с таблицей test_problem до тех пор, пока не найдёте причину неправильного поведения. Исправьте оригинальный запрос.

Тот же приём можно применять и для запросов, одновременно использующих несколько таблиц.

Приём 29: используйте часть данных при работе с запросами, которые возвращают неверные результаты на больших объёмах.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 2. Получены неверные данные.

Мы научились находить проблемный запрос.

Мы уже рассмотрели 2 примера синтаксической ошибки и один пример логической. Охватывают ли эти примеры все возможности, предоставляемые нам анализом проблемного запроса? Конечно, нет! Хотя строго говоря все ошибки в запросе можно свести к этим двум подтипам. В этой главе мы рассмотрим что ещё можно сделать с проблемным запросом.

Синтаксические ошибки тривиальны, поэтому мы далее не будем на них останавливаться.

Одна из часто встречающихся проблем - запрос SELECT возвращает неверные данные. Это может происходить по ряду причин.

Рассмотрим простейший - с точки зрения устранения - пример.


mysql> select count(*) as b from t3 order by b,a;

+---+

| b |

+---+

| 2 |

| 2 |

+---+



mysql> select count(*) as b from t3;

+---+

| b |

+---+

| 2 |

+---+

1 row in set (0.01 sec)



mysql> show create table t3\G

************ 1. row ************

       Table: t3

Create Table: CREATE TABLE `t3` (

  `a` int(11) NOT NULL

) ENGINE=MyISAM DEFAULT CHARSET=utf8

1 row in set (0.00 sec)

Несмотря на необычность запроса поведение явно неверное: count(*) не может возвращать более одной строчки, если не использован GROUP BY. Запрос тривиален и упрощать его некуда. В этом случае ваш путь по адресу http://bugs.mysql.com, в поиск, где мы и находим соответствующий баг: http://bugs.mysql.com/bug.php?id=47280 Там же мы выясняем, что баг обнаружен в версии 5.1.38 и сейчас исправлен. Соответственно обновление до версии 5.1.38 или более новой устранит проблему.

Само собой разумеется, если бага, подобного обнаруженного вами, нет, нужно его послать по тому же адресу http://bugs.mysql.com

Но что делать, если вы не можете в данный момент обновить MySQL сервер? В данном случае убрать order by. Данный пример демонстрирует не только то, что MySQL Server тоже содержит баги в коде, но и ещё один метод работы с проблемным запросом.

Приём 3: после того как вы выявили запрос, вызывающий проблемы, запустите его в командной строке и проанализируйте полученный результат.

Но существуют и баги с workaround, не требующими модификации SQL. Как правило если workaround не очевиден он описан в bug report.

Возьмём следующий пример:


mysql> create table `a` (

    ->   `id` bigint(20) not null auto_increment,

    ->   primary key (`id`)

    -> ) engine=myisam;

Query OK, 0 rows affected (0.04 sec)



mysql> create table `b` (

    ->   `id` bigint(20) not null auto_increment,

    ->   `a_id` bigint(20) default null,

    ->   primary key (`id`)

    -> ) engine=myisam;

Query OK, 0 rows affected (0.04 sec)



mysql> insert into `a` values (1),(2),(3),(4),(5),(6),(7),(8);

Query OK, 8 rows affected (0.00 sec)

Records: 8  Duplicates: 0  Warnings: 0

mysql> insert into `b` values (1,1),(2,1),(3,1),(4,2),(5,2),(6,2),(7,3),(8,3);

Query OK, 8 rows affected (0.01 sec)

Records: 8  Duplicates: 0  Warnings: 0



mysql> select a.id as a_id, count(distinct b.id) as cnt from a a left join b b on a.id = b.a_id

    -> where a.id = 1 group by a.id with rollup limit 100;

+------+-----+

| a_id | cnt |

+------+-----+

|    1 |   8 |

| NULL |   8 |

+------+-----+

2 rows in set (0.01 sec)

Откуда у нас 8 строк в a_id=1? Чётко видно, что мы внесли только 3 строки с a_id = 1:


mysql> insert into `b` values (1,1),(2,1),(3,1),

(4,2),(5,2),(6,2),(7,3),(8,3);

Query OK, 8 rows affected (0.01 sec)

Records: 8  Duplicates: 0  Warnings: 0

Что и подтвержает последующий запрос уже без группировок.


mysql> select a.id as a_id, b.id from a a left join b b on a.id = b.a_id where a.id = 1;

+------+------+

| a_id | id   |

+------+------+

|    1 |    1 |

|    1 |    2 |

|    1 |    3 |

+------+------+

3 rows in set (0.00 sec)

Этот случай описан по адресу http://bugs.mysql.com/bug.php?id=47650. Он также был обнаружен в версии 5.1.38 и на момент написания данного текста не был исправлен.

Но здесь имеется workaround:


mysql> alter table b add index(a_id);

Query OK, 8 rows affected (0.05 sec)

Records: 8  Duplicates: 0  Warnings: 0



mysql> select a.id as a_id, count(distinct b.id) as cnt from a a left join b b on a.id = b.a_id

    -> where a.id = 1 group by a.id with rollup limit 100;

+------+-----+

| a_id | cnt |

+------+-----+

|    1 |   3 |

| NULL |   3 |

+------+-----+

2 rows in set (0.02 sec)

Как вы могли убедиться результат теперь правильный.

Приём 4: пробуйте изменить SQL таким образом, чтобы результат был правильным. Пользуйтесь поисковыми системами для нахождения workaround.

Случаи с багами в коде MySQL хоть и легки для устранения, всё-таки встречаются гораздо реже, чем баги в SQL коде пользователя.

Что же делать, чтобы определить почему запрос SELECT работает не так как ожидается?

Рассмотрим пример.


mysql> create table t1(f1 int);

Query OK, 0 rows affected (0.01 sec)

mysql> create table t2(f2 int);

Query OK, 0 rows affected (0.08 sec)

mysql> insert into t1 values(1);

Query OK, 1 row affected (0.01 sec)



mysql> select * from t1;

+------+

| f1   |

+------+

|    1 | 

+------+

1 row in set (0.00 sec)

Но


mysql> select * from t1, t2;
Empty set (0.00 sec)

Почему SELECT из двух таблиц возвращает пустой набор, хотя строки в таблице t1 существуют?

На помощь на приходит EXPLAIN EXTENDED:


mysql> \W

Show warnings enabled.



mysql> explain extended select * from t1, t2;

+----+-------------+-------+--------+---------------+------+---------+------+------+----------+---------------------+

| id | select_type | table | type   | possible_keys | key  | key_len | ref  | rows | filtered | Extra               |

+----+-------------+-------+--------+---------------+------+---------+------+------+----------+---------------------+

|  1 | SIMPLE      | t1    | system | NULL          | NULL | NULL    | NULL |    1 |   100.00 |                     |

|  1 | SIMPLE      | t2    | system | NULL          | NULL | NULL    | NULL |    0 |     0.00 | const row not found |

+----+-------------+-------+--------+---------------+------+---------+------+------+----------+---------------------+

2 rows in set, 1 warning (0.20 sec)



Note (Code 1003): select '1' AS `f1`,'0' AS `f2` from `test`.`t1` join `test`.`t2`

Как вы видите, запрос преобразован в запрос с JOIN, который является синоимом INNER JOIN и который не может вернуть строки из табицы t1, если в таблице t2 нет соответствующих строк. Так как таблица t2 не содержит записей, запрос ничего и не возвращает.

Для более сложных (длинных) запросов алгоритм подобный: запустить EXPLAIN EXTENDED, если ошибка не выявлена, то разбить или упростить запрос, повторить.

EXPLAIN также поможет, если ваш запрос выполняется очень долго, хотя и возвращает верные данные. Мы не будем здесь подробно на этом останавливаться, поскольку данная возможность хорошо описана в официальном MySQL User Manual. Смотрите соответствующие главы.

Приём 5: используйте EXPLAIN EXTENDED для того, чтобы понять каким образом оптимизируется (а значит и выполняется) SQL запрос.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 3. В базе неверные данные или что делать с проблемным DML запросом.

Проблемы с неправильными данными возникают не только в случае с SELECT аналогичным рассмотренным ранее, но и в случае запросов, модифицирующих данные. Так называемых DML запросов.

Рассмотрим пример.


mysql> create table t1(f1 int);

Query OK, 0 rows affected (0.01 sec)

mysql> create table t2(f2 int);

Query OK, 0 rows affected (0.08 sec)

mysql> insert into t1 values(1);

Query OK, 1 row affected (0.01 sec)



mysql> select * from t1;

+------+

| f1   |

+------+

|    1 | 

+------+

1 row in set (0.00 sec)



mysql> delete from t1, t2 using t1, t2;

Query OK, 0 rows affected (0.00 sec)

Данный запрос должен был бы удалить все строки в таблицах t1 и t2: использован using t1, t2; и нет предиката WHERE. Однако это не так.

Обратите внимание на строчку "0 rows affected". Она обозначает, что было удалено 0 строк, то есть ничего удалено не было! Почему?

Проверим что у нас в таблицах:


mysql> select * from t1;

+------+

| f1   |

+------+

|    1 | 

+------+

1 row in set (0.00 sec)

Что произошло?

В случае с SELECT мы могли бы воспользоваться предыдущим приёмом и посмотреть вывод EXPLAIN EXTENDED. Но MySQL не поддерживает EXPLAIN DELETE/UPDATE/INSERT. Эта возможность планируется, но в данный момент ещё не реализована. Что же предпринять в этом случае?

Лучший способ проверить запросы delete/insert/update - это конвертировать их в соответствующие select запросы:


mysql> select * from t1, t2;

Empty set (0.00 sec)

Мы получили тот же запрос, что рассматривали в предыдущей главе. Соотетственно вывод аналогичный: в данном случае выражение t1, t2 обозначает t1 INNER JOIN t2. А так как в таблице t2 нет данных, то и нет поля, по которому они могли бы объединиться. Соответственно не было ничего удалено.

Аналогичным способом можно работать и с проблемными update запросами.

Приём 6: преобразуйте DML запросы в соответствующий SELECT чтобы выяснить какие строки будут изменены.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 4. Смешанные случаи.

Существуют варианты, когда неверный вывод является лишь симптомом, что ранее был осуществлён неправильный ввод.

Например, на каком-то шаге сценария вы начинаете получать неверные данные. После анализа запроса (или запросов) SELECT выясняется, что запросы корректны и возвращают именно те данные, которые есть в таблице (или таблицах).

Это обозначает, что неверные данные были внесены на ранних этапах сценария.

Как выяснить когда именно это было сделано?

Начинайте с шага сценария, следующего непосредственно перед выводом, проверяйте все запросы как было описано в предыдущих главах. Если опять всё работает верно, проверьте ещё более ранний шаг и так до тех пор пока не найдёте ошибку.

Можно рассматривать пример со списком из первой главы как образец такого неверного поведения.

Посмотрим ещё раз на вывод.

Имеющиеся системы


    * Учебник

    * Тест

    * test2

    * test2

    * test2

    * test2

    * test2



Введите название новой системы:

<>

Описание:

<>



<Go!>

Мы рассматривали страницу, модифицирующую список. Но что если подобный список обнаружился на странице, осуществляющей вывод? Вот код, отвечающий за вывод списка:


return $this->addParameters(array(Field::ITEMS => DAO::system()->getPlainList()));

Запрос SELECT будет совершенно корректным:


SELECT `system`.`id`, `system`.`name`, `system`.`description` FROM `system`

Посмотрим что в таблице:


mysql> select * from system;

+----+---------+-------------------------------------------------+

| id | name    | description                                     |

+----+---------+-------------------------------------------------+

|  1 | Учебник  | Конструирование мужской и женской одежды             |

|  2 | Тест     | Тестовый геометрический набор                        |

|  3 | test2   | New test                                        |

|  4 | test2   | foobar                                          |

|  8 | test2   |                                                 |

+----+---------+-------------------------------------------------+

5 rows in set (0.00 sec)

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

Приём 7: проверяйте ваш сценарий шаг за шагом в обратном порядке пока не найдёте проблемный запрос.

Длинно, не правда ли? Можно ли что-то сделать, чтобы выявить проблему более простым способом?

Да. Все запросы, в том числе и DML, всегда возвращают результат. Обязательно проверяйте его! Также проверяйте ошибки и предупреждения, которые возвращают запросы. Как правило проблемный запрос ошибочен, но непроверенный результат приводит к тому, что он остался незамеченным. Используйте средства вашего любимого языка программирования для проверки результата и ошибок.

MySQL возвращает следующие данные для DML запросов:


mysql> update system set name='test3' where id=8;

Query OK, 1 row affected (0.55 sec)

Rows matched: 1  Changed: 1  Warnings: 0

Ниже я подробно объясню что обоначает эта информация и дам указания как получить её не только в командной строке, но и в приложении. Я буду использовать синтакс C API. В случае альтернативных коннекторов функции будут называться, скорее всего, аналогично C API вариантам. JDBC, который использует Connector/J и ODBC имеют собственные интерфейсы для получения нужной информации. Используйте их!

Обратите внимание на следующее:


Query OK, N row affected

Запрос выполнен, N строк обновлено.

C API:

Используйте функцию

mysql_affected_rows()

чтобы получить эту информацию в вашем приложении.


Rows matched: M

Найдено M совпадающих строк.

C API:

Функция

mysql_info()

возвращает дополнительную информацию о последнем запросе в виде строки.


Changed: P

Из них изменено P строк. Обратите внимание, что M и P могут отличаться: MySQL замечает, когда обновлять ничего не надо и не делает лишней работы.

C API:

Функция

mysql_info()

возвращает дополнительную информацию о последнем запросе в виде строки.


Warnings: R

Было получено R предупреждений. Предупреждения вы получаете если возникли какие-то проблемы, но запрос тем не менее был выполнен. Обязательно следите за предупреждениями, так как они информируют о потенциальных проблемах.

В вашей программе вы можете использовать следующие функции:

C API:

mysql_info()

- возвращает дополнительную информацию о последнем запросе в виде строки.

mysql_warning_count()

- сколько предупреждений вернул предыдущий запрос

mysql_sqlstate()

- последний SQLSTATE. 0000 обозначает 0 ошибок и предупреждений

Также полезно проверять ошибку. Используйте следующие функции:

C API:

mysql_errno()

- номер ошибки MySQL

mysql_error()

- ошибка в текстовом виде

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

Приём 8: всегда проверяйте результат запроса! Используйте инструменты вашего коннектора или вывод интерактивного клиента.

К сожалению существуют случаи, когда именно незамеченная логическая ошибка в DML запросе приводит к выводу неверных данных. Часто это можно заметить сравнивая значение affected rows с ожидаемым, но иногда его не просто спрогнозировать. В этом случае поможет только приём 7.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 5. Альтернативные способы поиска проблемного запроса.

Я уже писала, что использование general query log ресурсоёмко. Часть проблемы снимается, если использовать новую возможность MySQL версии 5.1: online logging, которое позволяет включать и выключать general query log без остановки сервера.

К сожалению это не панацея: у вас может быть старая версия MySQL сервера, не имеющая такой возможности, general query log может содержать слишком много информации и вам будет трудно найти ошибку, у вас может быть какая-то другая собственная причина.

Что делать, если вы не можете использовать general query log?

Один из вариантов - использовать журналирование средствами вашего приложения. Добавьте код, который будет писать запросы, которые посылает ваше приложение, в log file.

Этот подход имеет то преимущество, что вы сможете тонко настроить вывод: что и как писать. Будет хорошо, если вы будете записывать возвращаемое значение и сообщения об ошибках в тот же лог.

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

Ещё один вариант - использовать прокси, который будет перехватывать запросы и записывать их в файл.

Один из предпочтительных вариантов это MySQL Proxy, поскольку это скриптуемый прокси, предназначенный для работы с сервером MySQL. Он использует MySQL клиент-сервер протокол. Писать скрипты для MySQL Proxy можно на языке програмирования lua.

Ниже приведёг пример реализации general query log при помощи MySQL Proxy:


function read_query( packet )

        if packet:byte() == proxy.COM_QUERY then

                print(os.date("%d%m%g %T") .. "\t"

                .. proxy.connection.server.thread_id

                .."\tQuery\t" .. packet:sub(2))

        end

end

Приведённый скрипт записывает в стандартный вывод все полученные запросы.

Запустить его можно так:


$mysql-proxy --proxy-lua-script=`pwd`/general_log.lua

Вывод будет таким:


$mysql-proxy --proxy-lua-script=`pwd`/general_log.lua 

011109 15:00:24 12      Query   select @@version_comment limit 1

011109 15:00:27 12      Query   SELECT DATABASE()

011109 15:00:27 12      Query   show databases

011109 15:00:27 12      Query   show tables

011109 15:00:30 12      Query   select * from t1

Разумеется, так как MySQL Proxy использует полноценный язык программирования Lua, вы сможете настроить вывод таким образом, чтобы получить необходимую информацию об именно тех запросах которые вам интересны.

Вы также можете использовать MySQL Proxy и для других целей, например, для load balancing. Больше информации здесь: http://dev.mysql.com/doc/refman/5.1/en/mysql-proxy.html и http://forge.mysql.com/wiki/MySQL_Proxy

Примеры скриптов можно найти здесь: http://forge.mysql.com/search.php?k=proxy

Приём 10: используйте MySQL Proxy или любой другой прокси.

Использование предложенных двух вариантов привлекательно ещё и тем, что вы можете тонко настроить вывод и записывать только те запросы, которые вам нужны для дальнейшего анализа.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Часть 2. Конкурентные запросы.

Глава 6. Взаимные блокировки.

В предыдущей части мы рассмотрели каким образом можно найти причину проблемы, если она повторяется всегда. Но бывают случаи, когда проблема возникает только при определённом стечении обстоятельств.

Например, такой простой запрос может выполняться достаточно долго:


mysql> select * from t;

+-----+

| a   |

+-----+

|   0 |

| 256 |

+-----+

2 rows in set (3 min 18.71 sec)

Чаще всего вы обнаруживаете неожиданно медленный запрос в slow query log. В данном случае смущает количество строк в результате.

Может быть это какая-то сложная таблица с множеством индексов? Хотя это не должно играть роли в данном случае.

Нет:


mysql> show create table t\G

************** 1. row **************

       Table: t

Create Table: CREATE TABLE `t` (

  `a` int(10) unsigned NOT NULL AUTO_INCREMENT,

  PRIMARY KEY (`a`)

) ENGINE=MyISAM AUTO_INCREMENT=257 DEFAULT CHARSET=utf8

1 row in set (0.00 sec)

Попробуем тоже самое проделать в консоли:


mysql> select * from t;

+-----+

| a   |

+-----+

|   0 |

| 256 |

+-----+

2 rows in set (0.00 sec)

0 секунд!

В чём же дело? Здесь наш главный помощник - команда SHOW PROCESSLIST:


mysql> show processlist\G

******************* 1. row *******************

     Id: 1311

   User: root

   Host: localhost

     db: test

Command: Query

   Time: 35

  State: Locked

   Info: select * from t

******************* 2. row *******************

     Id: 1312

   User: root

   Host: localhost

     db: test

Command: Query

   Time: 36

  State: User sleep

   Info: update t set a=sleep(200) where a=0

******************* 3. row ******************

     Id: 1314

   User: root

   Host: localhost

     db: NULL

Command: Query

   Time: 0

  State: NULL

   Info: show processlist

3 rows in set (0.00 sec)

В результате мы сразу видим, что интересующий нас запрос ждёт когда будет выполнен другой, требующий большего времени.

Что делать? На уровне приложения разводить запросы по времени: не давать им выполняться одновременно.

Приём 11: используйте SHOW PROCESSLIST чтобы посмотреть список одновременно выполняемых запросов.

Начиная с версии 5.1 INFORMATION_SCHEMA содержит таблицу PROCESSLIST. Вы также можете использовать эту таблицу чтобы посмотреть список запущенных процессов.


mysql> SELECT * FROM PROCESSLIST\G

*************************** 1. row ***************************

     ID: 955

   USER: root

   HOST: localhost

     DB: information_schema

COMMAND: Query

   TIME: 0

  STATE: executing

   INFO: SELECT * FROM PROCESSLIST

1 row in set (0.01 sec)

Это особенно удобно, если у вас одновременно выполняется много запросов и вы хотите отсортировать вывод.

Приём 12: используйте таблицу INFORMATION_SCHEMA.PROCESSLIST если вам нужен отсортированный по какому-либо параметру список одновременных запросов.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Глава 7. Конкурентные транзакции.

Ещё один часто встречающийся пример подобной проблемы - ошибка "Lock wait timeout exceeded" при использовании InnoDB таблиц. Чаще всего достаточно комнды SHOW ENGINE INNODB STATUS, которая покажет последние транзакции. Но вывод этой команды не содержит информации о всех запросах в транзакции, а только о текущем. Что делать если SHOW ENGINE INNODB STATUS не даёт всей информации?


mysql>  insert into t1 values(2,'1994-12-30', '1994-12-03');

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction



mysql> show engine innodb status \G

****************** 1. row ******************

  Type: InnoDB

  Name: 

Status: 

=====================================

091001 15:54:26 INNODB MONITOR OUTPUT

=====================================

Per second averages calculated from the last 15 seconds

....

------------

TRANSACTIONS

------------

Trx id counter 0 295696

Purge done for trx's n:o < 0 295690 undo n:o < 0 0

History list length 4

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 0 0, not started, OS thread id 101121024

MySQL thread id 1314, query id 217 localhost root

show engine innodb status

---TRANSACTION 0 295695, not started, OS thread id 101606912

MySQL thread id 1311, query id 216 localhost root

---TRANSACTION 0 295694, ACTIVE 13 sec, OS thread id 101122048

2 lock struct(s), heap size 320, 1 row lock(s), undo log entries 1



MySQL thread id 1312, query id 215 localhost root

Мы видим здесь информацию о конкурирующей транзакции, но не видим в чём конкретно проблема. General query log снова наш помощник:


mysql> select * from mysql.general_log where  thread_id = 1312 order by  event_time \G

******************* 1. row *******************

  event_time: 2009-10-01 15:54:11

   user_host: root[root] @ localhost []

   thread_id: 1312

   server_id: 51

command_type: Query

    argument: begin

******************* 2. row *******************

  event_time: 2009-10-01 15:54:13

   user_host: root[root] @ localhost []

   thread_id: 1312

   server_id: 51

command_type: Query

    argument: insert into t1 values(2,'1994-12-30', '1994-12-03')

2 rows in set (0.12 sec)

Или проще:


mysql> select argument from mysql.general_log where  thread_id = 1312 order by  event_time;

+-----------------------------------------------------+

| argument                                            |

+-----------------------------------------------------+

| begin                                               |

| insert into t1 values(2,'1994-12-30', '1994-12-03') |

+-----------------------------------------------------+

2 rows in set (0.01 sec)

Что делать? Опять-таки развести запросы по времени.

Приём 13: используйте SHOW ENGINE INNODB STATUS чтобы получить информацию о транзакциях.

Приём 14: используйте general query log если в выводе SHOW ENGINE INNODB STATUS только часть информации о проблемной транзакции.

Содержание

Вперёд

Автор 2009 Света Смирнова
COPYRIGHT © 2009 С.Смирнова и С.Ласунов
sveta_гав_js-client_точка_com

Часть 3. Другие случаи.

Глава 8. Большие объёмы данных.

Часто случается так, что запрос - это всего лишь косвенная причина неправильного поведения, а истинная причина в настройках.

Один из вариантов - маленький max_allowed_packet для передаваемых данных. Переменная MySQL сервера max_allowed_packet определяет максимально возможный объём данных, которые MySQL сервер может получать или отдавать. Размер max_allowed_packet задан в байтах.

Ошибка обычно воспроизводится так:


$mysql51  test <phpconf2009_1.sql

ERROR 1153 (08S01) at line 33: Got a packet bigger than 'max_allowed_packet' bytes

В данном случае всё понятно: сообщение об ошибке однозначно.

Но иногда это воспроизводится так:


$./my sql test <phpconf2009_1.sql

ERROR 1064 (42000) at line 33: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '00000000000000000000000000000000000000000000000000000000000000000000000000000000' at line 2

В то время как вы убеждены, что запрос не содержит синтаксической ошибки. Если вы видите сообщение о синтаксической ошибке в то время как запрос верный, проверяйте значение max_allowed_packet

max_allowed_packet должен быть установлен как для сервера, так и для клиента это разные значения. Также обратите внимание, что max_allowed_packet это значения для запроса целиком, включая SQL, не только для вносимых данных. Отсюда ошибки для запросов типа SELECT REPEAT('a', 10000000);


mysql> \W

Show warnings enabled.

mysql> SELECT REPEAT('A', 10000000);

+-----------------------+

| REPEAT('A', 10000000) |

+-----------------------+

| NULL                  |

+-----------------------+

1 row in set, 1 warning (0.00 sec)



Warning (Code 1301): Result of repeat() was larger than max_allowed_packet (1048576) - truncated

Приём 15: проверяйте значение max_allowed_packet и размер передаваемых данных если сервер выдаёт ошибку для синтаксически правильного запроса.

Содержание

Вперёд

Глава 9. Загадочное исчезновение сервера.

Часто это выглядит так:


$php phpconf2009_3.php

string(26) "MySQL server has gone away"

Код:


$cat phpconf2009_3.php 

<?php

mysql_connect('127.0.0.1:3351', 'root', '');

mysql_select_db('test');

mysql_query('set wait_timeout=1');

$query = 'SELECT 1';

sleep(3);

$result = mysql_query($query);

if (0 != mysql_errno())

    var_dump(mysql_error());

else

    while ($row = mysql_fetch_row($result))

        var_dump($row);

mysql_close();

?>

Перед тем как указать на причину возникновения ошибки мне бы хотелось обратить ваше внимание на несколько сиситемных переменных MySQL сервера. Это переменные, отвечающие за timeout:


mysql> show variables like '%timeout%';

+----------------------------+-------+

| Variable_name              | Value |

+----------------------------+-------+

| connect_timeout            | 10    |

| interactive_timeout        | 28800 |

| net_read_timeout           | 30    |

| net_write_timeout          | 60    |

| wait_timeout               | 28800 |

+----------------------------+-------+

Ниже приведены их описания:


connect_timeout

Сколько ждать ответа сервера перед тем как выдать ошибку о том, что сервер не отвечает.


interactive_timeout

Сколько ждать активности от интерактивного клиента перед тем как разорвать соединение.


wait_timeout

Сколько ждать активности от любого клиента перед тем как разорвать соединение. Если клиент интерактивный и значение interactive_timeout отличается от wait_timeout, то будет использовано значение interactive_timeout.


net_read_timeout

Сколько ждать ответа на запрос SELECT


net_write_timeout

Сколько ждать ответа на запрос, модифицирующий данные.

В приведённом выше примере проблема была в том, что мы ждали слишком долго для предварительно установенного маленького wait_timeout:


mysql_query('set wait_timeout=1');

установленный wait_timeout.


sleep(3);

время ожидания: 3>1, поэтому не удивительно, что мы получили ошибку.

Естественно sleep(3) был добавлен только для наглядности. В случае реального приложения следует обратить внимания на места, где такая задержка может быть вызвана в том числе кодом без использования sleep и подобных функций.

Также проверяйте другие timeout-ы в случае аналогичных ошибок.

Приём 16: проверяйте значение wait_timeout и других timeout-ов, если вы встречаете ошибку "MySQL server has gone away"

Также я хотела бы обратить ваше внимание на то, что вы не всегда получите сообщение "MySQL server has gone away" в случае слишком маленького timeout. Это также может быть сообщение Lost connection to MySQL server at 'reading authorization packet'. Чаще всего такое сообщение говорит о проблеме с connect_timeout.

Для примера я не смогла найти сети с достаточными для повторения проблемы перебоями, поэтому применила отладчик.

Запускаем интерпретатор PHP под отладчиком gdb:


$gdb php

Устанавливаем breakpoint в клиентской функции MySQL C API:


(gdb) b wait_for_data

Breakpoint 1 at 0x4337a: file client.c, line 190.

Передаём имя файла с PHP скриптом интерпретатору:


(gdb) set args phpconf2009_3.php

Запускаем программу:


(gdb) run

Starting program: /usr/local/bin/php phpconf2009_3.php 

Reading symbols for shared libraries .+.................................................................++.++ done

Breakpoint 1 at 0x204e435: file client.c, line 1861.

Reading symbols for shared libraries . done

Breakpoint 1, wait_for_data (fd=6, timeout=60) at client.c:195

195       ufds.fd= fd; client.c:1861

(gdb)

Когда интерпретатор останавливается ждём 11 секунд, что на 1 секунду больше предустановленного значения connect_timeout, затем вводим команду с (продолжить).


(gdb) c

Continuing.

PHP Warning:  mysql_connect(): Lost connection to MySQL server at 'reading authorization packet', system error: 0 in /Users/apple/Documents/www_project/MySQL/Conferences/phpconf2009_3.php on line 2



Warning: mysql_connect(): Lost connection to MySQL server at 'reading authorization packet', system error: 0 in /Users/apple/Documents/www_project/MySQL/Conferences/phpconf2009_3.php on line 2

В результате иы получили ошибку Lost connection to MySQL server at 'reading authorization packet', что говорит о слишком маленьком connect_timeout

Что делать?

Проблемы с connect_timeout чаще всего свидетельствуют либо о нестабильной работе сети между клиентом и MySQL сервером, либо о том, что машина, на которой запущен MySQL сервер, перегружена.

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

Не увеличивайте connect_timeout без необходимости: никому не пронравится ждать слишком долго!

Приём 17: проверяйте значение connect_timeout в случае ошибки Lost connection to MySQL server at 'reading authorization packet'

Содержание

Вперёд

Послесловие

В заключении хотелось бы повторить те приёмы, которые мы рассмотрели. К сожалению остались ещё неосвещённые моменты. Я буду рада узнать чтобы ещё хотелось осветить. Я жду ваших замечаний по адресу sveta_точка_smirnova_гав_sun_точка_com или sveta_гав_js-client_точка_com

Список приёмов.

Приём 1: используйте оператор вывода для вывода запроса в том виде, в котором его получает СУБД.

Приём 6: преобразуйте DML запросы в соответствующий SELECT чтобы выяснить какие строки будут изменены.

Приём 7: проверяйте ваш сценарий шаг за шагом в обратном порядке пока не найдёте проблемный запрос.

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

Приём 10: используйте MySQL Proxy или любой другой прокси.

Приём 11: используйте SHOW PROCESSLIST чтобы посмотреть список одновременно выполняемых запросов.

Приём 13: используйте SHOW ENGINE INNODB STATUS чтобы получить информацию о транзакциях.

Приём 14: используйте general query log если в выводе SHOW ENGINE INNODB STATUS только часть информации о проблемной транзакции.

Приём 16: проверяйте значение wait_timeout и других timeout-ов, если вы встречаете ошибку "MySQL server has gone away"

Приём 17: проверяйте значение connect_timeout в случае ошибки Lost connection to MySQL server at 'reading authorization packet'

Приём 18: всегда используйте error log

Приём 19: используйте general query log если error log не содержит информации о причинах крушения сервера.

Приём 20: всегда проверяйте достаточно ли у вас RAM для выделенных буферов.

Приём 21: устанавливайте значение max_connections таким какое вы сможете обслужить.

Приём 23: Используйте опцию log_warnings=2 чтобы отследить имеются ли у вас отклонённые соединения.

Приём 24: проверяйте запросы на сервере, запущенном с опцией no-defaults и сравнивайте результат.

Приём 25: если творится что-то непонятное, первым делом проверьте записи в error log.

Приём 26: насторйте InnoDB Monitor чтобы иметь в error log информацию о всех транзакциях с применением InnoDB таблиц.

Приём 27: используйте slow query log чтобы выявить медленные запросы.

Приём 28: используйте MySQL Sandbox, чтобы быстро и удобно оттестировать ваше приложение на нескольких версиях MySQL.

Содержание

Вперёд

От автора

Я работаю инженером технической поддержки в MySQL Bugs Analysis Support Group.

В своей работе я часто наблюдаю ситуации, когда люди, успешные в каком-либо языке программирования, испытывают трудности при отладке SQL. Под отладкой я прежде всего понимаю поиск ошибки. Существует несколько приёмов, позволяющих сузить круг возможных причин неправильного поведения SQL приложения, используя которые можно выявить ошибку. Я не буду подробно останавливаться на способах устранения проблемы с тем чтобы сконцентрироваться именно на приёмах её выявления. Также необходимо учесть, что большинство ошибок в программировании предполагают более одного решения и какое выбрать дело вкуса или, если хотите, архитектуры приложения. Я буду давать лишь общие рекомендации.

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

В качестве примера будет взят MySQL, также будет рассказано о возможностях именно MySQL. Тем не менее общие рекомендации применимы к большинству реляционных СУБД.

Впервые я выступала с этой темой на PHPConf в Москве в 2009 году. Это был мастер-класс, после которого я получила множество вопросов. Желание дать дополнительный материал по этим вопросам и привело меня к решению оформить тему в виде масштабного текста.

Содержание

Вперёд

Ссылки на использованные продукты и торговые марки.

Содержание

Промежуточные итоги.

Старайтесь всегда найти запрос, вызывающий нежелаемое поведение.
Анализируйте что неправильно, в соответствии с результатом устраняйте проблему.
Используйте выделенные приёмы для анализа результатов.

Содержание

Вперёд

Итоги.

Суммируя описанное в данной части хотелось бы порекомендовать следующее:

Старайтесь всегда найти запрос, вызывающий нежелаемое поведение

Используйте логи:

General query log
Логи в вашем приложении
MySQL Proxy или любой другой прокси
Другие

Анализируйте что неправильно, в соответствии с результатом устраняйте проблему

Ниже приведен список приёмов, которые мы рассмотрели в первой части.

Приём 1: используйте оператор вывода для вывода запроса в том виде, в котором его получает СУБД.

Приём 6: преобразуйте DML запросы в соответствующий SELECT чтобы выяснить какие строки будут изменены.

Приём 7: проверяйте ваш сценарий шаг за шагом в обратном порядке пока не найдёте проблемный запрос.

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

Приём 10: используйте MySQL Proxy или любой другой прокси.

Содержание

Вперёд

Итоги:

Проверьте, не блокирован ли запрос другими запросами

Используйте SHOW PROCESSLIST

Используйте SHOW ENGINE INNODB STATUS чтобы просмотреть информацию о транзакциях, в которых были задействованы InnoDB таблицы.

Анализируйте неправильный результат и в соответствии с результатом анализа устраняйте проблему.

Ниже приведен список приёмов, которые мы рассмотрели во второй части.

Приём 11: используйте SHOW PROCESSLIST чтобы посмотреть список одновременно выполняемых запросов.

Приём 13: используйте SHOW ENGINE INNODB STATUS чтобы получить информацию о транзакциях.

Приём 14: используйте general query log если в выводе SHOW ENGINE INNODB STATUS только часть информации о проблемной транзакции.

Содержание

Вперёд

Итоги.

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

Я хотела бы обратить ваше внимание на то, что мы рассмотрели только наиболее часто встречающиеся случаи в то время как MySQL сервер имеет много параметров, каждый из которых может влиять на поведение приложения. Анализируйте параметры, которые вы применяете. Один из приёмов: запустить тот же запрос, используя MySQL сервер, запущенный с опцией no-defaults и посмотреть отличается ли результат. Если результат отличается, проанализируйте влияние параметра ещё раз и исправьте проблему.

Приём 24: проверяйте запросы на сервере, запущенном с опцией --no-defaults и сравнивайте результат.

Ниже приведён список приёмов, рассмотренных в этой части.

Приём 16: проверяйте значение wait_timeout и других timeout-ов, если вы встречаете ошибку "MySQL server has gone away"

Приём 17: проверяйте значение connect_timeout в случае ошибки Lost connection to MySQL server at 'reading authorization packet'

Приём 18: всегда используйте error log

Приём 19: используйте general query log если error log не содержит информации о причинах крушения сервера.

Приём 20: всегда проверяйте достаточно ли у вас RAM для выделенных буферов.

Приём 21: устанавливайте значение max_connections таким какое вы сможете обслужить.

Приём 23: Используйте опцию log_warnings=2 чтобы отследить имеются ли у вас отклонённые соединения.

Приём 24: проверяйте запросы на сервере, запущенном с опцией --no-defaults и сравнивайте результат.

Содержание

Вперёд

Итоги.

В последней части мы рассмотрели приёмы работы при тестировании проблем на рабочем сервере. Повторим их:

Приём 25: если творится что-то непонятное, первым делом проверьте записи в error log.

Приём 26: насторйте InnoDB Monitor чтобы иметь в error log информацию о всех транзакциях с применением InnoDB таблиц.

Приём 27: используйте slow query log чтобы выявить медленные запросы.

Приём 28: используйте MySQL Sandbox, чтобы быстро и удобно оттестировать ваше приложение на нескольких версиях MySQL.

Содержание

Вперёд