0%

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

发表于 更新于 分类于
本文字数： 1.9k 阅读时长 ≈ 2 分钟

话接上文，还是这个 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_r和gmtime耗时上并没有显著差别。而且如果不调用gmtime_r只声明tm tm_date，qps也是一样下降。

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

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

参考