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

Периодические медленные запросы к базе данных, вызванные InnoDB

Обновление 2017-11-26

Проблема, похоже, связана с InnoDB. CI, а также установки Wordpress используют движки InnoDB, а остальные работают с MyISAM. После того как я преобразовал все базы данных MODx в InnoDB, у них возникли те же проблемы ... Иногда очень медленные запросы, вызывающие время загрузки> 10 секунд. Вот скриншот моего инструмента мониторинга с одного из моих сайтов MODx (вы можете видеть, что вчера я переключился с MyISAM на InnoDB, и время загрузки резко увеличилось):

Вот мой my.cnf:

skip_name_resolve               = 1
thread_cache_size               = 4
performance_schema
query_cache_type                = 0
query_cache_limit               = 0
query_cache_size                = 0
join_buffer_size                = 4M
tmp_table_size                  = 250M
max_heap_table_size             = 250M


innodb_buffer_pool_instances    = 1
innodb_log_file_size            = 16M
innodb_buffer_pool_size         = 185M
innodb_io_capacity              = 2000
innodb_read_io_threads          = 64
innodb_thread_concurrency       = 0
innodb_write_io_threads         = 64
innodb_flush_log_at_trx_commit  = 0
innodb_log_file_size            = 23M

Статистика базы данных (после преобразования MODx из MyISAM в InnoDB):

Проблема

Я использую машину CentOS 7 с Nginx 1.10.2 + PHP 7.1.10 (php-fpm) + MariaDB 10.1.28. Используя эту машину, я обслуживаю следующие приложения:

В то время как мои приложения Laravel и MODx Revo работают очень быстро без каких-либо проблем, мои мониторы состояния, медленные журналы (PHP-FPM и MariaDB Slowlog) и ручное тестирование подтверждают это примерно с. 10 запросов к моим приложениям Wordpress и CI 3 требования. очень медленные (самые медленные около 5-7 секунд), а остальные 7 требуют. работают быстро, как и ожидалось.

Wordpress

www-slow.log (PHP-FPM)

[13-Nov-2017 09:44:09]  [pool www] pid 24000
script_filename = /usr/share/nginx/www/wordpress/index.php
[0x00007ff6f7412aa0] mysqli_query() /usr/share/nginx/www/wordpress/wp-includes/wp-db.php:1942
[0x00007ff6f7412a20] _do_query() /usr/share/nginx/www/wordpress/wp-includes/wp-db.php:1830
[0x00007ff6f7412940] query() /usr/share/nginx/www/wordpress/wp-includes/wp-db.php:2185
[0x00007ff6f74127f0] update() /usr/share/nginx/www/wordpress/wp-includes/option.php:342
[0x00007ff6f74126d0] update_option() /usr/share/nginx/www/wordpress/wp-includes/class-wp-rewrite.php:1817
[0x00007ff6f7412630] flush_rules() /usr/share/nginx/www/wordpress/wp-includes/class-wp-hook.php:298
[0x00007ff6f7412550] apply_filters() /usr/share/nginx/www/wordpress/wp-includes/class-wp-hook.php:323
[0x00007ff6f74124e0] do_action() /usr/share/nginx/www/wordpress/wp-includes/plugin.php:453
[0x00007ff6f74123e0] do_action() /usr/share/nginx/www/wordpress/wp-settings.php:469
[0x00007ff6f7412230] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/wordpress/wp-config.php:117
[0x00007ff6f74121b0] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/wordpress/wp-load.php:37
[0x00007ff6f7412110] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/wordpress/wp-blog-header.php:13
[0x00007ff6f7412080] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/wordpress/index.php:17

slow.log (MariaDB)

# User@Host: wordpress[wordpress] @ localhost []
# Thread_id: 6810  Schema: wordpress  QC_hit: No
# Query_time: 19.189590  Lock_time: 0.000046  Rows_sent: 0  Rows_examined: 1
# Rows_affected: 1
#
# explain: id   select_type table   type    possible_keys   key key_len ref rows    r_rows  filtered    r_filtered  Extra
# explain: 1    SIMPLE  wp_options  range   option_name option_name 766 NULL    1   1.00    100.00  100.00  Using where
#
SET timestamp=1510527877;
UPDATE `wp_options` SET `option_value` = '' WHERE `option_name` = 'rewrite_rules';

CI

www-slow.log (PHP-FPM)

[12-Nov-2017 23:08:02]  [pool www] pid 23991
    script_filename = /usr/share/nginx/www/ci/index.php
    [0x00007ff6f74133c0] query() /usr/share/nginx/www/ci/system/database/drivers/pdo/pdo_driver.php:184
    [0x00007ff6f7413350] _execute() /usr/share/nginx/www/ci/system/database/DB_driver.php:791
    [0x00007ff6f74132e0] simple_query() /usr/share/nginx/www/ci/system/database/DB_driver.php:654
    [0x00007ff6f74131b0] query() /usr/share/nginx/www/ci/system/libraries/Session/drivers/Session_database_driver.php:358
    [0x00007ff6f7413110] _get_lock() /usr/share/nginx/www/ci/system/libraries/Session/drivers/Session_database_driver.php:151
    [0x00007ff6f7413080] read() /usr/share/nginx/www/ci/system/libraries/Session/Session.php:143
    [0x00007ff6f7413030] session_start() /usr/share/nginx/www/ci/system/libraries/Session/Session.php:143
    [0x00007ff6f7412f60] __construct() /usr/share/nginx/www/ci/system/core/Loader.php:1279
    [0x00007ff6f7412e40] _ci_init_library() /usr/share/nginx/www/ci/system/core/Loader.php:1172
    [0x00007ff6f7412d20] _ci_load_stock_library() /usr/share/nginx/www/ci/system/core/Loader.php:1037
    [0x00007ff6f7412c10] _ci_load_library() /usr/share/nginx/www/ci/system/core/Loader.php:1083
    [0x00007ff6f7412b00] _ci_load_library() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:173
    [0x00007ff6f7412a00] library() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:192
    [0x00007ff6f7412950] libraries() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:153
    [0x00007ff6f7412850] library() /usr/share/nginx/www/ci/system/core/Loader.php:1353
    [0x00007ff6f7412790] _ci_autoloader() /usr/share/nginx/www/ci/system/core/Loader.php:157
    [0x00007ff6f7412740] initialize() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:65
    [0x00007ff6f7412690] initialize() /usr/share/nginx/www/ci/system/core/Controller.php:79
    [0x00007ff6f74125f0] __construct() /usr/share/nginx/www/ci/application/third_party/MX/Base.php:55
    [0x00007ff6f7412560] __construct() /usr/share/nginx/www/ci/application/third_party/MX/Base.php:60

slow.log (MariaDB)

# Time: 171112 23:08:05
# User@Host: ci[ci] @ localhost []
# Thread_id: 6445  Schema: pm  QC_hit: No
# Query_time: 16.833340  Lock_time: 0.000049  Rows_sent: 0  Rows_examined: 168
# Rows_affected: 1
#
# explain: id   select_type table   type    possible_keys   key key_len ref rows    r_rows  filtered    r_filtered  Extra
# explain: 1    SIMPLE  ci_un_sessions  ALL NULL    NULL    NULL    NULL    168 168.00  100.00  0.60    Using where
#
use pm;
SET timestamp=1510524485;
UPDATE `ci_un_sessions` SET `timestamp` = 1510524468, `data` = '__ci_last_regenerate|i:1510524343;requested_page|s:41:\"http://example.com/projects/view/19\";user_id|s:1:\"1\";username|s:9:\"admin\";role_id|s:1:\"1\";status|s:1:\"1\";previous_page|s:41:\"http://example.com/projects/view/19\";'
WHERE `id` = '0a75c6tl27pngqnfrh261okdvuotth50';

Я также пытался переключить драйвер базы данных в CI с PDO на Mysqli ... это ничего не изменило. Также я запускал все эти медленные запросы в Phpmyadmin, и они выполняются очень быстро ... так что, наконец, в CI я переключил сеанс с DB на Session_files_driver, что привело к печати slowlog:

[12-Nov-2017 23:27:00]  [pool www] pid 23991
script_filename = /usr/share/nginx/www/ci/index.php
[0x00007ff6f7413140] flock() /usr/share/nginx/www/ci/system/libraries/Session/drivers/Session_files_driver.php:178
[0x00007ff6f7413080] read() /usr/share/nginx/www/ci/system/libraries/Session/Session.php:143
[0x00007ff6f7413030] session_start() /usr/share/nginx/www/ci/system/libraries/Session/Session.php:143
[0x00007ff6f7412f60] __construct() /usr/share/nginx/www/ci/system/core/Loader.php:1279
[0x00007ff6f7412e40] _ci_init_library() /usr/share/nginx/www/ci/system/core/Loader.php:1172
[0x00007ff6f7412d20] _ci_load_stock_library() /usr/share/nginx/www/ci/system/core/Loader.php:1037
[0x00007ff6f7412c10] _ci_load_library() /usr/share/nginx/www/ci/system/core/Loader.php:1083
[0x00007ff6f7412b00] _ci_load_library() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:173
[0x00007ff6f7412a00] library() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:192
[0x00007ff6f7412950] libraries() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:153
[0x00007ff6f7412850] library() /usr/share/nginx/www/ci/system/core/Loader.php:1353
[0x00007ff6f7412790] _ci_autoloader() /usr/share/nginx/www/ci/system/core/Loader.php:157
[0x00007ff6f7412740] initialize() /usr/share/nginx/www/ci/application/third_party/MX/Loader.php:65
[0x00007ff6f7412690] initialize() /usr/share/nginx/www/ci/system/core/Controller.php:79
[0x00007ff6f74125f0] __construct() /usr/share/nginx/www/ci/application/third_party/MX/Base.php:55
[0x00007ff6f7412560] __construct() /usr/share/nginx/www/ci/application/third_party/MX/Base.php:60
[0x00007ff6f7412500] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/ci/application/third_party/MX/Controller.php:4
[0x00007ff6f74124a0] [INCLUDE_OR_EVAL]() /usr/share/nginx/www/ci/application/third_party/MX/Modules.php:123
[0x00007ff6f7412400] autoload() unknown:0
[0x00007ff6f74123a0] spl_autoload_call() unknown:0

Профилирование медленного запроса

MariaDB [user]> UPDATE `fx_un_sessions` SET `timestamp` = 1511872955 WHERE `id` = 'hrpsbbvr785cndmmo9n1iqnrek7teqi3';
Query OK, 0 rows affected (8.07 sec)
Rows matched: 1  Changed: 0  Warnings: 0

+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000097 |
| checking permissions | 0.000015 |
| Opening tables       | 0.000031 |
| After opening tables | 0.000013 |
| System lock          | 0.000012 |
| Table lock           | 0.000012 |
| init                 | 0.000065 |
| updating             | 0.000088 |
| end                  | 0.000016 |
| query end            | 8.077103 |
| closing tables       | 0.000059 |
| Unlocking tables     | 0.000034 |
| freeing items        | 0.000019 |
| updating status      | 0.000032 |
| logging slow query   | 0.000136 |
| cleaning up          | 0.000035 |
+----------------------+----------+
16 rows in set (0.00 sec)