Назад | Перейти на главную страницу

MySQL убивает процессор с помощью gettimeofday

У меня проблема с mysql, убивающим процессор на Debian Squeeze 64. Это машина для разработки на VPS, поэтому я остановил все другие службы, включая apache2. Версия mysql - 5.1.49. Это журнал при запуске mysql:

Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: 130206 19:03:40 [Note] Plugin 'FEDERATED' is disabled.
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: InnoDB: 1 transaction(s) which must be rolled back or cleaned up
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: InnoDB: in total 1 row operations to undo
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: InnoDB: Trx id counter is 0 31809536
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: 130206 19:03:40  InnoDB: Started; log sequence number 2 892018402
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: 130206 19:03:40 [Note] Event Scheduler: Loaded 0 events
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: 130206 19:03:40 [Note] /usr/sbin/mysqld: ready for connections.
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: Version: '5.1.49-3-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: InnoDB: Starting in background the rollback of uncommitted transactions
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: InnoDB: Cleaning up trx with id 0 2218455
Feb  6 19:03:40 Debian-60-squeeze-64-LAMP mysqld: 130206 19:03:40  InnoDB: Rollback of non-prepared transactions completed
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4616]: Upgrading MySQL tables if necessary.
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4619]: /usr/bin/mysql_upgrade: the '--basedir' option is always ignored
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4619]: Looking for 'mysql' as: /usr/bin/mysql
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4619]: Looking for 'mysqlcheck' as: /usr/bin/mysqlcheck
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4619]: This installation of MySQL is already upgraded to 5.1.49, use --force if you still need to run mysql_upgrade
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4626]: Checking for insecure root accounts.
Feb  6 19:03:41 Debian-60-squeeze-64-LAMP /etc/mysql/debian-start[4630]: Triggering myisam-recover for all MyISAM tables

В тот момент, когда я запускаю mysql, процессор начинает работать до небес, хотя запросы не выполняются. Это результат состояния /etc/init.d/mysql:

Server version          5.1.49-3-log
Protocol version        10
Connection              Localhost via UNIX socket
UNIX socket             /var/run/mysqld/mysqld.sock
Uptime:                 29 min 38 sec

Threads: 1  Questions: 955  Slow queries: 0  Opens: 5512  Flush tables: 1  Open tables: 32  Queries per second avg: 0.537.

Используя strace для mysql pid, который использует 100% ЦП, я получаю что-то вроде этого всего за 1-2 минуты:

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
90.89  126.423901      179579       704           select
4.01    5.572348     2786174         2           rt_sigtimedwait
2.99    4.164260      118979        35         1 futex
2.11    2.929960           1   3471808           gettimeofday
0.00    0.000000           0         3         1 read
0.00    0.000000           0         3           write
0.00    0.000000           0         1           close
0.00    0.000000           0         4           rt_sigprocmask
0.00    0.000000           0         1         1 access
0.00    0.000000           0         6           sched_yield
0.00    0.000000           0         1           alarm
0.00    0.000000           0         1           accept
0.00    0.000000           0         1           shutdown
0.00    0.000000           0         1           getsockname
0.00    0.000000           0         2         1 setsockopt
0.00    0.000000           0         7           fcntl
0.00    0.000000           0         1           tgkill
------ ----------- ----------- --------- --------- ----------------
100.00  139.090469               3472581         4 total

Фактические вызовы выглядят так:

19:37:26.553922 gettimeofday({1360175846, 553939}, NULL) = 0 <0.000004>
19:37:26.622537 gettimeofday({1360175846, 622591}, NULL) = 0 <0.000011>
19:37:26.622659 gettimeofday({1360175846, 622679}, NULL) = 0 <0.000009>
19:37:26.622737 gettimeofday({1360175846, 622754}, NULL) = 0 <0.000009>
19:37:26.622812 gettimeofday({1360175846, 622829}, NULL) = 0 <0.000008>
19:37:26.622887 gettimeofday({1360175846, 622951}, NULL) = 0 <0.000010>
19:37:26.623010 gettimeofday({1360175846, 623028}, NULL) = 0 <0.000008>
19:37:26.623109 gettimeofday({1360175846, 623132}, NULL) = 0 <0.000009>

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

Спасибо !

Дополнительная информация по запросу:

Вывод SHOW PROCESSLIST

mysql> SHOW PROCESSLIST;
+-----+------+-----------+------+---------+------+-------+------------------+
| Id  | User | Host      | db   | Command | Time | State | Info             |
+-----+------+-----------+------+---------+------+-------+------------------+
| 325 | root | localhost | NULL | Query   |    0 | NULL  | SHOW PROCESSLIST |
+-----+------+-----------+------+---------+------+-------+------------------+
1 row in set (0.00 sec)

Вывод top -H:

top - 21:21:26 up  5:35,  2 users,  load average: 1.07, 1.02, 1.00
Tasks: 152 total,   2 running, 150 sleeping,   0 stopped,   0 zombie
Cpu(s): 96.2%us,  1.9%sy,  0.0%ni,  0.0%id,  0.0%wa,  1.9%hi,  0.0%si,  0.0%st
Mem:   2061536k total,   973540k used,  1087996k free,    44952k buffers
Swap:  2102552k total,        0k used,  2102552k free,   693716k cached

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

У меня была несколько похожая проблема, в которой MySQL 5.1 на Debian Squeeze (32-разрядная версия) время от времени (не всегда) переходил на 100% ЦП, но у меня не было времени на ее диагностику, поскольку это было за несколько дней до ключевой срок.

подробности

Я обнаружил, что существует несколько различных способов получить проблему с высокой загрузкой процессора в MySQL.

Самый простой способ воспроизвести - запустить определенное административное представление Django (стандартная страница пользовательского интерфейса администратора), которое объединяет несколько таблиц и возвращает несколько тысяч строк - это надежно помещает один поток в 99% CPU. Удаление этой темы остановило проблему.

mysql> show processlist;
+----+------------+-----------+-----------+---------+------+------------+-------------------------------------------------------------------------------------------------------+
| Id | User       | Host      | db        | Command | Time | State      | Info                                                                                                    |
+----+------------+-----------+-----------+---------+------+------------+-----------------------------------------------------------------------------------------------------+
| 68 | djangouser | localhost | django_db | Query   |   77 | statistics | SELECT `mytable`.`id`, `mytable`.`tenant_id`, `mytable |
| 69 | djangouser | localhost | django_db | Query   |    0 | NULL       | show processlist                                                                                     |
+----+------------+-----------+-----------+---------+------+------------+------------------------------------------------------------------------------------------------------+
2 rows in set (0.00 sec)

Связанный

https://groups.google.com/forum/?fromgroups=#!topic/django-users/Iz6x7c0i9nI Очень похожий случай, когда зависание произошло в наборе запросов Django.

несколько похожих случаев:

https://dba.stackexchange.com/questions/24643/mysql-5-5-runs-out-of-memory-drops-all-connections-when-creating-many-databases dba.stackexchange - MySQL разрывает все соединения после создания от 2000 до 5000 баз данных

https://groups.google.com/forum/?fromgroups=#!topic/django-users/sU-zj7s8uU4 - Оптимизатор непрерывных запросов для определенных запросов администратора Django из-за 20 внутренних соединений! Исправление заключалось в установке optimizer_search_depth на 3 (по умолчанию 62)

Мое решение - перейти на PostgreSQL

Django упростил переключение на PostgreSQL только через конфигурацию, плюс время на установку и настройку PostgreSQL - я понимаю, что это может быть не вариант для вас, но если ваш язык / фреймворк позволяет легко переключиться, серьезно подумайте об этом. Я использовал пакеты postgres по умолчанию в Debian 6.0 Squeeze, которые подходят - или вы можете использовать пакеты 9.1 или 9.2 для Debian из проекта Postgres, которые могут быть лучше и намного более свежие.

Переключение заняло всего пару часов, несмотря на то, что раньше не использовался PostgreSQL, и избавило от этой проблемы, не создавая новых. И у PostgreSQL есть много других хороших функций, и теперь я очень рад, что переключился.

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

Я была такая же проблема. Это было вызвано опечаткой, а не:

innodb_buffer_pool_size = 256M

я написал

innodb_buffer_pool_size = 256M