InnoDB 导致偶尔出现数据库查询缓慢的情况

InnoDB 导致偶尔出现数据库查询缓慢的情况

更新 2017-11-26

问题似乎与 InnoDB 有关。CI 以及 Wordpress 安装都使用 InnoDB 引擎,而其余部分则使用 MyISAM。在我将所有 MODx 数据库转换为 InnoDB 后,它们遇到了同样的问题……偶尔查询速度非常慢,导致加载时间超过 10 秒。这是我的一个 MODx 站点的监控工具的屏幕截图(您可以看到我昨天从 MyISAM 切换到了 InnoDB,加载时间激增):

切换到 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 之后):

  • MyISAM 表中的数据:589K(表:16)
  • InnoDB 表中的数据:131M(表:1089)

问题

我正在运行一台 CentOS 7 机器,其中装有 Nginx 1.10.2 + PHP 7.1.10 (php-fpm) + MariaDB 10.1.28。使用这台机器,我正在运行以下应用程序:

  • 4x Laravel 5.x
  • 10x MODx Revo 2.5.8
  • 1x Wordpress 4.8.3
  • 2x CI 3.1.6

虽然我的 Laravel 和 MODx Revo 应用程序运行速度超快且没有任何问题,但我的状态监视器、慢速日志(PHP-FPM 和 MariaDB Slowlog)和手动测试验证了,从对我的 Wordpress 和 CI 应用程序的大约 10 个请求中,有 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,导致打印慢日志:

[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)

相关内容