一、服務(wù)器端日志與客戶端日志的區(qū)別

站在用戶的角度思考問題，與客戶深入溝通，找到拱墅網(wǎng)站設(shè)計(jì)與拱墅網(wǎng)站推廣的解決方案，憑借多年的經(jīng)驗(yàn)，讓設(shè)計(jì)與互聯(lián)網(wǎng)技術(shù)結(jié)合，創(chuàng)造個(gè)性化、用戶體驗(yàn)好的作品，建站類型包括：成都做網(wǎng)站、成都網(wǎng)站制作、企業(yè)官網(wǎng)、英文網(wǎng)站、手機(jī)端網(wǎng)站、網(wǎng)站推廣、國際域名空間、網(wǎng)站空間、企業(yè)郵箱。業(yè)務(wù)覆蓋拱墅地區(qū)。

在正式講解之前，我們先來看一個(gè)日志類的實(shí)現(xiàn)方法，這個(gè)日志類也是代表著大多數(shù)客戶端日志的主流寫法:

/**
 *@desc:    程序運(yùn)行l(wèi)og類,log.h
 *@author:  zhangyl
 *@date:    2017.01.17
 **/
#ifndef __LOG_H__
#define __LOG_H__

#ifdef _ZYL_LOG_
#define LogInfo(...)     Log::GetInstance().AddLog("INFO", __FILE__, __LINE__, __FUNCSIG__, __VA_ARGS__)
#define LogWarning(...)  Log::GetInstance().AddLog("WARNING", __FILE__, __LINE__, __FUNCSIG__, __VA_ARGS__)
#define LogError(...)    Log::GetInstance().AddLog("ERROR", __FILE__, __LINE__, __FUNCSIG__, __VA_ARGS__)
#else
#define LogInfo(...) (void(0))
#define LogError(...) (void(0))
#endif

class Log
{
public:
    static Log& GetInstance();

    bool AddLog(const char* pszLevel, const char* pszFile, int lineNo, const char* pszFuncSig, char* pszFmt, ...);

private:
    Log();
    ~Log();
    Log(const Log&);
    Log& operator=(const Log&);

private:
    FILE*   m_file;

};

#endif //!__LOG_H__

/**
 *@desc:    程序運(yùn)行l(wèi)og類,log.cpp
 *@author:  zhangyl
 *@date:    2017.01.17
 **/

#include 
#include 
#include 
#include "Log.h"

Log& Log::GetInstance()
{
    static Log log;
    return log;
}

bool Log::AddLog(const char* pszLevel, const char* pszFile, int lineNo, const char* pszFuncSig, char* pszFmt, ...)
{
    if (m_file == NULL)
        return false;

    char tmp[8192*10] = { 0 };
    va_list va;                 //定義一個(gè)va_list型的變量,這個(gè)變量是指向參數(shù)的指針.
    va_start(va, pszFmt);           //用va_start宏初始化變量,這個(gè)宏的第二個(gè)參數(shù)是第一個(gè)可變參數(shù)的前一個(gè)參數(shù),是一個(gè)固定的參數(shù)
    _vsnprintf(tmp, ARRAYSIZE(tmp), pszFmt, va);//注意,不要漏掉前面的_
    va_end(va);

    time_t now = time(NULL);
    struct tm* tmstr = localtime(&now);
    char content[8192 * 10 + 256] = {0};
    sprintf_s(content, ARRAYSIZE(content), "[%04d-%02d-%02d %02d:%02d:%02d][%s][0x%04x][%s:%d %s]%s\r\n",
                tmstr->tm_year + 1900,
                tmstr->tm_mon + 1,
                tmstr->tm_mday,
                tmstr->tm_hour,
                tmstr->tm_min,
                tmstr->tm_sec,
                pszLevel,
                GetCurrentThreadId(),
                pszFile,
                lineNo,
                pszFuncSig,
                tmp);

    if (fwrite(content, strlen(content), 1, m_file) != 1)
        return false;

    fflush(m_file);

    return true;
}

Log::Log()
{
    time_t now = time(NULL);
    struct tm* tmstr = localtime(&now);
    char filename[256];
    sprintf_s(filename, ARRAYSIZE(filename), "%04d%02d%02d%02d%02d%02d.runlog", 
                tmstr->tm_year + 1900, 
                tmstr->tm_mon + 1, 
                tmstr->tm_mday, 
                tmstr->tm_hour, 
                tmstr->tm_min, 
                tmstr->tm_sec);

    m_file = fopen(filename, "at+");
}

Log::~Log()
{
    if (m_file != NULL)
        fclose(m_file);
}

這個(gè)Log類的定義和實(shí)現(xiàn)代碼節(jié)選自我的一款12306刷票軟件，如果需要使用這個(gè)類的話包含Log.h頭文件，然后使用宏：LogInfo/LogWarning/LogError這三個(gè)宏就可以了。示例如下：

    string strResponse;
    string strCookie = "Cookie: ";
    strCookie += m_strCookies;
    if (!HttpRequest(osURL.str().c_str(), strResponse, true, strCookie.c_str(), NULL, false, 10))
    {
        LogError("QueryTickets2 failed");
        return false;
    }

這個(gè)日志類，每次輸出一行，一行中輸出時(shí)間、日志級(jí)別、線程id、文件名、行號(hào)、函數(shù)簽名和自定義的錯(cuò)誤信息，演示如下：

[2017-02-16 17:30:08][INFO][0x0e7c][f:\mycode\hack12306\12306demo\client12306.cpp:1401 bool __thiscall Client12306::HttpRequest(const char *,class std::basic_string,class std::allocator > &,bool,const char *,const char *,bool,int)]http response: {"validateMessagesShowId":"_validatorMessage","status":true,"httpstatus":200,"data":{"loginAddress":"10.1.232.219","otherMsg":"","loginCheck":"Y"},"messages":[],"validateMessages":{}}

[2017-02-16 17:30:08][INFO][0x0e7c][f:\mycode\hack12306\12306demo\client12306.cpp:1379 bool __thiscall Client12306::HttpRequest(const char *,class std::basic_string,class std::allocator > &,bool,const char *,const char *,bool,int)]http post: url=https://kyfw.12306.cn:443/otn/login/userLogin, headers=Cookie: JSESSIONID=0A01D965C45FE88A1FB289F288BD96C255E3547783; BIGipServerotn=1708720394.50210.0000; , postdata=_json_att=

[2017-02-16 17:30:08][INFO][0x0e7c][f:\mycode\hack12306\12306demo\client12306.cpp:1401 bool __thiscall Client12306::HttpRequest(const char *,class std::basic_string,class std::allocator > &,bool,const char *,const char *,bool,int)]http response: 

[2017-02-16 17:30:08][INFO][0x0e7c][f:\mycode\hack12306\12306demo\client12306.cpp:1379 bool __thiscall Client12306::HttpRequest(const char *,class std::basic_string,class std::allocator > &,bool,const char *,const char *,bool,int)]http post: url=https://kyfw.12306.cn:443/otn/index/initMy12306, headers=Cookie: JSESSIONID=0A01D965C45FE88A1FB289F288BD96C255E3547783; BIGipServerotn=1708720394.50210.0000; , postdata=

上文中也說了，以上示例是我曾經(jīng)寫的一款客戶端程序的日志，注意“客戶端”這個(gè)重要的關(guān)鍵字。因?yàn)樯鲜鋈罩镜膶?shí)現(xiàn)雖然通用，但其局限性也只能用于客戶端這樣對(duì)性能和效率要求不高的程序（這里的性能和效率是相對(duì)于高并發(fā)高性能的服務(wù)器程序來說的，也就是說上述日志實(shí)現(xiàn)可用于大多數(shù)客戶端程序，但不能用于高性能高并發(fā)的服務(wù)器程序）。那么上述程序存在什么問題？問題是效率低！
不知道讀者有沒有注意上，上述日志類實(shí)現(xiàn)，是在調(diào)用者線程中直接進(jìn)行IO操作，相比較于高速的CPU，IO磁盤操作是很慢的，直接在某些工作線程（包括UI線程）寫文件，程序執(zhí)行速度太慢，尤其是當(dāng)日志數(shù)據(jù)比較多的時(shí)候。
這也就是服務(wù)器端日志和客戶端日志的區(qū)別之一，客戶端程序日志一般可以在直接在所在的工作線程寫日志，因?yàn)檫@點(diǎn)性能和時(shí)間損失對(duì)大多數(shù)客戶端程序來說，是可以忽略的，但對(duì)于要求高并發(fā)（例如并發(fā)量達(dá)百萬級(jí)乃至千萬級(jí)的系統(tǒng)）的服務(wù)器程序來說，單位時(shí)間內(nèi)耗在磁盤寫操作上的時(shí)間就相當(dāng)可觀了。我目前的做法是參考陳碩的muduo庫的做法，使用一個(gè)隊(duì)列，需要寫日志時(shí)，將日志加入隊(duì)列中，另外一個(gè)專門的日志線程來寫日志，我給出下我的具體實(shí)現(xiàn)代碼，如果需要查看muduo庫的做法，請(qǐng)參考陳碩的書《Linux多線程服務(wù)端編程：使用muduo C++網(wǎng)絡(luò)庫》關(guān)于日志章節(jié)。注意：以下是純C++11代碼：

/** 
 * 日志類頭文件, Logger.h
 * zhangyl 2017.02.28
 **/

#ifndef __LOGGER_H__
#define __LOGGER_H__

#include 
#include 
#include 
#include 
#include 
#include 

//struct FILE;

#define LogInfo(...)        Logger::GetInstance().AddToQueue("INFO", __FILE__, __LINE__, __PRETTY_FUNCTION__, __VA_ARGS__)
#define LogWarning(...)     Logger::GetInstance().AddToQueue("WARNING", __FILE__, __LINE__, __PRETTY_FUNCTION__, __VA_ARGS__)
#define LogError(...)       Logger::GetInstance().AddToQueue("ERROR", __FILE__, __LINE__, __PRETTY_FUNCTION__, __VA_ARGS__)

class Logger
{
public:
    static Logger& GetInstance();

    void SetFileName(const char* filename);
    bool Start();
    void Stop();

    void AddToQueue(const char* pszLevel, const char* pszFile, int lineNo, const char* pszFuncSig, char* pszFmt, ...);

private:
    Logger() = default;
    Logger(const Logger& rhs) = delete;
    Logger& operator =(Logger& rhs) = delete;

    void threadfunc();

private:
    std::string                     filename_;
    FILE*                           fp_{};
    std::shared_ptr    spthread_;
    std::mutex                      mutex_;
    std::condition_variable         cv_;            //有新的日志到來的標(biāo)識(shí)
    bool                            exit_{false};
    std::list          queue_;
};

#endif //!__LOGGER_H__

/**
 * 日志類實(shí)現(xiàn)文件, Logger.cpp
 * zhangyl 2017.02.28
 **/

#include "Logger.h"
#include 
#include 
#include 
#include 

Logger& Logger::GetInstance()
{
    static Logger logger;
    return logger;
}

void Logger::SetFileName(const char* filename)
{
    filename_ = filename;
}

bool Logger::Start()
{
    if (filename_.empty())
    {
        time_t now = time(NULL);
        struct tm* t = localtime(&now);
        char timestr[64] = { 0 };
        sprintf(timestr, "%04d%02d%02d%02d%02d%02d.imserver.log", t->tm_year + 1900, t->tm_mon + 1, t->tm_mday, t->tm_hour, t->tm_min, t->tm_sec);
        filename_ = timestr;
    }

    fp_ = fopen(filename_.c_str(), "wt+");
    if (fp_ == NULL)
        return false;

    spthread_.reset(new std::thread(std::bind(&Logger::threadfunc, this)));

    return true;
}

void Logger::Stop()
{
    exit_ = true;
    cv_.notify_one();

    //等待時(shí)間線程結(jié)束
    spthread_->join();
}

void Logger::AddToQueue(const char* pszLevel, const char* pszFile, int lineNo, const char* pszFuncSig, char* pszFmt, ...)
{
    char msg[256] = { 0 };

    va_list vArgList;                            
    va_start(vArgList, pszFmt);
    vsnprintf(msg, 256, pszFmt, vArgList);
    va_end(vArgList);

    time_t now = time(NULL);
    struct tm* tmstr = localtime(&now);
    char content[512] = { 0 };
    sprintf(content, "[%04d-%02d-%02d %02d:%02d:%02d][%s][0x%04x][%s:%d %s]%s\n",
                tmstr->tm_year + 1900,
                tmstr->tm_mon + 1,
                tmstr->tm_mday,
                tmstr->tm_hour,
                tmstr->tm_min,
                tmstr->tm_sec,
                pszLevel,
                std::this_thread::get_id(),
                pszFile,
                lineNo,
                pszFuncSig,
                msg);

    {
        std::lock_guard guard(mutex_);
        queue_.emplace_back(content);
    }

    cv_.notify_one();
}

void Logger::threadfunc()
{
    if (fp_ == NULL)
        return;

    while (!exit_)
    {
        //寫日志
        std::unique_lock guard(mutex_);
        while (queue_.empty())
        {
            if (exit_)
                return;

            cv_.wait(guard);
        }

        //寫日志
        const std::string& str = queue_.front();

        fwrite((void*)str.c_str(), str.length(), 1, fp_);
        fflush(fp_);
        queue_.pop_front();
    }
}

以上代碼只是個(gè)簡化版的實(shí)現(xiàn)，使用std::list來作為隊(duì)列，使用條件變量來作為新日志到來的觸發(fā)條件。當(dāng)然，由于使用了兩個(gè)固定長度的數(shù)組，大小是256和512，如果日志數(shù)據(jù)太長，會(huì)導(dǎo)致數(shù)組溢出，這個(gè)可以根據(jù)實(shí)際需求增大緩沖區(qū)或者改用動(dòng)態(tài)長度的string類型。使用這兩個(gè)文件只要包含Logger.h，然后使用如下一行代碼啟動(dòng)日志線程就可以了：

Logger::GetInstance().Start();

生成日志，使用頭文件里面定義的三個(gè)宏LogInfo、LogWarning、LogError，當(dāng)然你也可以擴(kuò)展自己的日志級(jí)別。

二、日志里面應(yīng)該寫些什么？

我開始在試著去寫日志的時(shí)候，也走了不少彎路，無論是客戶端還是服務(wù)器端，日志寫的內(nèi)容倒是不少，但都是些廢話，雖然也報(bào)出故障，但對(duì)解決實(shí)際問題時(shí)毫無作用。尤其是在服務(wù)器上生產(chǎn)環(huán)境以后，出現(xiàn)很多問題，問題也暴露出來了，但是由于日志含有的當(dāng)時(shí)現(xiàn)場的環(huán)境信息太少，只能看到錯(cuò)誤，卻沒法追蹤問題，更別說解決問題了。我們來看兩個(gè)具體的例子：

CIULog::Log(LOG_WARNING, __FUNCSIG__, _T("Be cautious! Unhandled net data! req_ans_command=%d."), header.cmd);

這條日志記錄，只打印出一條警告信息和命令號(hào)（cmd），對(duì)具體產(chǎn)生這個(gè)警告的輸入?yún)?shù)和當(dāng)時(shí)的環(huán)境也沒進(jìn)行任何記錄，即使產(chǎn)生問題，事后也無法追蹤。再看一條

    if (!HttpRequest(osURL.str().c_str(), strResponse, true, strCookie.c_str(), NULL, false, 10))
    {
        LogError("QueryTickets1 failed");
        return false;
    }

這條日志，因?yàn)閔ttp請(qǐng)求報(bào)了個(gè)簡單的錯(cuò)誤，至于產(chǎn)生錯(cuò)誤的參數(shù)和原因一概沒有交待，這種日志如果在生產(chǎn)環(huán)境上出現(xiàn)如何去排查呢？出錯(cuò)原因可能是設(shè)置的參數(shù)非法，這是外部原因，可以解決的，甚至是交互雙方的一端傳過來的，需要對(duì)方去糾正；也可能是當(dāng)時(shí)的網(wǎng)絡(luò)故障，這個(gè)也可以解決，也不算是程序的bug，不需要解決；也可能是的bug引起的，這個(gè)需要程序作者去解決。另外，如果是服務(wù)器程序，甚至應(yīng)該在錯(cuò)誤中交待下產(chǎn)生日志的用戶id、操作類型等信息，這樣事后才能便于定位位置，進(jìn)行重現(xiàn)等。
總結(jié)起來，日志記錄應(yīng)該盡量詳細(xì)，能反映出當(dāng)時(shí)出錯(cuò)的現(xiàn)場情節(jié)、產(chǎn)生的環(huán)境等。比如一個(gè)注冊請(qǐng)求失敗，至少要描述出當(dāng)時(shí)注冊的用戶名、密碼、用戶狀態(tài)（比如是否已經(jīng)注冊）、請(qǐng)求的注冊地址等等。因?yàn)槿罩緢?bào)錯(cuò)不一定是程序bug，可能是用戶非法請(qǐng)求。日志詳細(xì)了，請(qǐng)不用擔(dān)心服務(wù)器的磁盤空間，因?yàn)橄啾容^定位錯(cuò)誤，這點(diǎn)磁盤空間還是值得的，實(shí)在不行可以定期清理日志嘛。

另外一點(diǎn)是，可以將錯(cuò)誤日志、運(yùn)行狀態(tài)日志等分開，甚至可以將程序記錄日志與業(yè)務(wù)本身日志分開，這樣排查故障時(shí)優(yōu)先查看是否有錯(cuò)誤日志文件產(chǎn)生，再去錯(cuò)誤日志里面去找，而不用在一堆日志中篩選錯(cuò)誤日志。我的很多項(xiàng)目在生產(chǎn)環(huán)境也是這么做的。

以上是關(guān)于日志的一些個(gè)人心得吧，如有一些說的不對(duì)的地方，歡迎指正。