最近公司项目需要分析日志,我拿到的日志经过了一次处理,以Json格式存储,日志量每小时大约1G,行数大约60万,此为背景。
其实对于这类问题,通常的解法是写个脚本去跑。对于我来说,主业是C/C++,脚本就只会bash和awk,可是这两种都无法直接处理Json;其他像python和perl可以处理但又不想学。怎么办呢?我想到的办法是用C++设计一个小工具,它从标准输入stdin中获取Json数据,然后取出我们感兴趣的字段,最后从stdout输出。这样就可以在bash中利用管道将不同的处理流程串起来。
我首先实现了一个单线程版本,首先使用std::getline从std::cin中获取一行数据,然后解析数据并提取字段,最后通过std::cout输出。使用这个版本处理一次要花大约5分钟,当时觉得好像也可以接受了。
后来在和同事聊天时谈到这个问题,同事说可以试试多线程。我一想,确实是这样,我们的系统环境拥有12核CPU,32G内存,不好好利用实在太可惜了。于是我使用操作系统中经典的生产者/消费者模型又实现了一版。首先有1个读取线程,负责从std::cin中获取数据,并将得到的数据投递到读取队列中;接着有10个解析线程,负责从读取队列中取出数据,然后解析提取字段,并将结果投递到输出队列中;最后还有1个输出线程,负责从输出队列取出结果并使用std::cout输出。
就在我期待奇迹发生的时候,奇迹果然发生了,使用这个版本处理一次大约需要4分钟,这显然是不可接受的。拿着同样的代码在Windows上运行(i7 4核8线程,16G内存),结果只需要不到30秒,后来拿前面的单线程版本跑也只需要大约100秒。那么问题出在哪里呢?通过callgrind分析后发现,程序卡在读取线程中,具体是std::getline这个函数。
在网上查阅部分资料后才知道,C++为了和C语言做兼容,使用std::cin和std::cout做输入输出时会和stdin和stdout做同步,这将消耗大量时间,而这个功能可以通过std::ios::sync_with_stdio(false)关闭,条件是不能混用C/C++的输入输出了。试了一下,情况果然好了很多,单线程版本只要94秒的样子,性能比Windows上略好;多线程版本需要43秒左右,性能比Windows略差。即使如此,也非常可以接受了。
就在我准备收工的时候,又发现了新的问题:输出线程的结果不正确。正常情况下我们的工具遇到一条输入数据就会产生一条输出数据,但实际情况是输入60万条数据,对应的输出有时多于60万,有时少于60万。通过对结果仔细分析,发现出现了数据损坏,而这在逻辑上是不可能的。
为什么说不可能,因为我们的程序已经考虑到了多个线程使用std::cout输出可能会造成数据损坏的问题,从而专门使用一个线程进行输出。搜索整个代码,也确实只在输出线程中使用了一次std::cout,真是太奇怪了。
追查了许久,终于发现了一个奇怪的函数std::cin.tie。带参数调用时用于给std::cin绑定一个输出流,不带参数时直接返回当前绑定的对象,而std::cin默认绑定的就是std::cout,std::cin在每次读取之前会先对绑定的输出流对象执行flush操作。问题终于找到了,我们虽然确保了std::cout只在一个线程中使用,但是C++的默认实现使读取线程中std::cout也被使用到了,解决办法就是往std::cin.tie中传入NULL参数,解除绑定。
下面附上一段测试代码,用于复现这个问题。
#include <time.h>
#include <iostream>
#include <string>
#include <thread>
#include <atomic>
std::atomic<bool> running(true);
static const char * pMsg[10] = {
"This is a simple test.\n",
"This is a second test.\n",
"This is a third test.\n",
"This is a forth test.\n",
"This is a fifth test.\n",
"This is a sixth test.\n",
"This is a seventh test.\n",
"This is a eighth test.\n",
"This is a ninth test.\n",
"This is a tenth test.\n",
};
static void writing(void)
{
srand((unsigned int)time(NULL));
for(int i = 0; i < 100000; ++i)
{
std::cout << pMsg[rand() % 10];
}
running = false;
}
static void reading(void)
{
while(running && !std::cin.eof())
{
std::string line;
std::getline(std::cin, line);
}
}
int main(int argc, char ** argv)
{
std::ios::sync_with_stdio(false);
std::cin.tie(NULL);
std::thread writing_thread(writing);
std::thread reading_thread(reading);
writing_thread.join();
reading_thread.join();
return 0;
}
程序开了两个线程,输出线程会输出10万行数据,读取线程只是随便读着玩的,使用的时候需要重定向一下输入输出,输入使用一个稍大一点的文本文件即可。通过注释掉main函数前两行可以试不同条件下的运行情况,可以发现一个有趣的现象,在Windows上基本上是没有差别的,也不会出错;而Linux上差别就大了,呵,自己慢慢体会。
上述代码在Windows上使用VS2013编译通过。Linux上使用GCC 4.9.2编译通过,编译命令:g++ -std=gnu++11 -pthread -O3 test.cpp -o test。