Shulou(Shulou.com)06/02 Report--

The difference between server-side log and client-side log

Before we formally explain, let's take a look at the implementation of a log class, which also represents the mainstream writing of most client logs:

/ * * @ desc: the program runs the log class, 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)) # endifclass 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* masked file;} # endif / /! _ _ LOG_H__/** * @ desc: program runs log class, log.cpp * @ author: zhangyl * @ date: 2017.01.17 * * / # 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 listing 10] = {0}; va_list va; / / defines a variable of va_ list type, which is a pointer to a parameter. Va_start (va, pszFmt); / / initialize the variable with the va_start macro. The second parameter of this macro is the previous parameter of the first variable parameter, which is a fixed parameter _ vsnprintf (tmp, ARRAYSIZE (tmp), pszFmt, va); / / be careful not to leave out the preceding _ va_end (va); time_t now = time (NULL); struct tm* tmstr = localtime (& now) Char content [8192 * 10 + 256] = {0} Sprintf_s (content, ARRAYSIZE (content), "[d-d-d d:d:d] [% s] [0xx] [% SV% 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), "dddddd.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);}

The definition and implementation code of this Log class is an excerpt from my 12306 ticket swiping software. If you need to use this class, include the Log.h header file, and then use the macro: LogInfo/LogWarning/LogError these three macros. Examples are as follows:

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

This log class outputs time, log level, thread id, file name, line number, function signature and custom error messages one line at a time, as shown below:

[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 &, 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 &, 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 &, 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 &, 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=

As mentioned above, the above example is a log of a client program I have written. Pay attention to the important keyword "client". Because although the above log implementation is universal, its limitations can only be used for programs like the client that do not require high performance and efficiency (the performance and efficiency here are relative to high-concurrency and high-performance server programs, that is to say, the above log implementation can be used for most client programs, but not for high-performance and high-concurrency server programs). So what's wrong with the above procedure? The problem is inefficiency!

I do not know if the reader has noticed, the above log class implementation, is directly in the caller thread IO operation, compared with the high-speed CPU,IO disk operation is very slow, directly in some work threads (including UI thread) to write files, the program execution speed is too slow, especially when there is more log data.

This is one of the differences between server-side logs and client-side logs. Client program logs can generally be written directly on the worker thread, because this performance and time loss is negligible for most client programs. but for server programs that require high concurrency (for example, systems with millions or even tens of millions of concurrency) The amount of time spent per unit of time on disk writes is considerable. My current practice is to refer to Chen Shuo's muduo library practice, use a queue, when you need to write a log, add the log to the queue, another special log thread to write the log, I give my specific implementation code, if you need to view the practice of the muduo library, please refer to Chen Shuo's book "Linux multi-threaded server programming: using the muduo C++ network library" about the log section. Note: the following is a pure Clear11 code:

/ * Logger.h * zhangyl 2017.02.28 * * / # ifndef _ LOGGER_H__#define _ _ LOGGER_H__#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_ / / Mark bool exit_ {false}; std::list queue_;}; # endif /! _ LOGGER_H__/** * log class implementation file, Logger.cpp * zhangyl 2017.02.28 * * / # include "Logger.h" # 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, "dddddd.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 (); / / waiting time thread end 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, "[d-d-d d:d:d] [% s] [0xx] [% SV% 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_) {/ / write std::unique_lock guard (mutex_) While (queue_.empty ()) {if (exit_) return; cv_.wait (guard);} / / write log const std::string& str = queue_.front (); fwrite ((void*) str.c_str (), str.length (), 1, fp_); fflush (fp_) Queue_.pop_front ();}}

The above code is just a simplified implementation, using std::list as the queue and condition variables as the trigger for the arrival of the new log. Of course, due to the use of two fixed-length arrays of size 256and 512, if the log data is too long, it will cause the array to overflow, which can increase the buffer or switch to the dynamic length string type according to the actual need. To use these two files, simply include Logger.h, and then start the log thread with the following line of code:

Logger::GetInstance () .Start ()

To generate a log, use the three macros LogInfo, LogWarning, and LogError defined in the header file. Of course, you can also expand your log level.

Second, what should be written in the log?

When I started to try to write a log, I also took a lot of detours, both on the client side and on the server side, but it was all nonsense, and although it also reported a failure, it had no effect on solving practical problems. Especially after the production environment on the server, there are many problems, and the problems are also exposed, but because the log contains too little environmental information at that time, we can only see errors, but can not track the problem, let alone solve the problem. Let's look at two specific examples:

CIULog::Log (LOG_WARNING, _ _ FUNCSIG__, _ T ("Be cautious! Unhandled net data! req_ans_command=%d."), header.cmd)

This log record only prints a warning message and a command number (cmd), and there is no record of the specific input parameters that produced the warning and the environment at that time, and even if a problem occurs, it cannot be tracked afterwards. Look at another one.

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

This log, because the http request reported a simple error, as for the error parameters and reasons are not explained, how to troubleshoot this kind of log if it appears in the production environment? The reason for the error may be that the parameters set are illegal, which is an external reason, which can be solved, even if it is transmitted from one end of the interaction, which needs to be corrected by the other side; it may also be the network failure at that time, which can also be solved, and it is not the bug of the program, which does not need to be solved; it may also be caused by bug, which needs to be solved by the program author. In addition, if it is a server program, you should even explain the user id, operation type and other information that generated the log in the error, so that it is easy to locate the location and reproduce it afterwards.

To sum up, the log record should be as detailed as possible to reflect the scene of the error at that time, the environment and so on. For example, if a registration request fails, at least describe the user name, password, user status (such as whether it is already registered), the registration address of the request, and so on. Because the log error is not necessarily the program bug, it may be an illegal request from the user. The log is detailed, please do not worry about the disk space of the server, because compared with positioning errors, this disk space is still worth it, you can clean the log regularly.

Another point is that you can separate the error log, the running status log, and so on, or even separate the program log from the business log, so that you can first check if any error log files are generated when troubleshooting, and then go to the error log to find it. instead of filtering the error log in a pile of logs. Many of my projects do the same in a production environment.

The above is about the log of some personal experience, if there is something wrong, welcome to correct.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.