笔者在写作本章节的时候，并不敢把此章节的标题叫做《高性能日志系统的设计》，之所以不敢加上“高性能”三个字的原因是，第一，我的对于日志系统设计知识和经验都来自于学习和工作经验，我并不是原创者，只是知识的搬运工；第二，目前有许多优秀的、被广泛使用的开源的日志系统，他们给了我很多启发，不敢在此班门弄斧。不管怎样，笔者还是想写一些自己关于对日志系统的理解和经验，让我们开始吧。
为什么需要日志
实际的软件项目产出都有一个流程，即先开发、测试，再发布生产，由于人的因素，既然是软件产品就不可能百分百没有bug或者逻辑错误，对于已经发布了生产的项目，一旦某个时刻产生非预期的结果，我们就需要去定位和排查问题。但是一般正式的生产环境的服务器或者产品是不允许开发人员通过附加调试器去排查问题的，主要有如下可能原因：
- 在一些大的互联网公司或者部门分工明确的公司，开发部门、测试部分和产品运维部门是分工明确的，软件产品一旦发布到生产环境以后，将全部交由运维部门人员去管理和维护，而原来开发此产品的开发人员不再拥有相关的操作程序的权限。
- 对于已经上了生产环境的服务，其数据是公司的核心产值所在，一般不允许或者不敢被开发人员随意调试或者操作，以免对公司造成损失。
- 发布到生产环境的服务，一般为了让程序执行效率更高、文件体积更小，都是去掉调试符号后的版本，不方便也不利于调试。
既然我们无法通过调试器去调试，这个时候我们为了跟踪和回忆当时的程序行为进而定位问题，我们就需要日志系统。
退一步说，即使在开发或者测试环境，我们可以把程序附加到调试器上去调试，但是对于一些特定的程序行为，我们无法通过设置断点，让程序在某个时刻暂停下来进行调试。例如，对于某些网络通信功能，如果暂停时间过长（相对于操作系统的操作来说），通信的对端可能由于彼端没有在规定时间内响应而断开连接，导致程序逻辑无法进入我们想要的执行流中去；再例如，对于一些高频操作（如心跳包、定时器、界面绘制下的某些高频重复行为），可能在少量次数下无法触发我们想要的行为，而通过断点的暂停方式，我们不得不重复操作几十次、上百次甚至更多，这样排查问题效率是非常低下的。对于这类操作，我们可以通过打印日志，将当时的程序行为上下文现场记录下来，然后从日志系统中找到某次不正常的行为的上下文信息。这也是日志的另外一个作用。
本文将从技术和业务上两个方面来介绍日志系统相关的设计与开发，所谓技术上，就是如何从程序开发的角度设计一款功能强大、性能优越、使用方便的日志系统；而业务上，是指我们在使用日志系统时，应该去记录哪些行为和数据，既简洁、不啰嗦，又方便需要时准确快速地定位问题。
日志系统的技术上的实现
日志的最初的原型即将程序运行的状态打印出来，对于C/C 这门语言来说，即可以利用printf、std::cout等控制台输出函数，将日志信息输出到控制台，这类简单的情形我们不在此过多赘述。
对于，实际的商业项目，为了方便排查问题，我们一般不将日志写到控制台，而是输出到文件或者数据库系统。不管哪一种，其思路基本上一致，我们这里以写文件为例来详细介绍。
同步写日志
所谓同步写日志，指的是在输出日志的地方，将日志即时写入到文件中去。根据笔者的经验，这种设计广泛地用于相当数量的客户端软件。笔者曾从事过数年的客户端开发（包括pc、安卓版本），设计过一些功能复杂的金融客户端产品，在这些系统中采用的就是这种同步写日志的方式。之所以使用这种方式其主要原因就是设计简单，而又不会影响用户使用体验。说到这里读者可能有这样一个疑问：一般的客户端软件，一般存在界面，而界面部分所属的逻辑就是程序的主线程，如果采取这种同步写日志的方式，当写日志时，写文件是磁盘IO操作，相比较程序其他部分是CPU操作，前者要慢很多，这样势必造成CPU等待，进而导致主线程“卡”在写文件处，进而造成界面卡顿，从而导致用户使用软件的体验不好。读者的这种顾虑确实是存在的。但是，很多时候我们不用担心这种问题，主要有两个原因：
- 对于客户端程序，即使在主线程（UI线程）中同步写文件，其单次或者几次磁盘操作累加时间，与人（用户）的可感知时间相比，也是非常小的，也就是说用户根本感觉不到这种同步写文件造成的延迟。当然，这里也给您一个提醒就是，如果在UI线程里面写日志，尤其是在一些高频操作中（如Windows的界面绘制消息WM_PAINT处理逻辑中），一定要控制写日志的长度和次数，否则就会因频繁写文件和一次写入数据过大而对界面造成卡顿。
- 客户端程序除了UI线程，还有其他与界面无关的工作线程，在这些线程中直接写文件，一般不会对用户的体验产生什么影响。
说了这么多，我们给出一个具体的例子。
日志类的.h文件
代码语言：javascript复制 1/**
2 *@desc: IULog.h
3 *@author: zhangyl
4 *@date: 2014.12.25
5 */
6#ifndef __LOG_H__
7#define __LOG_H__
8
9enum LOG_LEVEL
10{
11 LOG_LEVEL_INFO,
12 LOG_LEVEL_WARNING,
13 LOG_LEVEL_ERROR
14};
15
16//注意：如果打印的日志信息中有中文，则格式化字符串要用_T()宏包裹起来，
17#define LOG_INFO(...) CIULog::Log(LOG_LEVEL_INFO, __FUNCSIG__,__LINE__, __VA_ARGS__)
18#define LOG_WARNING(...) CIULog::Log(LOG_LEVEL_WARNING, __FUNCSIG__, __LINE__,__VA_ARGS__)
19#define LOG_ERROR(...) CIULog::Log(LOG_LEVEL_ERROR, __FUNCSIG__,__LINE__, __VA_ARGS__)
20
21class CIULog
22{
23public:
24 static bool Init(bool bToFile, bool bTruncateLongLog, PCTSTR pszLogFileName);
25 static void Uninit();
26
27 static void SetLevel(LOG_LEVEL nLevel);
28
29 //不输出线程ID号和所在函数签名、行号
30 static bool Log(long nLevel, PCTSTR pszFmt, ...);
31 //输出线程ID号和所在函数签名、行号
32 static bool Log(long nLevel, PCSTR pszFunctionSig, int nLineNo, PCTSTR pszFmt, ...); //注意:pszFunctionSig参数为Ansic版本
33 static bool Log(long nLevel, PCSTR pszFunctionSig, int nLineNo, PCSTR pszFmt, ...);
34private:
35 CIULog() = delete;
36 ~CIULog() = delete;
37
38 CIULog(const CIULog& rhs) = delete;
39 CIULog& operator=(const CIULog& rhs) = delete;
40
41 static void GetTime(char* pszTime, int nTimeStrLength);
42
43private:
44 static bool m_bToFile; //日志写入文件还是写到控制台
45 static HANDLE m_hLogFile;
46 static bool m_bTruncateLongLog; //长日志是否截断
47 static LOG_LEVEL m_nLogLevel; //日志级别
48};
49
50#endif // !__LOG_H__日志的cpp文件（实现文件）
代码语言：javascript复制 1/**
2 *@desc: IULog.cpp
3 *@author: zhangyl
4 *@date: 2014.12.25
5 */
6#include "stdafx.h"
7#include "IULog.h"
8#include "EncodingUtil.h"
9#include <tchar.h>
10
11#ifndef LOG_OUTPUT
12#define LOG_OUTPUT
13#endif
14
15#define MAX_LINE_LENGTH 256
16
17bool CIULog::m_bToFile = false;
18bool CIULog::m_bTruncateLongLog = false;
19HANDLE CIULog::m_hLogFile = INVALID_HANDLE_VALUE;
20LOG_LEVEL CIULog::m_nLogLevel = LOG_LEVEL_INFO;
21
22bool CIULog::Init(bool bToFile, bool bTruncateLongLog, PCTSTR pszLogFileName)
23{
24#ifdef LOG_OUTPUT
25 m_bToFile = bToFile;
26 m_bTruncateLongLog = bTruncateLongLog;
27
28 if (pszLogFileName == NULL || pszLogFileName[0] == NULL)
29 return FALSE;
30
31 TCHAR szHomePath[MAX_PATH] = {0};
32 ::GetModuleFileName(NULL, szHomePath, MAX_PATH);
33 for (int i = _tcslen(szHomePath); i >= 0; --i)
34 {
35 if (szHomePath[i] == _T('\'))
36 {
37 szHomePath[i] = _T(' ');
38 break;
39 }
40 }
41
42 TCHAR szLogDirectory[MAX_PATH] = { 0 };
43 _stprintf_s(szLogDirectory, _T("%s\Logs\"), szHomePath);
44
45 DWORD dwAttr = ::GetFileAttributes(szLogDirectory);
46 if (!((dwAttr != 0xFFFFFFFF) && (dwAttr & FILE_ATTRIBUTE_DIRECTORY)))
47 {
48 TCHAR cPath[MAX_PATH] = { 0 };
49 TCHAR cTmpPath[MAX_PATH] = { 0 };
50 TCHAR* lpPos = NULL;
51 TCHAR cTmp = _T(' ');
52
53 _tcsncpy_s(cPath, szLogDirectory, MAX_PATH);
54
55 for (int i = 0; i < (int)_tcslen(cPath); i )
56 {
57 if (_T('\') == cPath[i])
58 cPath[i] = _T('/');
59 }
60
61 lpPos = _tcschr(cPath, _T('/'));
62 while (lpPos != NULL)
63 {
64 if (lpPos == cPath)
65 {
66 lpPos ;
67 }
68 else
69 {
70 cTmp = *lpPos;
71 *lpPos = _T(' ');
72 _tcsncpy_s(cTmpPath, cPath, MAX_PATH);
73 ::CreateDirectory(cTmpPath, NULL);
74 *lpPos = cTmp;
75 lpPos ;
76 }
77 lpPos = _tcschr(lpPos, _T('/'));
78 }
79 }
80
81 m_hLogFile = ::CreateFile(pszLogFileName, GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ, NULL, CREATE_NEW, FILE_ATTRIBUTE_NORMAL, NULL);
82 if (m_hLogFile == INVALID_HANDLE_VALUE)
83 return false;
84
85#endif // end LOG_OUTPUT
86
87 return true;
88}
89
90void CIULog::Uninit()
91{
92#ifdef LOG_OUTPUT
93 if(m_hLogFile != INVALID_HANDLE_VALUE)
94 {
95 ::CloseHandle(m_hLogFile);
96 m_hLogFile = INVALID_HANDLE_VALUE;
97 }
98#endif //end LOG_OUTPUT
99}
100
101void CIULog::SetLevel(LOG_LEVEL nLevel)
102{
103 m_nLogLevel = nLevel;
104}
105
106bool CIULog::Log(long nLevel, PCTSTR pszFmt, ...)
107{
108#ifdef LOG_OUTPUT
109 if (nLevel < m_nLogLevel)
110 return false;
111
112 char szTime[64] = { 0 };
113 GetTime(szTime,ARRAYSIZE(szTime));
114 std::string strDebugInfo(szTime);
115
116 std::string strLevel("[INFO]");
117 if (nLevel == LOG_LEVEL_WARNING)
118 strLevel = "[Warning]";
119 else if (nLevel == LOG_LEVEL_ERROR)
120 strLevel = "[Error]";
121
122 strDebugInfo = strLevel;
123
124 //当前线程信息
125 char szThreadID[32] = { 0 };
126 DWORD dwThreadID = ::GetCurrentThreadId();
127 sprintf_s(szThreadID, ARRAYSIZE(szThreadID), "[ThreadID: %u]", dwThreadID);
128 strDebugInfo = szThreadID;
129
130 //log正文
131 std::wstring strLogMsg;
132 va_list ap;
133 va_start(ap, pszFmt);
134 int nLogMsgLength = _vsctprintf(pszFmt, ap);
135 //容量必须算上最后一个
136 if ((int)strLogMsg.capacity() < nLogMsgLength 1)
137 {
138 strLogMsg.resize(nLogMsgLength 1);
139 }
140 _vstprintf_s((TCHAR*)strLogMsg.data(), strLogMsg.capacity(), pszFmt, ap);
141 va_end(ap);
142
143 //string内容正确但length不对，恢复一下其length
144 std::wstring strMsgFormal;
145 strMsgFormal.append(strLogMsg.c_str(), nLogMsgLength);
146
147 //如果日志开启截断，长日志只取前MAX_LINE_LENGTH个字符
148 if (m_bTruncateLongLog)
149 strMsgFormal = strMsgFormal.substr(0, MAX_LINE_LENGTH);
150
151 std::string strLogMsgAscii;
152 strLogMsgAscii = EncodeUtil::UnicodeToAnsi(strMsgFormal);
153
154 strDebugInfo = strLogMsgAscii;
155 strDebugInfo = "rn";
156
157 if(m_bToFile)
158 {
159 if(m_hLogFile == INVALID_HANDLE_VALUE)
160 return false;
161
162 ::SetFilePointer(m_hLogFile, 0, NULL, FILE_END);
163 DWORD dwBytesWritten = 0;
164 ::WriteFile(m_hLogFile, strDebugInfo.c_str(), strDebugInfo.length(), &dwBytesWritten, NULL);
165 ::FlushFileBuffers(m_hLogFile);
166 return true;
167 }
168
169 ::OutputDebugStringA(strDebugInfo.c_str());
170
171#endif // end LOG_OUTPUT
172
173 return true;
174}
175
176bool CIULog::Log(long nLevel, PCSTR pszFunctionSig, int nLineNo, PCTSTR pszFmt, ...)
177{
178#ifdef LOG_OUTPUT
179 if (nLevel < m_nLogLevel)
180 return false;
181
182 //时间
183 char szTime[64] = { 0 };
184 GetTime(szTime, ARRAYSIZE(szTime));
185 std::string strDebugInfo(szTime);
186
187 //错误级别
188 std::string strLevel("[INFO]");
189 if (nLevel == LOG_LEVEL_WARNING)
190 strLevel = "[Warning]";
191 else if (nLevel == LOG_LEVEL_ERROR)
192 strLevel = "[Error]";
193
194 strDebugInfo = strLevel;
195
196 //当前线程信息
197 char szThreadID[32] = {0};
198 DWORD dwThreadID = ::GetCurrentThreadId();
199 sprintf_s(szThreadID, ARRAYSIZE(szThreadID), "[ThreadID: %u]", dwThreadID);
200 strDebugInfo = szThreadID;
201
202 //函数签名
203 char szFuncSig[512] = { 0 };
204 sprintf_s(szFuncSig, "[%s:%d]", pszFunctionSig, nLineNo);
205 strDebugInfo = szFuncSig;
206
207 //log正文
208 std::wstring strLogMsg;
209 va_list ap;
210 va_start(ap, pszFmt);
211 int nLogMsgLength = _vsctprintf(pszFmt, ap);
212 //容量必须算上最后一个
213 if ((int)strLogMsg.capacity() < nLogMsgLength 1)
214 {
215 strLogMsg.resize(nLogMsgLength 1);
216 }
217 _vstprintf_s((TCHAR*)strLogMsg.data(), strLogMsg.capacity(), pszFmt, ap);
218 va_end(ap);
219
220 //string内容正确但length不对，恢复一下其length
221 std::wstring strMsgFormal;
222 strMsgFormal.append(strLogMsg.c_str(), nLogMsgLength);
223
224 //如果日志开启截断，长日志只取前MAX_LINE_LENGTH个字符
225 if (m_bTruncateLongLog)
226 strMsgFormal = strMsgFormal.substr(0, MAX_LINE_LENGTH);
227
228 std::string strLogMsgAscii;
229 strLogMsgAscii = EncodeUtil::UnicodeToAnsi(strMsgFormal);
230
231 strDebugInfo = strLogMsgAscii;
232 strDebugInfo = "rn";
233
234 if(m_bToFile)
235 {
236 if(m_hLogFile == INVALID_HANDLE_VALUE)
237 return false;
238
239 ::SetFilePointer(m_hLogFile, 0, NULL, FILE_END);
240 DWORD dwBytesWritten = 0;
241 ::WriteFile(m_hLogFile, strDebugInfo.c_str(), strDebugInfo.length(), &dwBytesWritten, NULL);
242 ::FlushFileBuffers(m_hLogFile);
243 return true;
244 }
245
246 ::OutputDebugStringA(strDebugInfo.c_str());
247
248#endif // end LOG_OUTPUT
249
250 return true;
251}
252
253bool CIULog::Log(long nLevel, PCSTR pszFunctionSig, int nLineNo, PCSTR pszFmt, ...)
254{
255#ifdef LOG_OUTPUT
256 if (nLevel < m_nLogLevel)
257 return false;
258
259 //时间
260 char szTime[64] = { 0 };
261 GetTime(szTime, ARRAYSIZE(szTime));
262 std::string strDebugInfo(szTime);
263
264 //错误级别
265 std::string strLevel("[INFO]");
266 if (nLevel == LOG_LEVEL_WARNING)
267 strLevel = "[Warning]";
268 else if (nLevel == LOG_LEVEL_ERROR)
269 strLevel = "[Error]";
270
271 strDebugInfo = strLevel;
272
273 //当前线程信息
274 char szThreadID[32] = {0};
275 DWORD dwThreadID = ::GetCurrentThreadId();
276 sprintf_s(szThreadID, ARRAYSIZE(szThreadID), "[ThreadID: %u]", dwThreadID);
277 strDebugInfo = szThreadID;
278
279 //函数签名
280 char szFuncSig[512] = { 0 };
281 sprintf_s(szFuncSig, "[%s:%d]", pszFunctionSig, nLineNo);
282 strDebugInfo = szFuncSig;
283
284 //日志正文
285 std::string strLogMsg;
286 va_list ap;
287 va_start(ap, pszFmt);
288 int nLogMsgLength = _vscprintf(pszFmt, ap);
289 //容量必须算上最后一个
290 if ((int)strLogMsg.capacity() < nLogMsgLength 1)
291 {
292 strLogMsg.resize(nLogMsgLength 1);
293 }
294 vsprintf_s((char*)strLogMsg.data(), strLogMsg.capacity(), pszFmt, ap);
295 va_end(ap);
296
297 //string内容正确但length不对，恢复一下其length
298 std::string strMsgFormal;
299 strMsgFormal.append(strLogMsg.c_str(), nLogMsgLength);
300
301 //如果日志开启截断，长日志只取前MAX_LINE_LENGTH个字符
302 if (m_bTruncateLongLog)
303 strMsgFormal = strMsgFormal.substr(0, MAX_LINE_LENGTH);
304
305 strDebugInfo = strMsgFormal;
306 strDebugInfo = "rn";
307
308 if(m_bToFile)
309 {
310 if(m_hLogFile == INVALID_HANDLE_VALUE)
311 return false;
312
313 ::SetFilePointer(m_hLogFile, 0, NULL, FILE_END);
314 DWORD dwBytesWritten = 0;
315 ::WriteFile(m_hLogFile, strDebugInfo.c_str(), strDebugInfo.length(), &dwBytesWritten, NULL);
316 ::FlushFileBuffers(m_hLogFile);
317 return true;
318 }
319
320 ::OutputDebugStringA(strDebugInfo.c_str());
321
322#endif // end LOG_OUTPUT
323
324 return true;
325}
326
327void CIULog::GetTime(char* pszTime, int nTimeStrLength)
328{
329 SYSTEMTIME st = {0};
330 ::GetLocalTime(&st);
331 sprintf_s(pszTime, nTimeStrLength, "[d-d-d d:d:d:d]", st.wYear, st.wMonth, st.wDay, st.wHour, st.wMinute, st.wSecond, st.wMilliseconds);
332}上述代码中根据日志级别定义了三个宏LOG_INFO、LOG_WARNING、LOG_ERROR，如果要使用该日志模块，只需要在程序启动处的地方调用CIULog::Init函数初始化日志：
代码语言：javascript复制1SYSTEMTIME st = {0};
2::GetLocalTime(&st);
3TCHAR szLogFileName[MAX_PATH] = {0};
4_stprintf_s(szLogFileName, MAX_PATH, _T("%s\Logs\dddddd.log"), g_szHomePath, st.wYear, st.wMonth, st.wDay, st.wHour, st.wMinute, st.wSecond);
5CIULog::Init(true, false, szLogFileName);当然，最佳的做法，在程序退出的地方，调用CIULog::Uninit回收日志模块相关的资源：
代码语言：javascript复制1CIULog::Uninit();在做好这些准备工作以后，如果你想在程序的某个地方写一条日志，只需要这样写：
代码语言：javascript复制1LOG_INFO("Request logon: Account=%s, Password=*****, Status=%d, LoginType=%d.", pLoginRequest->m_szAccountName, pLoginRequest->m_szPassword, pLoginRequest->m_nStatus, (long)pLoginRequest->m_nLoginType);
2LOG_WARN("Some warning...");
3LOG_ERROR("Recv data error, errorNO=%d.", ::WSAGetLastError());关于CIULog这个日志模块类，如果读者要想实际运行查看效果，可以从链接（https://github.com/baloonwj/flamingo/tree/master/flamingoclient）下载完整的项目代码来运行。该日志输出效果如下：
代码语言：javascript复制 1[2018-11-09 23:52:54:0826][INFO][ThreadID: 7252][bool __thiscall CIUSocket::Login(const char *,const char *,int,int,int,class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > &):1107]Request logon: Account=zhangy, Password=*****, Status=76283204, LoginType=1.
2[2018-11-09 23:52:56:0352][INFO][ThreadID: 5828][void __thiscall CIUSocket::SendThreadProc(void):794]Recv data thread start...
3[2018-11-09 23:52:56:0385][INFO][ThreadID: 6032][void __thiscall CSendMsgThread::HandleUserBasicInfo(const class CUserBasicInfoRequest *):298]Request to get userinfo.
4[2018-11-09 23:52:56:0355][INFO][ThreadID: 7140][void __thiscall CIUSocket::RecvThreadProc(void):842]Recv data thread start...
5[2018-11-09 23:52:57:0254][INFO][ThreadID: 7220][int __thiscall CRecvMsgThread::HandleFriendListInfo(const class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > &):593]Recv user basic info, info count=1:
6[2018-11-09 23:52:57:0685][INFO][ThreadID: 6032][void __thiscall CSendMsgThread::HandleGroupBasicInfo(const class CGroupBasicInfoRequest *):336]Request to get group members, groupid=268435457.
7[2018-11-09 23:52:57:0809][INFO][ThreadID: 8184][bool __thiscall CIUSocket::ConnectToImgServer(int):428]Connect to img server:120.55.94.78, port:20002 successfully.
8[2018-11-09 23:52:58:0048][INFO][ThreadID: 6032][void __thiscall CSendMsgThread::HandleGroupBasicInfo(const class CGroupBasicInfoRequest *):336]Request to get group members, groupid=268435458.
9[2018-11-09 23:52:58:0084][INFO][ThreadID: 7220][int __thiscall CRecvMsgThread::HandleGroupBasicInfo(const class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > &):671]Recv group member info, groupid=268435457, info count=29:
10[2018-11-09 23:52:58:0500][Error][ThreadID: 8184][long __thiscall CImageTaskThread::DownloadImage(const char *,const wchar_t *,int,struct HWND__ *,void *):568]Download img failed: read filesize error, filesize=0, img name=be19574dcdd11fb9a96cf00f7e5f0e66
11[2018-11-09 23:52:58:0943][INFO][ThreadID: 6032][void __thiscall CSendMsgThread::HandleGroupBasicInfo(const class CGroupBasicInfoRequest *):336]Request to get group members, groupid=268435485.
12[2018-11-09 23:52:59:0310][INFO][ThreadID: 7220][int __thiscall CRecvMsgThread::HandleGroupBasicInfo(const class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > &):671]Recv group member info, groupid=268435458, info count=7:
13[2018-11-09 23:52:59:0508][Error][ThreadID: 8184][long __thiscall CImageTaskThread::DownloadImage(const char *,const wchar_t *,int,struct HWND__ *,void *):619]Failed to download image: F:mycodeflamingoXflamingoclientSource..BinUserszhangyUserThumb15.png.多线程同步写日志出现的问题一
从上面的日志输出来看，这种同步的日志输出方式，也存在时间顺序不正确的问题（时间戳大的日志比时间戳小的日志靠前）。这是由于多线程同时写日志到同一个文件时，产生日志的时间和实际写入磁盘的时间不是一个原子操作。下图解释了该现象出现的根源：
多线程写同一个日志文件出现先产生的日志后写入到文件中的现象
好在这种时间顺序不正确只会出现在不同线程之间，对于同一个线程的不同时间的日志记录顺序肯定是正确的。所以这种日期错乱现象，并不影响我们使用日志。
多线程同步写日志出现的问题二
多线程同时写入同一个日志文件还有一个问题，就是假设线程A写某一个时刻追加日志内容为“AAAAA”，线程B在同一时刻追加日志内容为“BBBBB”，线程C在同一时刻追加日志内容为“CCCCC”，那么最终的日志文件中的内容会不会出现“AABBCCABCAACCBB”这种格式？
在类Unix系统上（包括linux），同一个进程内针对同一个FILE*的操作是线程安全的，也就是说，在这类操作系统上得到的日志结果A、B、C各个字母组一定是连续在一起，也就是说最终得到的日志内容可能是“AAAAACCCCCBBBBB”或“AAAAABBBBBCCCCC”等这种连续的格式，绝不会出现A、B、C字母相间的现象。
而在Windows系统上，对于FILE*的操作并不是线程安全的。但是笔者做了大量实验，在Windows系统上也没有出现这种A、B、C字母相间的现象。（关于这个问题的讨论，可以参考这里：https://www.zhihu.com/question/40472431）
加上这种同步日志的实现方式，一般用于低频写日志的软件系统中（如客户端软件），所以，我们可以认为这种多线程同时写日志到一个文件中是可行的。
