SQLinfo.ru - Все о MySQL

Форум пользователей MySQL

Задавайте вопросы, мы ответим

Вы не зашли.

#1 30.03.2015 12:05:49

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

И снова о server has gone away :)

Активно работаем простыми запросами:

UPDATE `some_table` SET `cost`='1.00', `status`='ENROUTE', `sended`='2015-03-30 10:52:47' WHERE `msg_id`='6c06c407-5519-0e2a-5550-4d810c2683f1';

SHOW TABLES FROM `users` LIKE 'some_table2';

Самый злостный нарушитель:
SELECT `id`,`table`,`msg_id` FROM `some_table3` WHERE `action`='delete';

Первые два запроса попадают на "server has gone away" реже, а вот последний - очень часто, возможно даже каждую секунду. Рассмотрим его ситуацию.

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

Структура таблички:
CREATE TABLE IF NOT EXISTS `users` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  `table` varchar(16) NOT NULL COMMENT 'Таблица пользователя',
  `timestamp` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT 'Дата и время вставки последней записи',
  `action` enum('insert','delete') NOT NULL DEFAULT 'insert',
  `msg_id` char(36) NOT NULL DEFAULT ''
) ENGINE=MEMORY  DEFAULT CHARSET=utf8 COMMENT='Пользователи шлюза, таблицы которых надо обработать';

ALTER TABLE `users`
ADD PRIMARY KEY (`id`), ADD UNIQUE KEY `row` (`table`,`action`,`msg_id`);

Статистика подключений за почти 5 суток (общее количество, примерно в час, % от общего):

Максимально одновременных    183
Неудачных попыток    11.1 k    95.45     0.84%
Прерваны    22.2 k    191.18     1.68%
Всего    1,320 k    11.36 k    100.00%

С чего начинать? Табличку на диск переносить не хочется из-за большой активности.

ЗЫ MySQL работает в VZ контейнере, общий LA сервера составляет порядка 2.


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#2 30.03.2015 12:41:19

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

Что написано в логе (системный и mysqld) относительно причины "gone away"? Может ли быть так, что не хватает памяти и процесс mysqld убивается.

Неактивен

 

#3 30.03.2015 13:01:15

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

В логах ни слова об этом. В сислоге от мускля совсем никогда ничего, в мускльном логе только мусор от запуска демона. Или речь о логе запросов? Аптайм сервера почти 5 дней, при убивании процесса, на сколько я понимаю, этот счётчик времени тоже сбросился бы.

Выхлоп лога запуска сервера:
2015-Mar-25 14:52:35 :: startup
150325 14:52:35 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
150325 14:52:35 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
150325 14:52:35 [Note] Server socket created on IP: '0.0.0.0'.
150325 14:52:35 [Note] Plugin 'FEDERATED' is disabled.
150325 14:52:35 InnoDB: The InnoDB memory heap is disabled
150325 14:52:35 InnoDB: Mutexes and rw_locks use GCC atomic builtins
150325 14:52:35 InnoDB: Compressed tables use zlib 1.2.7
150325 14:52:35 InnoDB: Initializing buffer pool, size = 128.0M
150325 14:52:35 InnoDB: Completed initialization of buffer pool
150325 14:52:35 InnoDB: highest supported file format is Barracuda.
150325 14:52:47  InnoDB: Waiting for the background threads to start
150325 14:52:52 InnoDB: 5.5.30 started; log sequence number 80674041251
150325 14:52:53 [Warning] 'user' entry 'root@some.service.ua' ignored in --skip-name-resolve mode.
150325 14:52:53 [Warning] 'user' entry '@some.service.ua' ignored in --skip-name-resolve mode.
150325 14:52:53 [Warning] 'proxies_priv' entry '@ root@some.service.ua' ignored in --skip-name-resolve mode.
150325 14:52:53 [Note] Event Scheduler: Loaded 0 events
150325 14:52:53 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.30-alt3'  socket: '/mysql.sock'  port: 3306  (ALT Linux)


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#4 30.03.2015 13:20:13

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

Это похоже на багу движка MEMORY.

Неактивен

 

#5 30.03.2015 13:45:02

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

Тоже нет, сделал табличку типом InnoDB, ничего не изменилось. Примечательно то, что выборки из этой таблицы всегда либо с `action`='delete', либо с `action`='insert', при этом я не помню, бывала ли когда-нибудь ошибка при `action`='insert'. Сейчас думаю сменить тип столбца `action` на varchar, может будет какой-то результат.

ЗЫ Запрос SELECT `column_name`, `table_name`,`table_schema` FROM `information_schema`.`key_column_usage`для этой таблицы длился где-то 3-4 минуты со статусом "Opening tables", это вроде не нормально. Текущее состояние "Opened tables" равно 321к, table_open_cache = 400. Увеличивать? На сколько? Могло ли это повлиять на поведение с ошибкой?

Отредактированно Neval (30.03.2015 13:46:18)


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#6 30.03.2015 13:47:58

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

Какое значение wait_timeout? Opening tables - это ненормально, увеличьте table_open_cache до такого значения, чтобы Opened tables не росло.

Неактивен

 

#7 30.03.2015 13:56:22

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

wait_timeout = 60
Увеличил table_open_cache до 10к. А текущие счётчики как-то можно сбросить, чтобы не передёргивать демон?


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#8 30.03.2015 14:16:19

paulus
Администратор
MySQL Authorized Developer and DBA
Зарегистрирован: 22.01.2007
Сообщений: 6757

Re: И снова о server has gone away :)

Я бы еще посмотрел на net_read_timeout / net_write_timeout. По косвенным признакам, база
сильно нагружена (это стоит проверить), скорее всего, по диску. Gone away может быть следст-
вием того, что срабатывают таймауты на получение запроса-ответа.

Неактивен

 

#9 30.03.2015 14:23:08

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

wait_timeout = 60 значит, что через минуту выполнения запрос будет таким образом отключен

Неактивен

 

#10 30.03.2015 14:35:28

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

paulus написал:

Я бы еще посмотрел на net_read_timeout / net_write_timeout.

30 / 60

paulus написал:

По косвенным признакам, база
сильно нагружена (это стоит проверить), скорее всего, по диску. Gone away может быть следст-
вием того, что срабатывают таймауты на получение запроса-ответа.

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

rgbeast написал:

wait_timeout = 60 значит, что через минуту выполнения запрос будет таким образом отключен

Да, но учитывая количество ошибок, этот параметр не актуален. Понаблюдал, на глаз получилось где-то 50-80 отказов в секунду. Наверное надо какой-то слип добавить))


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#11 30.03.2015 15:05:17

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

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

Отредактированно Neval (30.03.2015 15:05:36)


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#12 31.08.2015 11:54:23

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

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


mysql> show variables like '%timeout%';
+----------------------------+----------+
| Variable_name              | Value    |
+----------------------------+----------+
| connect_timeout            | 10       |
| delayed_insert_timeout     | 300      |
| innodb_lock_wait_timeout   | 500      |
| innodb_rollback_on_timeout | OFF      |
| interactive_timeout        | 28800    |
| lock_wait_timeout          | 31536000 |
| net_read_timeout           | 30       |
| net_write_timeout          | 60       |
| slave_net_timeout          | 3600     |
| wait_timeout               | 28800    |
+----------------------------+----------+
10 rows in set (0.00 sec)
 


При этом, есть вот такой зверь:

mysql> show processlist;
+----------+-----------+----------------+-------+---------+---------+-------+------------------+
| Id       | User      | Host           | db    | Command | Time    | State | Info             |
+----------+-----------+----------------+-------+---------+---------+-------+------------------+
| 46231716 | some_user | *.*.*.*:33988  | users | Sleep   | 1860546 |       | NULL             |
| 46456192 | some_user | *.*.*.*:60323  | users | Sleep   | 1812343 |       | NULL             |
| 46536374 | some_user | *.*.*.*:38878  | users | Sleep   | 1800558 |       | NULL             |
| 46881579 | some_user | *.*.*.*:37724  | users | Sleep   | 1730489 |       | NULL             |
| 46893109 | some_user | *.*.*.*:38155  | users | Sleep   | 1728935 |       | NULL             |
| 46965596 | some_user | *.*.*.*:39430  | users | Sleep   | 1718509 |       | NULL             |
| 47339865 | some_user | *.*.*.*:49135  | users | Sleep   | 1646464 |       | NULL             |
| 47347136 | some_user | *.*.*.*:54802  | users | Sleep   | 1645728 |       | NULL             |
| 47981048 | some_user | *.*.*.*:60921  | users | Sleep   | 1545669 |       | NULL             |
| 48327795 | some_user | *.*.*.*:38719  | users | Sleep   | 1472323 |       | NULL             |
| 48360430 | some_user | *.*.*.*:33984  | users | Sleep   | 1468684 |       | NULL             |
| 48393544 | some_user | *.*.*.*:39907  | users | Sleep   | 1464715 |       | NULL             |
| 48400008 | some_user | *.*.*.*:43256  | users | Sleep   | 1463929 |       | NULL             |
| 49679323 | some_user | *.*.*.*:47146  | users | Sleep   | 1193299 |       | NULL             |
| 49690534 | some_user | *.*.*.*:39847  | users | Sleep   | 1191462 |       | NULL             |
| 50113145 | some_user | *.*.*.*:60114  | users | Sleep   | 1109604 |       | NULL             |
 

Адреса клиентов скрыты. Почему они так долго висят при текущих настройках таймаутов?


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#13 31.08.2015 12:49:47

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

Они должны были бы остановиться по wait_timeout, если были бы неактивны в течение 28800 секунд. Можно предположить, что они так долго не простаивают и регулярно выполняют запросы. wait_timeout применяется к периоду ожидания, а не к полному времени исполнения

Неактивен

 

#14 31.08.2015 13:20:55

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

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

Если на сессию, то не может ведь быть ситуаций, когда запросы периодически выполняются, а время слипа при этом не сбрасывается roll У самой первой сессии слип, получается, висит уже 21 день, тут уже наверное с любыми настройками должно соединение закрываться)))


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#15 31.08.2015 17:04:29

rgbeast
Администратор
MySQL Authorized Developer and DBA
Откуда: Москва
Зарегистрирован: 21.01.2007
Сообщений: 3880

Re: И снова о server has gone away :)

Да, точно, должны были закрыться. Непонятно почему не закрылись.

Неактивен

 

#16 31.08.2015 18:47:34

paulus
Администратор
MySQL Authorized Developer and DBA
Зарегистрирован: 22.01.2007
Сообщений: 6757

Re: И снова о server has gone away :)

А клиент после подключения не может себе выставить таймаут побольше?
И еще — соединения реально живые? Может, по ним, например, ping бегает?

Неактивен

 

#17 01.09.2015 17:27:50

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

paulus написал:

А клиент после подключения не может себе выставить таймаут побольше?

Не должен, там права только на чтение одной таблицы и запись в некоторые её поля, и усё. Возможно, конечно же, мы чего-то не знаем)))
Пользователей много, подобная ситуация замечена только с одним. Он периодически подключается заново, может как-то с этим связано?

paulus написал:

И еще — соединения реально живые? Может, по ним, например, ping бегает?

Мммм, впервые слышу про такого зверя в контексте СУБД. Пинг обычный, сетевой?


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#18 01.09.2015 18:23:14

paulus
Администратор
MySQL Authorized Developer and DBA
Зарегистрирован: 22.01.2007
Сообщений: 6757

Re: И снова о server has gone away :)

Можно посмотреть на netstat его соединений? Очень хочется понять, что думает сетевой стек про эти соединения, и бегают ли по ним пакеты в принципе.

https://dev.mysql.com/doc/refman/5.6/en/mysql-ping.html — вот этот. Тот, который внутри протокола.

Просто эта штука выглядит сильно как бага, но, чтобы признать багой, надо исключить «плохого клиента», который написал собственный коннектор, который говорит "SET wait_timeout=1000000" после старта ;-)

Неактивен

 

#19 03.09.2015 04:53:48

LazY
_cмельчак
MySQL Authorized Developer and DBA
Зарегистрирован: 02.04.2007
Сообщений: 849

Re: И снова о server has gone away :)

Neval написал:

У самой первой сессии слип, получается, висит уже 21 день

А на клиенте случайно не используется ли persistent connection?

Неактивен

 

#20 05.09.2015 19:14:46

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

LazY написал:

А на клиенте случайно не используется ли persistent connection?

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

ЗЫ А вообще, все клиенты стучатся из внешнего мира. Для них возможно постоянное соединение?


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#21 05.09.2015 19:23:46

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

paulus написал:

https://dev.mysql.com/doc/refman/5.6/en/mysql-ping.html — вот этот. Тот, который внутри протокола.

Почитал, почти ничего не понял))) Понял только одно - это надо дёргать на клиенте, который висит в слипе. Но у меня же нет доступа к тому подключению, у меня рут smile


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#22 05.09.2015 19:26:57

Neval
Гуру
Откуда: Киев
Зарегистрирован: 11.03.2008
Сообщений: 449

Re: И снова о server has gone away :)

paulus написал:

Можно посмотреть на netstat его соединений?

Не подскажете пример аргументов для нашего случая? Не могу понять что нужно увидеть))


Человек без чувства юмора - не серьёзный человек wink

Неактивен

 

#23 06.09.2015 00:52:06

paulus
Администратор
MySQL Authorized Developer and DBA
Зарегистрирован: 22.01.2007
Сообщений: 6757

Re: И снова о server has gone away :)

Про нетстат. Допустим, у нас есть вот такая строка

| 6107 | root | 127.0.0.1:49054 | NULL | Query   |    0 | NULL  | show processlist |

Она говорит об открытом соединении с 127.0.0.1:49054. Нужно посмотреть на это соединение с точки зрения операционной системы. Хочу увидеть, что соединение открыто, и что по нему бегают пакетики. Например, так:
# netstat -an | grep 49054
tcp        0      0 127.0.0.1:3306          127.0.0.1:49054         ESTABLISHED

и
# tcpdump -i any -n port 49054
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes
00:48:58.169536 IP 127.0.0.1.49054 > 127.0.0.1.3306: Flags [P.], seq 3035462416:3035462429, ack 3029728040, win 273, options [nop,nop,TS val 2257323614 ecr 2257312773], length 13


Для tcpdump можно сделать -w filename, чтобы он записал в файлик, чтобы не следить за консолькой.


Про persistent connection — разумеется, раз соединение висит, оно persistent. Вопрос ведь не в том, что оно висит, а в том, что оно не убивается легко.

Если хочется таки поубивать, а разбираться лениво, то pt-kill хорошо справится.

Неактивен

 

Board footer

Работает на PunBB
© Copyright 2002–2008 Rickard Andersson