MySQL server has gone away

[max1985]

Здравствуйте! Подскажите что может быть не так. При переходе на страницу товара, иногда выдает 500 ошибку. В логах такое:

PHP Fatal error:  Uncaught Exception: Error: MySQL server has gone away<br />Error No: 2006<br />SELECT * FROM product_discount WHERE product_id = '183' AND customer_group_id = '1' AND quantity > 1 AND ((date_start = '0000-00-00' OR date_start < NOW()) AND (date_end = '0000-00-00' OR date_end > NOW())) ORDER BY quantity ASC, priority ASC, price ASC in /system/library/db/mysqli.php:40\nStack trace:\n#0 /system/library/db.php(16): DB\\MySQLi->query('SELECT * FROM o...', Array)\n#1 /system/storage/modification/catalog/model/catalog/product.php(383): DB->query('SELECT * FROM o...')\n#2 /system/storage/modification/system/engine/loader.php(207): ModelCatalogProduct->getProductDiscounts('183')\n#3 /system/engine/proxy.php(25): Loader->{closure}(Array, Array)\n#4 /system/storage/ in /system/library/db/mysqli.php on line 40, referer: https://senaoru.fvds.ru/unifi-switch-8-150w

Это VPS. На сервере два сайта. Один рабочий, который работает на Opencart 2.0. А второй просто залил новый движек OCstory 2.3 и перенес туда базу товаров и категорий.

Так вот эта проблемы возникает на новом движке.

Думал проблема с запросом, но посмотрел в фалах и оказалось что запросы на обоих сайтах одинаковые:

"SELECT * FROM " . DB_PREFIX . "product_discount WHERE product_id = '" . (int)$product_id . "' AND customer_group_id = '" . (int)$this->config->get('config_customer_group_id') . "' AND quantity > 1 AND ((date_start = '0000-00-00' OR date_start < NOW()) AND (date_end = '0000-00-00' OR date_end > NOW())) ORDER BY quantity ASC, priority ASC, price ASC"

Помогите советом! Спасибо!

[snastik]

Донастраивать вам надо сервер.

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

[max1985]

47 минут назад, snastik сказал:

Донастраивать вам надо сервер.

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

Так это и есть ошибка из лога... Или другой лог нужен?

[snastik]

15 минут назад, max1985 сказал:

Так это и есть ошибка из лога... Или другой лог нужен?

Я же написал. Системный лог - а не лог магазина.
Скорее всего ошибки работы базы у вас пишутся в какой-нибудь серврный лог типа message.

[max1985]

40 минут назад, snastik сказал:

Я же написал. Системный лог - а не лог магазина.
Скорее всего ошибки работы базы у вас пишутся в какой-нибудь серврный лог типа message.

В messages что-то явно не то...

 

Nov  8 15:22:26 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Unban 158.69.194.115
Nov  8 15:22:27 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 122.154.225.202
Nov  8 15:22:34 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Unban 178.128.162.10
Nov  8 15:22:42 senaoru fail2ban.filter[1262]: INFO [exim-iptables] Found 46.38.144.202
Nov  8 15:22:52 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 178.128.162.10
Nov  8 15:22:52 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 178.128.162.10
Nov  8 15:22:54 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 178.128.162.10
Nov  8 15:22:57 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 157.245.62.6
Nov  8 15:22:57 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 157.245.62.6
Nov  8 15:22:58 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Ban 157.245.62.6
Nov  8 15:22:58 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 157.245.62.6
Nov  8 15:23:11 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 181.221.192.113
Nov  8 15:23:13 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 181.221.192.113
Nov  8 15:23:14 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Ban 181.221.192.113
Nov  8 15:23:31 senaoru fail2ban.filter[1262]: INFO [exim-iptables] Found 46.38.144.202
Nov  8 15:23:32 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Unban 162.243.59.16
Nov  8 15:23:48 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 80.211.132.145
Nov  8 15:23:48 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 80.211.132.145
Nov  8 15:23:51 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 80.211.132.145
Nov  8 15:23:51 senaoru fail2ban.filter[1262]: INFO [exim-iptables] Found 185.36.81.248
Nov  8 15:23:51 senaoru fail2ban.actions[1262]: NOTICE [ssh-iptables] Ban 80.211.132.145
Nov  8 15:24:11 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 162.243.59.16
Nov  8 15:24:11 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 162.243.59.16
Nov  8 15:24:13 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 162.243.59.16
Nov  8 15:24:22 senaoru fail2ban.filter[1262]: INFO [exim-iptables] Found 46.38.144.202
Nov  8 15:24:30 senaoru fail2ban.filter[1262]: INFO [exim-iptables] Found 185.36.81.245
Nov  8 15:24:31 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 58.222.107.253
Nov  8 15:24:33 senaoru fail2ban.filter[1262]: INFO [ssh-iptables] Found 58.222.107.253

 

А вот в mysqld.log есть такое, но не пойму что к чему

191108 10:08:32 [Note] Event Scheduler: Purging the queue. 0 events
191108 10:08:32  InnoDB: Starting shutdown...
191108 10:08:34  InnoDB: Shutdown completed; log sequence number 167304291
191108 10:08:34 [Note] /usr/libexec/mysqld: Shutdown complete

191108 10:10:31 [Note] Plugin 'FEDERATED' is disabled.
191108 10:10:31 InnoDB: The InnoDB memory heap is disabled
191108 10:10:31 InnoDB: Mutexes and rw_locks use GCC atomic builtins
191108 10:10:31 InnoDB: Compressed tables use zlib 1.2.3
191108 10:10:31 InnoDB: Using Linux native AIO
191108 10:10:31 InnoDB: Initializing buffer pool, size = 128.0M
191108 10:10:31 InnoDB: Completed initialization of buffer pool
191108 10:10:31 InnoDB: highest supported file format is Barracuda.
191108 10:10:31  InnoDB: Waiting for the background threads to start
191108 10:10:32 InnoDB: 5.5.62 started; log sequence number 167304291
191108 10:10:32 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
191108 10:10:32 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
191108 10:10:32 [Note] Server socket created on IP: '0.0.0.0'.
191108 10:10:32 [Note] Event Scheduler: Loaded 0 events
191108 10:10:32 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.62'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) by Remi
191108 12:34:56 [Note] /usr/libexec/mysqld: Normal shutdown

Буду признателен за помощь в разгребании этого!

Змінено 8 листопада 2019 користувачем max1985

[snastik]

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

[max1985]

11 минут назад, snastik сказал:

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

Вот мой конфиг /etc/my.cnf

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
symbolic-links=0

skip-external-locking
key_buffer_size = 16M
max_allowed_packet = 64M
table_open_cache = 64
sort_buffer_size = 512K
net_buffer_length = 8K
read_buffer_size = 256K
read_rnd_buffer_size = 512K
myisam_sort_buffer_size = 8M

#innodb_use_native_aio = 0
innodb_file_per_table

max_connections=70
max_user_connections=30
wait_timeout=10
interactive_timeout=50
long_query_time=5

#slow_query_log=1
#slow_query_log_file=/var/log/mysql-slow-queries.log



[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

#
# include all files from the config directory
#
!includedir /etc/my.cnf.d

Я так понимаю логи пишутся сюда /var/log/mysqld.log?

[snastik]

1 час назад, max1985 сказал:

Вот мой конфиг /etc/my.cnf

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
symbolic-links=0

skip-external-locking
key_buffer_size = 16M
max_allowed_packet = 64M
table_open_cache = 64
sort_buffer_size = 512K
net_buffer_length = 8K
read_buffer_size = 256K
read_rnd_buffer_size = 512K
myisam_sort_buffer_size = 8M

#innodb_use_native_aio = 0
innodb_file_per_table

max_connections=70
max_user_connections=30
wait_timeout=10
interactive_timeout=50
long_query_time=5

#slow_query_log=1
#slow_query_log_file=/var/log/mysql-slow-queries.log



[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

#
# include all files from the config directory
#
!includedir /etc/my.cnf.d

Я так понимаю логи пишутся сюда /var/log/mysqld.log?

 

Mysql - это демон фоновый процесс.
Ошибки свое работы он пишет в свои логи, но если случается что то с ним самим, если его убивают службы операционной системы, которые следят за расходованием ресурсов - что он может написать в свои логи, если он сдох ?
Соответственно ошибку вам надо искать не в логах самого mysql сервера а в системных логах.
И скорее всего проблема будет в нехватке памяти.

[esculapra]

3 часа назад, max1985 сказал:

product_id = '" . (int)$product_id . "'

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

date_start = '0000-00-00' OR date_start < NOW() -  обрати внимание на NOW() 

Отсеки из запроса.

Я часто туплю в этих функциях, поэтому для своих (не опенкарт) проектов храню данные как интежер (получая из пхп UNIX-timestamp).

[esculapra]

3 часа назад, max1985 сказал:

А второй просто залил новый движек OCstory 2.3

Не, инсталлируй нормально OCstory, а потом имплртируй БД

[max1985]

9 часов назад, esculapra сказал:

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

date_start = '0000-00-00' OR date_start < NOW() -  обрати внимание на NOW() 

Отсеки из запроса.

Я часто туплю в этих функциях, поэтому для своих (не опенкарт) проектов храню данные как интежер (получая из пхп UNIX-timestamp).

Отсек этот запрос. Действительно бесполезный... Дату начала никогда не ставлю.

Но проблема не ушла, хотя стала появляться реже...

[max1985]

8 часов назад, esculapra сказал:

Не, инсталлируй нормально OCstory, а потом имплртируй БД

Так и делал. Сначала установил чистый двиг, потом по одной таблице переносил данные, учитывая что у некотрых таблиц разная структура.

[max1985]

9 часов назад, snastik сказал:

 

Mysql - это демон фоновый процесс.
Ошибки свое работы он пишет в свои логи, но если случается что то с ним самим, если его убивают службы операционной системы, которые следят за расходованием ресурсов - что он может написать в свои логи, если он сдох ?
Соответственно ошибку вам надо искать не в логах самого mysql сервера а в системных логах.
И скорее всего проблема будет в нехватке памяти.

С памятью по идее все ок. На сервере 2ГБ и 4ГБ под Swap

А логов так и не нашел. Может Вы визуально из списка поймете где они?

Еще включил вывод ошибок, когда происходит падение, на сайте вылазит ошибка

Warning: Error while sending QUERY packet. PID=13278 in /home/admin/web/senaoru.fvds.ru/public_html/system/library/db/mysqli.php on line 18

Warning: Error while sending QUERY packet. PID=13278 in /system/library/db/mysqli.php on line 18

 

Змінено 9 листопада 2019 користувачем max1985

[100napb]

13 hours ago, max1985 said:

MySQL server has gone away<br />Error No: 2006

 

11 hours ago, max1985 said:

Вот мой конфиг /etc/my.cnf

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

 

попробуйте изменить в конфигах параметр wait_timeout и увеличить его хотя бы до 30сек, например. У Вас он сейчас 10. Вдруг.. )

 

и да. Как Вам писали выше: изучите файл системного лога центоса (message.log который). А именно: попытайтесь сопоставить время ошибки со временем событий из него - вдруг проглядели.

[SooR]

15 часов назад, max1985 сказал:

Думал проблема с запросом, но посмотрел в фалах и оказалось что запросы на обоих сайтах одинаковые:

И набор данных тоже одинаковый?

Попробуйте выполнить этот запрос в проблемную базу из phpmyadmin или другого менеджера БД

SELECT * FROM product_discount WHERE product_id = '183' AND customer_group_id = '1' AND quantity > 1 AND ((date_start = '0000-00-00' OR date_start < NOW()) AND (date_end = '0000-00-00' OR date_end > NOW())) ORDER BY quantity ASC, priority ASC, price ASC

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

Также пробуйте поочередно убирать условия поиска, начиная с самых "весомых".

[max1985]

1 час назад, 100napb сказал:

 

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

 

попробуйте изменить в конфигах параметр wait_timeout и увеличить его хотя бы до 30сек, например. У Вас он сейчас 10. Вдруг.. )

 

и да. Как Вам писали выше: изучите файл системного лога центоса (message.log который). А именно: попытайтесь сопоставить время ошибки со временем событий из него - вдруг проглядели.

В принципе так и есть, некоторые товары открываются быстро, другие нет... И если загрузка превышает 10сек, то вылазит ошибка. Сейчас поставил 30 сек, ошибка не вылазит, но есть страницы которые грузятся долго. Думаю это не совсем правильное решение проблемы. Тут наверное что-то не так на серваке настроено...

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

[max1985]

50 минут назад, SooR сказал:

И набор данных тоже одинаковый?

Попробуйте выполнить этот запрос в проблемную базу из phpmyadmin или другого менеджера БД

SELECT * FROM product_discount WHERE product_id = '183' AND customer_group_id = '1' AND quantity > 1 AND ((date_start = '0000-00-00' OR date_start < NOW()) AND (date_end = '0000-00-00' OR date_end > NOW())) ORDER BY quantity ASC, priority ASC, price ASC

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

Также пробуйте поочередно убирать условия поиска, начиная с самых "весомых".

https://prnt.sc/pukw4y Вроде норм.

А что значит поочередно убирать условия поиска?

Змінено 9 листопада 2019 користувачем max1985

[SooR]

16 часов назад, max1985 сказал:

иногда выдает 500 ошибку

Значит ключевое слово - иногда

Падает всегда на этом запросе? Может в параллели какое-то обновление идет, тяжелые запросы импорта, карты сайта и т.д. Только логи или запрашивайте show full processlist в бд во время тяжелых операций или обновления.

[max1985]

19 минут назад, SooR сказал:

Значит ключевое слово - иногда

Падает всегда на этом запросе? Может в параллели какое-то обновление идет, тяжелые запросы импорта, карты сайта и т.д. Только логи или запрашивайте show full processlist в бд во время тяжелых операций или обновления.

Именно на этом запросе, но с разными товарами... Никакого импорта и ничего такого не делаю.

Делаю так: чищу кеш и начинаю  переходить с одного товара на другай... В итоге бац!

Warning: Error while sending QUERY packet. PID=13278 in /system/library/db/mysqli.php on line 18