English Version

Глава 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 - отказ в доступе к оперативной памяти. Точно можно посмотреть в документации к вашей операционной системе: man signal в UNIX. В Windows вы обычно получите запись вроде "mysqld got exception 0xc0000005". Коды исключений Windows ищите в системной документации.

Также вы можете получить ошибку наподобие этой:

100828 21:52:31 InnoDB: Error: cannot allocate 8589950976 bytes of
InnoDB: memory with malloc! Total allocated memory
InnoDB: by InnoDB 46483728 bytes. Operating system errno: 12

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

$perror 12
OS error code 12: Cannot allocate memory

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

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

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