0%

gmtime 在多线程环境使用引发的 bug

话接上文,还是这个 C++ 模型服务,在并发请求的情况下,大概有0.01%的请求部分模型分数不对。定位这种问题,对一个Python程序员来说,真是苦手。还好,经过调整代码不断测试,最终完美解决了问题。

线程安全

对比数据,可以发现和请求中的某个时间字段有关。关键逻辑代码如下,主要是一个时间差的计算。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
// string date_str = "2019-01-01 00:00:00";
// string date_appl = "2012-01-01 00:00:00";
double test_a(string& date_str, string& date_appl, tm& tm_appl) {
stringstream ss(date_str.substr(0,10));
int date_sec;
ss >> date_sec; // stringstream to int
time_t ts_date_1 = date_sec + 8*3600;
tm* tm_date = gmtime(&ts_date_1); // timestemp to tm
tm_date->tm_hour = 0;
tm_date->tm_min = 0;
tm_date->tm_sec = 0;
double seconds = difftime(mktime(&tm_appl), mktime(tm_date)); // diff timestemp
return seconds;
}

根据之前的经验,肯定是该函数内部某些操作非线程安全的, 通过google搜索(关键词: gmtime thread safe)和询问朋友,得到以下信息。

  • stringstream to int: 这里date_sec变量不存在竞争条件,所以安全
  • gmtime: 不安全
  • mktime: 时区不变的情况下安全
  • difftime: 安全

bug应该是来自gmtime,该函数返回的是tm结构体指针,指向的是一个 static 结构体,所以不是线程安全,可以用gmtime_r函数替换。

修改之后

1
2
3
4
5
6
7
8
9
10
11
12
double test_a(string& date_str, string& date_appl, tm& tm_appl) {
stringstream ss(date_str.substr(0,10));
int date_sec;
ss >> date_sec; // stringstream to int
time_t ts_date_1 = date_sec + 8*3600;
tm tm_date;
gmtime_r(&ts_date_1, &tm_date);
tm_date.tm_hour = 0;
tm_date.tm_min = 0;
tm_date.tm_sec = 0;
double seconds = difftime(mktime(&tm_appl), mktime(&tm_date));
}

经过测试,bug得以解决。但是同时发现一个问题,程序的qps下降了1/3。

QPS下降

编程测试代码测试对比gmtime_rgmtime耗时上并没有显著差别。而且如果不调用gmtime_r只声明tm tm_date,qps也是一样下降。

考虑到这个函数,在服务中调用次数比较多,而且自动变量的栈空间在函数调用时就会分配, tm结构体又比较大,应该对耗时有影响。

尝试修改tm tm_datestatic tm tm_date静态分配内存, qps恢复正常了。
但是由于我们需要在多线程环境中使用,最终修改为static thread_local tm tm_date

参考