27
技术社区[云栖]
我最新的慢日志去哪了？
最近接到一个客户说，我在easydb中为什么看不到实时的慢sql，只能看到过气的慢日志的？
慢日志对于MySQL来说确实，是非常重要的，无论是问题排查还是性能优化，都能从其中捕获一些问题的来源，如果慢日志失去了实时性那还了得？
然后即刻登到easydb中去看，发现最新的慢日志定格在了7月5号晚22：00左右。难道真的是easydb捕获不到最新的慢日志了吗？
但是发现MySQL日志文件中的slowlog最后一条确实是跟easydb中的最新的一条相一致，那么easydb依旧是实时抓取slow log。那问题出现在哪里了呢？
Linux主机？还是MySQL服务器的时间？
Linux所在主机的时间
[root@msyql ]# date
Thu Jul 6 10:35:12 CST 2017MySQL的时间
mysql> select now();
+---------------------+
| now() |
+---------------------+
| 2017-07-06 10:36:10 |
+---------------------+
1 row in set (0.00 sec)比较悲伤并没有看到我们想看到的时间，时间都跟我屏幕右下方的时间相一致。
那问题出在哪里了呢？到底是哪里控制了MySQL slow日志里面的时间？
看一下关于MySQL 时间的参数
mysql> show variables like '%time%';
+---------------------------------+-------------------+
| Variable_name | Value |
+---------------------------------+-------------------+
| binlog_max_flush_queue_time | 0 |
| connect_timeout | 8 |
| datetime_format | %Y-%m-%d %H:%i:%s |
| delayed_insert_timeout | 300 |
| explicit_defaults_for_timestamp | ON |
| flush_time | 0 |
| innodb_flush_log_at_timeout | 1 |
| innodb_lock_wait_timeout | 5 |
| innodb_old_blocks_time | 1000 |
| innodb_rollback_on_timeout | OFF |
| interactive_timeout | 28800 |
| lc_time_names | en_US |
| lock_wait_timeout | 31536000 |
| long_query_time | 1.000000 |
| net_read_timeout | 30 |
| net_write_timeout | 60 |
| rpl_stop_slave_timeout | 300 |
| slave_net_timeout | 30 |
| slow_launch_time | 2 |
| time_format | %H:%i:%s |
| timed_mutexes | OFF |
| timestamp | 1499328877.100398 |
| wait_timeout | 28800 |
+---------------------------------+-------------------+
25 rows in set (0.00 sec)然后我看了一下我自己的MySQL 关于时间的参数
mysql> show variables like '%time%';
+---------------------------------------+-------------------+
| Variable_name | Value |
+---------------------------------------+-------------------+
| connect_timeout | 10 |
| datetime_format | %Y-%m-%d %H:%i:%s |
| delayed_insert_timeout | 302 |
| flush_time | 0 |
| have_response_time_distribution | YES |
| innodb_lock_wait_timeout | 50 |
| innodb_old_blocks_time | 0 |
| innodb_rollback_on_timeout | OFF |
| innodb_thread_concurrency_timer_based | OFF |
| interactive_timeout | 7200 |
| lc_time_names | en_US |
| lock_wait_timeout | 31536000 |
| long_query_time | 1.000000 |
| net_read_timeout | 30 |
| net_write_timeout | 60 |
| query_response_time_range_base | 10 |
| query_response_time_stats | OFF |
| rpl_semi_sync_master_timeout | 1000 |
| slave_net_timeout | 60 |
| slow_launch_time | 2 |
| slow_query_log_timestamp_always | OFF |
| slow_query_log_timestamp_precision | second |
| time_format | %H:%i:%s |
| timed_mutexes | OFF |
| timestamp | 1499329112 |
| trx_changes_idle_timeout | 0 |
| trx_idle_timeout | 0 |
| trx_readonly_idle_timeout | 0 |
| wait_timeout | 86400 |
+---------------------------------------+-------------------+
注：北美东部夏令时间英文名: Eastern Daylight Time 也就是上面的EDT
北美中部夏令时间英文名: Central Daylight Time 也就是上面的CST
这个system_time_zone跟time_zone有什么区别呢？这两个参数是干什么的呢？
看一下官方文档的解释：
The server system time zone. When the server begins executing, it inherits a time zone setting from the machine defaults, possibly modified by the environment of the account used for running the server or the startup script. The value is used to set system_time_zone.
./bin/mysqld_safe --defaults-file=/home/my3301/my.cnf --timezone=CST &发现这个时候的MySQL系统时间慢了8个小时，而且慢日志的时间跟这个时间是一致的，也是慢了8个小时。
mysql> select now();
+---------------------+
| now() |
+---------------------+
| 2017-07-06 02:36:10 |
+---------------------+
1 row in set (0.00 sec)./bin/mysqld_safe --defaults-file=/home/my3301/my.cnf --timezone=CST-8 &启动MySQL的时候指定timezone为CST
发现这个时候的MySQL系统时间跟我左下角的时间就正好吻合了，并且慢日志的时间跟我左下角的时间一致了。
这其实就验证了timezone这个参数影响了慢日志写入到日志里面的时间了。
那system_time_zone根time_zone又有什么区别呢？
The system_time_zone variable differs from time_zone. Although they might have the same value, the latter variable is used to initialize the time zone for each client that connects.
也就是一个是服务器系统时区，一个是连接的客户端的时区。
如果这两个参数设置不当，就会导致Linux主机系统的时间、MySQL select now()的时间，还有慢日志等日志产生的时间不一致。
这也就是为什么客户的慢日志为啥只能收集到12小时“前”的原因了~
最后更新：2017-07-06 17:32:19