由mysql timestamp字段引发的一个系统bug

shangban

2015-06-30 13:11:00左右，memcache由于硬件故障，莫名重启，导致数据库访问量突然增大(按照之前的测试结果，远未到达系统瓶颈)，且当时syscpu 远高于正常值。
监控信息如下:


当时的mysqld堆栈信息如下:

• Thread 50 (Thread 0x2afb6591a700 (LWP 7020)):
  
  
• #0 0x0000003c34ef808f in __lll_unlock_wake_private () from /lib64/libc.so.6
  
• #1 0x0000003c34e9dccc in _L_unlock_2226 () from /lib64/libc.so.6
  
• #2 0x0000003c34e9db01 in __tz_convert () from /lib64/libc.so.6
  
• #3 0x0000000000783012 in Time_zone_system::gmt_sec_to_TIME(st_mysql_time*, long) const ()
  
• #4 0x00000000007c177b in Field_timestampf::get_date_internal(st_mysql_time*) ()
  
• #5 0x00000000007c23dd in Field_temporal_with_date::val_str(String*, String*) ()
  
• #6 0x0000000000672fa8 in Protocol_text::store(Field*) ()
  
• #7 0x00000000006722f5 in Protocol::send_result_set_row(List<Item>*) ()
  
• #8 0x00000000006c77af in select_send::send_data(List<Item>&) ()
  
• #9 0x00000000006db6b0 in end_send(JOIN*, st_join_table*, bool) ()
  
• #10 0x00000000006d6c4f in evaluate_join_record(JOIN*, st_join_table*) ()
  
• #11 0x00000000006d6fbb in sub_select(JOIN*, st_join_table*, bool) ()
  
• #12 0x00000000006d61e8 in JOIN::exec() ()
  
• #13 0x000000000071f0d5 in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, SQL_I_List<st_order>*, SQL_I_List<st_order>*, Item*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) ()
  
• #14 0x000000000071f935 in handle_select(THD*, select_result*, unsigned long) ()
  
• #15 0x000000000057fe02 in execute_sqlcom_select(THD*, TABLE_LIST*) ()
  
• #16 0x00000000006f935c in mysql_execute_command(THD*) ()
  
• #17 0x00000000006fe5e8 in mysql_parse(THD*, char*, unsigned int, Parser_state*) ()
  
• #18 0x00000000006ffdc9 in dispatch_command(enum_server_command, THD*, char*, unsigned int) ()
  
• #19 0x0000000000789a08 in threadpool_process_request(THD*) ()
  
• #20 0x000000000078a9dd in worker_main(void*) ()
  
• #21 0x0000000000b4a8c3 in pfs_spawn_thread ()
  
• #22 0x0000003c352079d1 in start_thread () from /lib64/libpthread.so.0
  
• #23 0x0000003c34ee88fd in clone () from /lib64/libc.so.6
  

从堆栈可以看到大部分请求都在调用glibc的时区转换函数，但该函数由于全局锁的原因，在并发环境下产生了热点竞争。

深入分析mysql时区相关的函数:

• void
  
  
• Time_zone_system::gmt_sec_to_TIME(MYSQL_TIME *tmp, my_time_t t) const
  
• {
  
•   struct tm tmp_tm;
  
•   time_t tmp_t= (time_t)t;
  
• 
  
•   localtime_r(&tmp_t, &tmp_tm);
  
•   localtime_to_TIME(tmp, &tmp_tm);
  
•   tmp->time_type= MYSQL_TIMESTAMP_DATETIME;
  
•   adjust_leap_second(tmp);
  
• }
  

继续进入localtime_r函数

• struct tm *
  
  
• __tz_convert (const time_t *timer, int use_localtime, struct tm *tp)
  
• {
  
•   long int leap_correction;
  
•   int leap_extra_secs;
  
• 
  
•   if (timer == NULL)
  
•     {
  
•       __set_errno (EINVAL);
  
•       return NULL;
  
•     }
  
• 
  
• __libc_lock_lock (tzset_lock);
  
• 
  
•   /* Update internal database according to current TZ setting.
  
•      POSIX.1 8.3.7.2 says that localtime_r is not required to set tzname.
  
•      This is a good idea since this allows at least a bit more parallelism. */
  
•   tzset_internal (tp == &_tmbuf && use_localtime, 1);
  
• 
  
•   if (__use_tzfile)
  
•     __tzfile_compute (*timer, use_localtime, &leap_correction,
  
•               &leap_extra_secs, tp);
  
•   else
  
•     {
  
•       if (! __offtime (timer, 0, tp))
  
•     tp = NULL;
  
•       else
  
•     __tz_compute (*timer, tp, use_localtime);
  
•       leap_correction = 0L;
  
•       leap_extra_secs = 0;
  
•     }
  
• 
  
•   if (tp)
  
•     {
  
•       if (! use_localtime)
  
•     {
  
•       tp->tm_isdst = 0;
  
•       tp->tm_zone = "GMT";
  
•       tp->tm_gmtoff = 0L;
  
•     }
  
• 
  
•       if (__offtime (timer, tp->tm_gmtoff - leap_correction, tp))
  
•         tp->tm_sec += leap_extra_secs;
  
•       else
  
•     tp = NULL;
  
•     }
  
• 
  
•   __libc_lock_unlock (tzset_lock);
  
• 
  
•   return tp;
  
• }
  

很清楚的看到，在调用系统时区转换时，有全局锁__libc_lock_lock的保护，导致线程并发环境下，系统性能受限。

而在time_zone=system时，会调用该函数从而获取系统的时区。如果将time_zone='+8:00'则不会调用系统时区.
对此，真实的模拟了线上的case(分别对time_zone=system和time_zone='+8:00'做了压测):

• mysqlslap --no-defaults -u$user -p$password --create-schema=DianPingTS -h$host -P$port --number-of-queries=1000000000 --concurrency=30 --query="select AddTime,UpdateTime from $table where addtime>='2015-07-01 15:21:35' and addtime<='2015-07-01 17:33:35';"
  

以下是测试结果:


由此可见，在time_zone='+8:00'在timestamp类型的大量转换情况下，性能能得到质的提升..


小伙伴们，如果也遇到该问题，只要将time_zone='+8:00' (注意地区在东8区哦)就可以了..^_^