一、问题展示

下面是问题当时的系统负载如下：

我们可以看到40.4%sy 正是系统调用负载较高的表现，随即朋友采集了perf如下：

接下来朋友采集了pstack给我，我发现大量的线程处于如下状态下：

Thread38(Thread0x7fe57a86f700(LWP67268)):#00x0000003dee4f82cein__lll_lock_wait_private()from/lib64/libc.so.6#10x0000003dee49df8din_L_lock_2163()from/lib64/libc.so.6#20x0000003dee49dd47in__tz_convert()from/lib64/libc.so.6#30x00000000007c02e7inTime_zone_system::gmt_sec_to_TIME(st_mysql_time*,long)const()#40x0000000000811df6inField_timestampf::get_date_internal(st_mysql_time*)()#50x0000000000809ea9inField_temporal_with_date::val_date_temporal()()#60x00000000005f43ccinget_datetime_value(THD*,Item***,Item**,Item*,bool*)()#70x00000000005e7ba7inArg_comparator::compare_datetime()()#80x00000000005eef4einItem_func_gt::val_int()()#90x00000000006fc6abinevaluate_join_record(JOIN*,st_join_table*)()#100x0000000000700e7einsub_select(JOIN*,st_join_table*,bool)()#110x00000000006fecc1inJOIN::exec()()

我们可以注意一下__tz_convert 这正是时区转换的证据。

二、关于timestamp简要说明

timestamp：占用4字节，内部实现是新纪元时间（1970-01-01 00:00:00）以来的秒，那么这种格式在展示给用户的时候就需要做必要的时区转换才能得到正确数据。下面我们通过访问ibd文件来查看一下内部表示方法，使用到了我的两个工具innodb和bcview，详细参考https://www.jianshu.com/p/719f1bbb21e8。

timestamp的内部表示

建立一个测试表

mysql>showvariableslike'%time_zone%';+------------------+--------+|Variable_name|Value|+------------------+--------+|system_time_zone|CST||time_zone|+08:00|+------------------+--------+mysql>createtabletmm(dttimestamp);QueryOK,0rowsaffected(0.04sec)mysql>insertintotmmvalues('2019-01-0101:01:01');QueryOK,1rowaffected(0.00sec)

我们来查看一下内部表示如下：

[root@gp1test]#./bcviewtmm.ibd1612525|grep00000003currentblock:00000003--Offset:00125--cntbytes:25--datais:000001ac3502000000070d52c80000002f01105c2a4b4d0000

整理一下如下：

000001ac3502：rowid

000000070d52：trx id

c80000002f0110：roll ptr

5c2a4b4d：timestamp类型的实际数据十进制为1546275661

我们使用Linux命令如下：

[root@gp1~]#date-d@1546275661TueJan101:01:01CST2019

因为我的Linux也是CST +8时区这里数据也和MySQL中显示一样。下面我们调整一下时区再来看看取值如下：

mysql>settime_zone='+06:00';QueryOK,0rowsaffected(0.00sec)mysql>select*fromtmm;+---------------------+|dt|+---------------------+|2018-12-3123:01:01|+---------------------+1rowinset(0.01sec)

这里可以看到减去了2个小时，因为我的时区从+8变为了+6。

三、timestap转换

在进行新纪元时间（1970-01-01 00:00:00）以来的秒到实际时间之间转换的时候MySQL根据参数time_zone的设置有两种选择：

time_zone：设置为SYSTEM的话，使用sys_time_zone获取的OS会话时区，同时使用OS API进行转换。对应转换函数 Time_zone_system::gmt_sec_to_TIME

time_zone：设置为实际的时区的话，比如‘+08:00’，那么使用使用MySQL自己的方法进行转换。对应转换函数 Time_zone_offset::gmt_sec_to_TIME

实际上Time_zone_system和Time_zone_offset均继承于Time_zone类，并且实现了Time_zone类的虚函数进行了重写，因此上层调用都是Time_zone::gmt_sec_to_TIME。

注意这种转换操作是每行符合条件的数据都需要转换的。

四、问题修复方案

我们从问题栈帧来看这个故障使用的是 Time_zone_system::gmt_sec_to_TIME 函数进行转换的，因此可以考虑如下：

time_zone：设置为指定的时区，比如‘+08:00’。这样就不会使用OS API进行转换了，而转为MySQL自己的内部实现 调用 Time_zone_offset::gmt_sec_to_TIME函数。但是需要注意的是，如果使用MySQL自己的实现那么us%会加剧。

使用datetime代替timestamp，新版本datetime为5个字节，只比timestamp多一个字节。

五、修复前后sy%使用量对比

据朋友说他大概在上午11点多完成了修改，做的方式是将 time_zone修改为‘+08:00’，下面展示修改前后CPU使用率的对比：

修复前：

修复后：

六、备用栈帧

time_zone=‘SYSTEM’转换栈帧

#0Time_zone_system::gmt_sec_to_TIME(this=0x2e76948,tmp=0x7fffec0f3ff0,t=1546275661)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/tztime.cc:1092#10x0000000000f6b65cinTime_zone::gmt_sec_to_TIME(this=0x2e76948,tmp=0x7fffec0f3ff0,tv=...)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/tztime.h:60#20x0000000000f51643inField_timestampf::get_date_internal(this=0x7ffe7ca66540,ltime=0x7fffec0f3ff0)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:6014#30x0000000000f4ff49inField_temporal_with_date::val_str(this=0x7ffe7ca66540,val_buffer=0x7fffec0f4370,val_ptr=0x7fffec0f4370)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:5429#40x0000000000f11d7binField::val_str(this=0x7ffe7ca66540,str=0x7fffec0f4370)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.h:866#50x0000000000f4549dinField::send_text(this=0x7ffe7ca66540,protocol=0x7ffe7c001e88)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:1725#60x00000000014dfb82inProtocol_text::store(this=0x7ffe7c001e88,field=0x7ffe7ca66540)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/protocol_classic.cc:1415#70x0000000000fb06c0inItem_field::send(this=0x7ffe7c006ec0,protocol=0x7ffe7c001e88,buffer=0x7fffec0f4760)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/item.cc:7801#80x000000000156b15cinTHD::send_result_set_row(this=0x7ffe7c000b70,row_items=0x7ffe7c005d58)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.cc:5026#90x0000000001565758inQuery_result_send::send_data(this=0x7ffe7c006e98,items=...)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.cc:2932#100x0000000001585490inend_send(join=0x7ffe7c007078,qep_tab=0x7ffe7c0078d0,end_of_records=false)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_executor.cc:2925#110x0000000001582059inevaluate_join_record(join=0x7ffe7c007078,qep_tab=0x7ffe7c007758)

time_zone=‘+08:00’转换栈帧

#0Time_zone_offset::gmt_sec_to_TIME(this=0x6723d90,tmp=0x7fffec0f3ff0,t=1546275661)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/tztime.cc:1418#10x0000000000f6b65cinTime_zone::gmt_sec_to_TIME(this=0x6723d90,tmp=0x7fffec0f3ff0,tv=...)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/tztime.h:60#20x0000000000f51643inField_timestampf::get_date_internal(this=0x7ffe7ca66540,ltime=0x7fffec0f3ff0)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:6014#30x0000000000f4ff49inField_temporal_with_date::val_str(this=0x7ffe7ca66540,val_buffer=0x7fffec0f4370,val_ptr=0x7fffec0f4370)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:5429#40x0000000000f11d7binField::val_str(this=0x7ffe7ca66540,str=0x7fffec0f4370)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.h:866#50x0000000000f4549dinField::send_text(this=0x7ffe7ca66540,protocol=0x7ffe7c001e88)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/field.cc:1725#60x00000000014dfb82inProtocol_text::store(this=0x7ffe7c001e88,field=0x7ffe7ca66540)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/protocol_classic.cc:1415#70x0000000000fb06c0inItem_field::send(this=0x7ffe7c006ec0,protocol=0x7ffe7c001e88,buffer=0x7fffec0f4760)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/item.cc:7801#80x000000000156b15cinTHD::send_result_set_row(this=0x7ffe7c000b70,row_items=0x7ffe7c005d58)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.cc:5026#90x0000000001565758inQuery_result_send::send_data(this=0x7ffe7c006e98,items=...)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_class.cc:2932#100x0000000001585490inend_send(join=0x7ffe7c007078,qep_tab=0x7ffe7c0078d0,end_of_records=false)at/root/mysqlall/percona-server-locks-detail-5.7.22/sql/sql_executor.cc:2925#110x0000000001582059inevaluate_join_record(join=0x7ffe7c007078,qep_tab=0x7ffe7c007758)