为何要打印日志？C++在高并发下如何写日志文件（附源码）？

提示：扫一扫查出行
【扫一扫了解最新限行尾号】
复制提示

为何要打印日志？让程序裸奔不是一件很快乐的事么？

有些BUG就像薛定谔的猫，具有波粒二象性，当你试图去观察它时它就消失了，当你不去观察它时，它又会出现。当你在测试人员面前赌咒发誓，亲自路演把程序跑一遍的时候，这些bug就会神奇的消失；一旦离开你的骚操作重新回到测试人员手中，这些bug又会突然的出现。这就是开发人员和测试人员互相对天发誓自证清白的尬聊场面。

因为这些幽灵Bug破坏了团队的氛围，伤害了开发和测试人员的感情，从而导致了产品质量下降。 因此非常有必要找到这些bug发生的原因。

试图找到这些具备量子特性的bug发生的原因，通常的手段就是打印日志，因为你很难通过几次思想实验或几次尬聊就能自证清白。

打印日志是查找、分析、定位问题的一个非常有效的手段。尤其对后台程序而言更加重要，后台程序需要长期运行，运行期间会面临各种各样的情况，这些情况包括正常业务逻辑，非正常业务逻辑，甚至是异常情况。我们往往需要在不同情况下将这些发生的事情按时间轴记录下来，从而在系统出现问题或瓶颈时进行回溯分析。

Java中有现成的日志打印类log4j，并将日志定义了4个级别：ERROR、WARN、INFO、DEBUG。通常级别越高输出的日志越少，如果你的后台程序一天就能输出一个G的ERROR日志，那也是非常不容易的事，基本可以告别程序员生涯了，还打啥日志啊？还能让测试人员愉快的工作么？

通常在出现ERROR日志时，我们就需要定位问题，这就需要打印大量的DEBUG或INFO日志来进行问题回溯。这篇文章不是介绍Java如何打印日志，网络上的文章已经很多了。

这里说一下C++在高并发下如何打印日志，这里实现最基本功能（仅做抛砖引玉之用）。通常我们会写一个日志输出函数，如下：

void Logout(const char* pszLogFile, const char* pszLog) { // 参数检查 assert(pszLogFile); assert(pszLog); if(NULL == pszLogFile || NULL == pszLog) return;// 打开日志文件 FILE* pFile = fopen(pszLogFile, "ab+"); if(pFile) { // 写日志 fwrite((void*)pszLog, 1, strlen(pszLog), pFile); fclose(pFile); } }

如果是不同级别的日志，可以定义不同日志文件名，你也可以丰富上面的日志函数，增加发生的时间、所在线程ID、所在文件名等辅助信息。

通常情况下这种方式没有问题，通过一次文件IO操作将信息记录下来。但如果是一个后台服务，当高并发发生的时候，问题就会出现了。此时将会有多个线程同时写日志的情况发生，尤其是那些INFO类型的日志，比如记录HTTP请求的request信息，这时你的日志将会成为系统的瓶颈。毕竟大量的文件IO操作也是一种负担，这些IO操作可能要超过你的正常业务逻辑，比如写数据库、网络IO等。

此时我们需要将日志先写入内存块中，当内存写满后在一次性Flush到磁盘中，这样就避免了大量的磁盘IO操作。下面是CFileMem封装类，很简单，里面注释的很详细就不解释了。

头文件.h

#include <windows.h>// for CRITICAL_SECTION// 缺省内存块大小，大于该值时进行将缓存数据写入磁盘文件 #define SIZE_DEFAULT_MEM(1024*64)// 64Kclass CFileMem { public: CFileMem(); virtual ~CFileMem();public: // 打开内存文件，dwMemBlockSize为缓存块大小，大于该值时进行一次IO操作 BOOL Open(const char* pszPathFile, DWORD dwMemBlockSize = SIZE_DEFAULT_MEM);/* 写数据到内存文件，dwFileSize将返回当前磁盘文件的大小，该值可用于外部判断日志文件是否过大，比如当dwFileSize大于多少M时，可重命名文件从而避免单个日志文件过大 */ BOOL Write(const char* pszLog, DWORD& dwFileSize); BOOL Write(const unsigned char* pData, DWORD dwDataSize, DWORD& dwFileSize);// 将内存数据写入磁盘 BOOL Flush(DWORD& dwFileSize);// 关闭内存文件 void Close();// 重命名文件 void Rename(const char* pszOldPathFile, const char* pszNewPathFile);protected: CRITICAL_SECTION m_csMem;// 内存池锁 char m_szPathFile[256];// 日志文件路径名 char* m_pMemBlock;// 内存块，用于存储文件数据 DWORD m_dwMemBlockSize;// 内存块大小 DWORD m_dwPos;// 内存块的当前位置 };

实现文件.cpp

#include "FileMem.h" #include <stdio.h>CFileMem::CFileMem() { m_pMemBlock = NULL; m_dwMemBlockSize = 0; m_dwPos = 0; memset(m_szPathFile, 0, 256); ::InitializeCriticalSection(&m_csMem); }CFileMem::~CFileMem() { Close(); ::DeleteCriticalSection(&m_csMem); }// 打开内存文件，dwMemBlockSize为缓存块大小，大于该值时进行一次IO操作 BOOL CFileMem::Open(const char* pszPathFile, DWORD dwMemBlockSize) { if(!pszPathFile) return FALSE;// 关闭之前已打开内存块 Close();// 保存日志文件全路径名 strcpy(m_szPathFile, pszPathFile);if(dwMemBlockSize <= 0) return FALSE; m_pMemBlock = (char*)malloc(dwMemBlockSize); if(NULL == m_pMemBlock) return FALSE;memset(m_pMemBlock, 0, dwMemBlockSize); m_dwMemBlockSize = dwMemBlockSize; m_dwPos = 0; return TRUE; }/* 写数据到内存文件，dwFileSize将返回当前磁盘文件的大小，该值可用于外部判断日志文件是否过大，比如当dwFileSize大于多少M时，可重命名文件从而避免单个日志文件过大 */ BOOL CFileMem::Write(const char* pszLog, DWORD& dwFileSize) { return Write((const unsigned char*)pszLog, strlen(pszLog), dwFileSize); } BOOL CFileMem::Write(const unsigned char* pData, DWORD dwDataSize, DWORD& dwFileSize) { dwFileSize = 0; if(NULL == pData || 0 == dwDataSize) return FALSE;// 如果内部没有开辟缓冲区，则直接写文件 if(NULL == m_pMemBlock || 0 == m_dwMemBlockSize) { FILE* pFile = ::fopen(m_szPathFile, "ab+"); if(NULL == pFile) return FALSE; ::fwrite(pData, 1, dwDataSize, pFile);// 获取磁盘文件大小 ::fseek(pFile, 0L, SEEK_END); dwFileSize = ::ftell(pFile); ::fclose(pFile); return TRUE; }::EnterCriticalSection(&m_csMem);// 如果内存块已满，则写入磁盘文件 DWORD dwTotalSize = m_dwPos + dwDataSize; if(dwTotalSize >= m_dwMemBlockSize) { FILE* pFile = ::fopen(m_szPathFile, "ab+"); if(NULL == pFile) { ::LeaveCriticalSection(&m_csMem); return FALSE; }// 将当前内存中数据写入文件 ::fwrite(m_pMemBlock, 1, m_dwPos, pFile); ::fwrite(pData, 1, dwDataSize, pFile);// 获取磁盘文件大小 ::fseek(pFile, 0L, SEEK_END); dwFileSize = ::ftell(pFile); ::fclose(pFile);// 清空内存块 memset(m_pMemBlock, 0, m_dwMemBlockSize); m_dwPos = 0; } else { // 如果内存未满，将当前数据写入内存 memcpy(m_pMemBlock+m_dwPos, pData, dwDataSize); m_dwPos += dwDataSize; } ::LeaveCriticalSection(&m_csMem); return TRUE; }// 将缓冲区的内容写入磁盘 BOOL CFileMem::Flush(DWORD& dwFileSize) { // 参数 dwFileSize = 0; if(NULL == m_pMemBlock || 0 == m_dwMemBlockSize || 0 == m_dwPos) return TRUE;::EnterCriticalSection(&m_csMem); FILE* pFile = ::fopen(m_szPathFile, "ab+"); if(NULL == pFile) { ::LeaveCriticalSection(&m_csMem); return FALSE; } // 内存数据写入磁盘文件 ::fwrite(m_pMemBlock, 1, m_dwPos, pFile);// 获取磁盘文件大小 ::fseek(pFile, 0L, SEEK_END); dwFileSize = ::ftell(pFile); ::fclose(pFile);// 清空内存块 memset(m_pMemBlock, 0, m_dwMemBlockSize); m_dwPos = 0;::LeaveCriticalSection(&m_csMem);return TRUE; }void CFileMem::Close() { // 将内存中文件写入磁盘 DWORD dwFileSize = 0; Flush(dwFileSize);// 释放内存块 free(m_pMemBlock); m_pMemBlock = NULL; m_dwMemBlockSize = 0; m_dwPos = 0; memset(m_szPathFile, 0, 256); }// 重命名文件 void CFileMem::Rename(const char* pszOldPathFile, const char* pszNewPathFile) { ::EnterCriticalSection(&m_csMem); ::rename(pszOldPathFile, pszNewPathFile); ::LeaveCriticalSection(&m_csMem); }

测试函数：

#include <assert.h> #include <stdio.h> #include <time.h>// for Clock // 传统的日志输出函数 void Logout(const char* pszLogFile, const char* pszLog) { // 参数检查 assert(pszLogFile); assert(pszLog); if(NULL == pszLogFile || NULL == pszLog) return;// 打开日志文件 FILE* pFile = fopen(pszLogFile, "ab+"); if(pFile) { // 写日志 fwrite((void*)pszLog, 1, strlen(pszLog), pFile); fclose(pFile); } }static void TestFileMem() { const char* pszLogFile1 = "c:/test1.log"; const char* pszLogInfo = "Hello world\r\n"; int iCount = 10000;// 循环写日志1万次// 第一种方式：传统写日志方式 clock_t cStart = clock(); for(int i = 0; i < iCount; i++) Logout(pszLogFile1, pszLogInfo); clock_t cEnd = clock(); long lElapsed = cEnd - cStart; printf("Logout Elpased time %d ms\r\n", lElapsed);// 第二种方式：使用CFileMem写日志 const char* pszLogFile2 = "c:/test2.log"; CFileMem fm; DWORD dwFileSize = 0; fm.Open(pszLogFile2); cStart = clock(); for(i = 0; i < iCount; i++) fm.Write(pszLogInfo, dwFileSize); fm.Close(); cEnd = clock(); lElapsed = cEnd - cStart;printf("CFileMem Elpased time %d ms\r\n", lElapsed);}