为何要打印日志?C++在高并发下如何写日志文件(附源码)?

Posted 一只会铲史的猫

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了为何要打印日志?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)       // 64K

class 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);

}

输出结果


通过测试比较,第二种方式速度更加快速,而且是线程安全的。
我写的“HttpServer:一款Windows平台下基于IOCP模型的高并发轻量级web服务器”,就使用该类进行日志打印,效果不错。

感谢您的阅读!

以上是关于为何要打印日志?C++在高并发下如何写日志文件(附源码)?的主要内容,如果未能解决你的问题,请参考以下文章

Nginx在高并发下的性能优化点!有这篇就够了!

高并发下的内存管理技巧

高并发下如何保证数据库和缓存双写一致性?

高并发下如何保证数据库和缓存双写一致性?

select 时进行update的操作,在高并发下引起死锁

PHP和Redis实现在高并发下的抢购及秒杀功能示例详解