• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright 2007, Google Inc.
2 // All rights reserved.
3 //
4 // Redistribution and use in source and binary forms, with or without
5 // modification, are permitted provided that the following conditions are
6 // met:
7 //
8 //     * Redistributions of source code must retain the above copyright
9 // notice, this list of conditions and the following disclaimer.
10 //     * Redistributions in binary form must reproduce the above
11 // copyright notice, this list of conditions and the following disclaimer
12 // in the documentation and/or other materials provided with the
13 // distribution.
14 //     * Neither the name of Google Inc. nor the names of its
15 // contributors may be used to endorse or promote products derived from
16 // this software without specific prior written permission.
17 //
18 // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
19 // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
20 // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
21 // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
22 // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
23 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
24 // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
25 // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
26 // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
27 // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
28 // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
29 
30 #include <ctime>
31 #include <iomanip>
32 #include <cstring>
33 #include <windows.h>
34 #include <tchar.h>
35 #include <algorithm>
36 #include "base/logging.h"
37 
38 namespace logging {
39 
40 const char* const log_severity_names[LOG_NUM_SEVERITIES] = {
41   "INFO", "WARNING", "ERROR", "FATAL" };
42 
43 int min_log_level = 0;
44 LogLockingState lock_log_file = LOCK_LOG_FILE;
45 LoggingDestination logging_destination = LOG_ONLY_TO_FILE;
46 
47 const int kMaxFilteredLogLevel = LOG_WARNING;
48 char* log_filter_prefix = NULL;
49 
50 // which log file to use? This is initialized by InitLogging or
51 // will be lazily initialized to the default value when it is
52 // first needed.
53 TCHAR log_file_name[MAX_PATH] = { 0 };
54 
55 // this file is lazily opened and the handle may be NULL
56 HANDLE log_file = NULL;
57 
58 // what should be prepended to each message?
59 bool log_process_id = false;
60 bool log_thread_id = false;
61 bool log_timestamp = true;
62 bool log_tickcount = false;
63 
64 // An assert handler override specified by the client to be called instead of
65 // the debug message dialog.
66 LogAssertHandlerFunction log_assert_handler = NULL;
67 
68 // The critical section is used if log file locking is false. It helps us
69 // avoid problems with multiple threads writing to the log file at the same
70 // time.
71 bool initialized_critical_section = false;
72 CRITICAL_SECTION log_critical_section;
73 
74 // When we don't use a critical section, we are using a global mutex. We
75 // need to do this because LockFileEx is not thread safe
76 HANDLE log_mutex = NULL;
77 
78 // Called by logging functions to ensure that debug_file is initialized
79 // and can be used for writing. Returns false if the file could not be
80 // initialized. debug_file will be NULL in this case.
InitializeLogFileHandle()81 bool InitializeLogFileHandle() {
82   if (log_file)
83     return true;
84 
85   if (!log_file_name[0]) {
86     // nobody has called InitLogging to specify a debug log file, so here we
87     // initialize the log file name to the default
88     GetModuleFileName(NULL, log_file_name, MAX_PATH);
89     TCHAR* last_backslash = _tcsrchr(log_file_name, '\\');
90     if (last_backslash)
91       last_backslash[1] = 0; // name now ends with the backslash
92     _tcscat_s(log_file_name, _T("debug.log"));
93   }
94 
95   log_file = CreateFile(log_file_name, GENERIC_WRITE,
96                         FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
97                         OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
98   if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
99     // try the current directory
100     log_file = CreateFile(_T(".\\debug.log"), GENERIC_WRITE,
101                           FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
102                           OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
103     if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
104       log_file = NULL;
105       return false;
106     }
107   }
108   SetFilePointer(log_file, 0, 0, FILE_END);
109   return true;
110 }
111 
InitLogMutex()112 void InitLogMutex() {
113   if (!log_mutex) {
114     // \ is not a legal character in mutex names so we replace \ with /
115     std::wstring safe_name(log_file_name);
116     std::replace(safe_name.begin(), safe_name.end(), '\\', '/');
117     std::wstring t(L"Global\\");
118     t.append(safe_name);
119     log_mutex = ::CreateMutex(NULL, FALSE, t.c_str());
120   }
121 }
122 
InitLogging(const TCHAR * new_log_file,LoggingDestination logging_dest,LogLockingState lock_log,OldFileDeletionState delete_old)123 void InitLogging(const TCHAR* new_log_file, LoggingDestination logging_dest,
124                  LogLockingState lock_log, OldFileDeletionState delete_old) {
125   if (log_file) {
126     // calling InitLogging twice or after some log call has already opened the
127     // default log file will re-initialize to the new options
128     CloseHandle(log_file);
129     log_file = NULL;
130   }
131 
132   lock_log_file = lock_log;
133   logging_destination = logging_dest;
134 
135   // ignore file options if logging is only to system
136   if (logging_destination == LOG_ONLY_TO_SYSTEM_DEBUG_LOG)
137     return;
138 
139   _tcscpy_s(log_file_name, MAX_PATH, new_log_file);
140   if (delete_old == DELETE_OLD_LOG_FILE)
141     DeleteFile(log_file_name);
142 
143   if (lock_log_file == LOCK_LOG_FILE) {
144     InitLogMutex();
145   } else if (!initialized_critical_section) {
146     // initialize the critical section
147     InitializeCriticalSection(&log_critical_section);
148     initialized_critical_section = true;
149   }
150 
151   InitializeLogFileHandle();
152 }
153 
SetMinLogLevel(int level)154 void SetMinLogLevel(int level) {
155   min_log_level = level;
156 }
157 
SetLogFilterPrefix(char * filter)158 void SetLogFilterPrefix(char* filter)  {
159   if (log_filter_prefix) {
160     delete[] log_filter_prefix;
161     log_filter_prefix = NULL;
162   }
163 
164   if (filter) {
165     size_t size = strlen(filter)+1;
166     log_filter_prefix = new char[size];
167     strcpy_s(log_filter_prefix, size, filter);
168   }
169 }
170 
SetLogItems(bool enable_process_id,bool enable_thread_id,bool enable_timestamp,bool enable_tickcount)171 void SetLogItems(bool enable_process_id, bool enable_thread_id,
172                  bool enable_timestamp, bool enable_tickcount) {
173   log_process_id = enable_process_id;
174   log_thread_id = enable_thread_id;
175   log_timestamp = enable_timestamp;
176   log_tickcount = enable_tickcount;
177 }
178 
SetLogAssertHandler(LogAssertHandlerFunction handler)179 void SetLogAssertHandler(LogAssertHandlerFunction handler) {
180   log_assert_handler = handler;
181 }
182 
183 // Displays a message box to the user with the error message in it. For
184 // Windows programs, it's possible that the message loop is messed up on
185 // a fatal error, and creating a MessageBox will cause that message loop
186 // to be run. Instead, we try to spawn another process that displays its
187 // command line. We look for "Debug Message.exe" in the same directory as
188 // the application. If it exists, we use it, otherwise, we use a regular
189 // message box.
DisplayDebugMessage(const std::string & str)190 void DisplayDebugMessage(const std::string& str) {
191   if (str.empty())
192     return;
193 
194   // look for the debug dialog program next to our application
195   wchar_t prog_name[MAX_PATH];
196   GetModuleFileNameW(NULL, prog_name, MAX_PATH);
197   wchar_t* backslash = wcsrchr(prog_name, '\\');
198   if (backslash)
199     backslash[1] = 0;
200   wcscat_s(prog_name, MAX_PATH, L"debug_message.exe");
201 
202   // stupid CreateProcess requires a non-const command line and may modify it.
203   // We also want to use the wide string
204   int charcount = MultiByteToWideChar(CP_UTF8, 0, str.c_str(), -1, NULL, 0);
205   if (!charcount)
206     return;
207   scoped_array<wchar_t> cmdline(new wchar_t[charcount]);
208   if (!MultiByteToWideChar(CP_UTF8, 0, str.c_str(), -1, cmdline.get(), charcount))
209     return;
210 
211   STARTUPINFO startup_info;
212   memset(&startup_info, 0, sizeof(startup_info));
213   startup_info.cb = sizeof(startup_info);
214 
215   PROCESS_INFORMATION process_info;
216   if (CreateProcessW(prog_name, cmdline.get(), NULL, NULL, false, 0, NULL,
217                      NULL, &startup_info, &process_info)) {
218     WaitForSingleObject(process_info.hProcess, INFINITE);
219     CloseHandle(process_info.hThread);
220     CloseHandle(process_info.hProcess);
221   } else {
222     // debug process broken, let's just do a message box
223     MessageBoxW(NULL, cmdline.get(), L"Fatal error", MB_OK | MB_ICONHAND);
224   }
225 }
226 
LogMessage(const char * file,int line,LogSeverity severity,int ctr)227 LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
228                        int ctr)
229     : severity_(severity) {
230   Init(file, line);
231 }
232 
LogMessage(const char * file,int line,const CheckOpString & result)233 LogMessage::LogMessage(const char* file, int line, const CheckOpString& result)
234     : severity_(LOG_FATAL) {
235   Init(file, line);
236   stream_ << "Check failed: " << (*result.str_);
237 }
238 
LogMessage(const char * file,int line)239 LogMessage::LogMessage(const char* file, int line)
240      : severity_(LOG_INFO) {
241   Init(file, line);
242 }
243 
LogMessage(const char * file,int line,LogSeverity severity)244 LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
245     : severity_(severity) {
246   Init(file, line);
247 }
248 
249 // writes the common header info to the stream
Init(const char * file,int line)250 void LogMessage::Init(const char* file, int line) {
251   // log only the filename
252   const char* last_slash = strrchr(file, '\\');
253   if (last_slash)
254     file = last_slash + 1;
255 
256   stream_ <<  '[';
257   if (log_process_id)
258     stream_ << GetCurrentProcessId() << ':';
259   if (log_thread_id)
260     stream_ << GetCurrentThreadId() << ':';
261   if (log_timestamp) {
262     time_t t = time(NULL);
263     struct tm tm_time;
264     localtime_s(&tm_time, &t);
265     stream_ << std::setfill('0')
266             << std::setw(2) << 1 + tm_time.tm_mon
267             << std::setw(2) << tm_time.tm_mday
268             << '/'
269             << std::setw(2) << tm_time.tm_hour
270             << std::setw(2) << tm_time.tm_min
271             << std::setw(2) << tm_time.tm_sec
272             << ':';
273   }
274   if (log_tickcount)
275     stream_ << GetTickCount() << ':';
276   stream_ << log_severity_names[severity_] << ":" << file << "(" << line << ")] ";
277 
278   message_start_ = stream_.pcount();
279 }
280 
~LogMessage()281 LogMessage::~LogMessage() {
282   if (severity_ < min_log_level)
283     return;
284 
285   std::string str_newline(stream_.str(), stream_.pcount());
286   str_newline.append("\r\n");
287 
288   if (log_filter_prefix && severity_ <= kMaxFilteredLogLevel &&
289       str_newline.compare(message_start_, strlen(log_filter_prefix),
290                           log_filter_prefix) != 0) {
291     goto cleanup;
292   }
293 
294   if (logging_destination != LOG_ONLY_TO_FILE)
295     OutputDebugStringA(str_newline.c_str());
296 
297   // write to log file
298   if (logging_destination != LOG_ONLY_TO_SYSTEM_DEBUG_LOG &&
299       InitializeLogFileHandle()) {
300     // we can have multiple threads and/or processes, so try to prevent them from
301     // clobbering each other's writes
302     if (lock_log_file == LOCK_LOG_FILE) {
303       // Ensure that the mutex is initialized in case the client app did not
304       // call InitLogging. This is not thread safe. See below
305       InitLogMutex();
306 
307       DWORD r = ::WaitForSingleObject(log_mutex, INFINITE);
308       DCHECK(r != WAIT_ABANDONED);
309     } else {
310       // use the critical section
311       if (!initialized_critical_section) {
312         // The client app did not call InitLogging, and so the critical section
313         // has not been created. We do this on demand, but if two threads try to
314         // do this at the same time, there will be a race condition to create
315         // the critical section. This is why InitLogging should be called from
316         // the main thread at the beginning of execution.
317         InitializeCriticalSection(&log_critical_section);
318         initialized_critical_section = true;
319       }
320       EnterCriticalSection(&log_critical_section);
321     }
322 
323     SetFilePointer(log_file, 0, 0, SEEK_END);
324     DWORD num_written;
325     WriteFile(log_file, (void*)str_newline.c_str(), (DWORD)str_newline.length(), &num_written, NULL);
326 
327     if (lock_log_file == LOCK_LOG_FILE) {
328       ReleaseMutex(log_mutex);
329     } else {
330       LeaveCriticalSection(&log_critical_section);
331     }
332   }
333 
334   if (severity_ == LOG_FATAL) {
335     // display a message or break into the debugger on a fatal error
336     if (::IsDebuggerPresent()) {
337       DebugBreak();
338     } else {
339       if (log_assert_handler) {
340         log_assert_handler(std::string(stream_.str(), stream_.pcount()));
341       } else {
342         // don't use the string with the newline, get a fresh version to send to
343         // the debug message process
344         DisplayDebugMessage(std::string(stream_.str(), stream_.pcount()));
345         TerminateProcess(GetCurrentProcess(), 1);
346       }
347     }
348   }
349 
350 cleanup:
351   // Calling stream_.str() freezes the stream buffer.  A frozen buffer will
352   // not be freed during strstreambuf destruction.
353   stream_.freeze(false);
354 }
355 
CloseLogFile()356 void CloseLogFile() {
357   if (!log_file)
358     return;
359 
360   CloseHandle(log_file);
361   log_file = NULL;
362 }
363 
364 } // namespace logging
365 
operator <<(std::ostream & out,const wchar_t * wstr)366 std::ostream& operator<<(std::ostream& out, const wchar_t* wstr) {
367   if (!wstr || !wstr[0])
368     return out;
369 
370   // compute the length of the buffer we'll need
371   int charcount = WideCharToMultiByte(CP_UTF8, 0, wstr, -1,
372                                       NULL, 0, NULL, NULL);
373   if (charcount == 0)
374     return out;
375 
376   // convert
377   scoped_array<char> buf(new char[charcount]);
378   WideCharToMultiByte(CP_UTF8, 0, wstr, -1, buf.get(), charcount, NULL, NULL);
379   return out << buf.get();
380 }
381