| OLD | NEW |
| (Empty) |
| 1 // Copyright 2006-2009 Google Inc. | |
| 2 // | |
| 3 // Licensed under the Apache License, Version 2.0 (the "License"); | |
| 4 // you may not use this file except in compliance with the License. | |
| 5 // You may obtain a copy of the License at | |
| 6 // | |
| 7 // http://www.apache.org/licenses/LICENSE-2.0 | |
| 8 // | |
| 9 // Unless required by applicable law or agreed to in writing, software | |
| 10 // distributed under the License is distributed on an "AS IS" BASIS, | |
| 11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | |
| 12 // See the License for the specific language governing permissions and | |
| 13 // limitations under the License. | |
| 14 // ======================================================================== | |
| 15 | |
| 16 // This is code that defines the backend for the new LogMessage definition | |
| 17 // and the functions that the client application can call to control logging. | |
| 18 | |
| 19 #include <ctime> | |
| 20 #include <iomanip> | |
| 21 #include <cstring> | |
| 22 #include <windows.h> | |
| 23 #include <tchar.h> | |
| 24 #include <algorithm> | |
| 25 #include "omaha/base/logging/logging.h" | |
| 26 | |
| 27 namespace logging { | |
| 28 | |
| 29 const char* const log_severity_names[LOG_NUM_SEVERITIES] = { | |
| 30 "INFO", "WARNING", "ERROR", "FATAL" }; | |
| 31 | |
| 32 int min_log_level = 0; | |
| 33 LogLockingState lock_log_file = LOCK_LOG_FILE; | |
| 34 LoggingDestination logging_destination = LOG_ONLY_TO_FILE; | |
| 35 | |
| 36 // which log file to use? This is initialized by InitLogging or | |
| 37 // will be lazily initialized to the default value when it is | |
| 38 // first needed. | |
| 39 TCHAR log_file_name[MAX_PATH] = { 0 }; | |
| 40 | |
| 41 // this file is lazily opened and the handle may be NULL | |
| 42 HANDLE log_file = NULL; | |
| 43 | |
| 44 // what should be prepended to each message? | |
| 45 bool log_process_id = false; | |
| 46 bool log_thread_id = false; | |
| 47 bool log_timestamp = true; | |
| 48 bool log_tickcount = false; | |
| 49 | |
| 50 // An assert handler override specified by the client to be called instead of | |
| 51 // the debug message dialog. | |
| 52 LogAssertHandlerFunction log_assert_handler = NULL; | |
| 53 | |
| 54 // The critical section is used if log file locking is false. It helps us | |
| 55 // avoid problems with multiple threads writing to the log file at the same | |
| 56 // time. | |
| 57 bool initialized_critical_section = false; | |
| 58 CRITICAL_SECTION log_critical_section; | |
| 59 | |
| 60 // When we don't use a critical section, we are using a global mutex. We | |
| 61 // need to do this because LockFileEx is not thread safe | |
| 62 HANDLE log_mutex = NULL; | |
| 63 | |
| 64 void InitLogMutex() { | |
| 65 if (!log_mutex) { | |
| 66 // \ is not a legal character in mutex names so we replace \ with / | |
| 67 std::wstring safe_name(log_file_name); | |
| 68 std::replace(safe_name.begin(), safe_name.end(), '\\', '/'); | |
| 69 std::wstring t(L"Global\\"); | |
| 70 t.append(safe_name); | |
| 71 log_mutex = ::CreateMutex(NULL, FALSE, t.c_str()); | |
| 72 } | |
| 73 } | |
| 74 | |
| 75 void InitLogging(const TCHAR* new_log_file, LoggingDestination logging_dest, | |
| 76 LogLockingState lock_log, OldFileDeletionState delete_old) { | |
| 77 if (log_file) { | |
| 78 // calling InitLogging twice or after some log call has already opened the | |
| 79 // default log file will re-initialize to the new options | |
| 80 CloseHandle(log_file); | |
| 81 log_file = NULL; | |
| 82 } | |
| 83 | |
| 84 lock_log_file = lock_log; | |
| 85 logging_destination = logging_dest; | |
| 86 | |
| 87 // ignore file options if logging is only to system | |
| 88 if (logging_destination == LOG_ONLY_TO_SYSTEM_DEBUG_LOG) | |
| 89 return; | |
| 90 | |
| 91 _tcsncpy(log_file_name, new_log_file, MAX_PATH); | |
| 92 log_file_name[MAX_PATH - 1] = _T('\0'); | |
| 93 if (delete_old == DELETE_OLD_LOG_FILE) | |
| 94 DeleteFile(log_file_name); | |
| 95 | |
| 96 if (lock_log_file == LOCK_LOG_FILE) { | |
| 97 InitLogMutex(); | |
| 98 } else if (!initialized_critical_section) { | |
| 99 // initialize the critical section | |
| 100 InitializeCriticalSection(&log_critical_section); | |
| 101 initialized_critical_section = true; | |
| 102 } | |
| 103 } | |
| 104 | |
| 105 void SetMinLogLevel(int level) { | |
| 106 min_log_level = level; | |
| 107 } | |
| 108 | |
| 109 void SetLogItems(bool enable_process_id, bool enable_thread_id, | |
| 110 bool enable_timestamp, bool enable_tickcount) { | |
| 111 log_process_id = enable_process_id; | |
| 112 log_thread_id = enable_thread_id; | |
| 113 log_timestamp = enable_timestamp; | |
| 114 log_tickcount = enable_tickcount; | |
| 115 } | |
| 116 | |
| 117 void SetLogAssertHandler(LogAssertHandlerFunction handler) { | |
| 118 log_assert_handler = handler; | |
| 119 } | |
| 120 | |
| 121 // Called by logging functions to ensure that debug_file is initialized | |
| 122 // and can be used for writing. Returns false if the file could not be | |
| 123 // initialized. debug_file will be NULL in this case. | |
| 124 bool VerifyLogFileHandle() { | |
| 125 if (log_file) | |
| 126 return true; | |
| 127 | |
| 128 if (!log_file_name[0]) { | |
| 129 // nobody has called InitLogging to specify a debug log file, so here we | |
| 130 // initialize the log file name to the default | |
| 131 GetModuleFileName(NULL, log_file_name, MAX_PATH); | |
| 132 TCHAR* last_backslash = _tcsrchr(log_file_name, '\\'); | |
| 133 if (last_backslash) | |
| 134 last_backslash[1] = 0; // name now ends with the backslash | |
| 135 _tcscat(log_file_name, _T("debug.log")); | |
| 136 } | |
| 137 | |
| 138 log_file = CreateFile(log_file_name, GENERIC_WRITE, | |
| 139 FILE_SHARE_READ | FILE_SHARE_WRITE, NULL, | |
| 140 OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL); | |
| 141 if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) { | |
| 142 log_file = NULL; | |
| 143 return false; | |
| 144 } | |
| 145 SetFilePointer(log_file, 0, 0, FILE_END); | |
| 146 return true; | |
| 147 } | |
| 148 | |
| 149 // Displays a message box to the user with the error message in it. For | |
| 150 // Windows programs, it's possible that the message loop is messed up on | |
| 151 // a fatal error, and creating a MessageBox will cause that message loop | |
| 152 // to be run. Instead, we try to spawn another process that displays its | |
| 153 // command line. We look for "Debug Message.exe" in the same directory as | |
| 154 // the application. If it exists, we use it, otherwise, we use a regular | |
| 155 // message box. | |
| 156 void DisplayDebugMessage(const std::string& str) { | |
| 157 if (str.empty()) | |
| 158 return; | |
| 159 | |
| 160 // look for the debug dialog program next to our application | |
| 161 wchar_t prog_name[MAX_PATH]; | |
| 162 GetModuleFileNameW(NULL, prog_name, MAX_PATH); | |
| 163 wchar_t* backslash = wcsrchr(prog_name, '\\'); | |
| 164 if (backslash) | |
| 165 backslash[1] = 0; | |
| 166 wcsncat(prog_name, L"DebugMessage.exe", MAX_PATH); | |
| 167 prog_name[MAX_PATH - 1] = L'\0'; | |
| 168 | |
| 169 // stupid CreateProcess requires a non-const command line and may modify it. | |
| 170 // We also want to use the wide string | |
| 171 int charcount = MultiByteToWideChar(CP_UTF8, 0, str.c_str(), -1, NULL, 0); | |
| 172 if (!charcount) | |
| 173 return; | |
| 174 scoped_array<wchar_t> cmdline(new wchar_t[charcount]); | |
| 175 if (!MultiByteToWideChar(CP_UTF8, 0, str.c_str(), -1, cmdline.get(), | |
| 176 charcount)) | |
| 177 return; | |
| 178 | |
| 179 STARTUPINFO startup_info; | |
| 180 memset(&startup_info, 0, sizeof(startup_info)); | |
| 181 startup_info.cb = sizeof(startup_info); | |
| 182 | |
| 183 PROCESS_INFORMATION process_info; | |
| 184 if (CreateProcessW(prog_name, cmdline.get(), NULL, NULL, false, 0, NULL, | |
| 185 NULL, &startup_info, &process_info)) { | |
| 186 WaitForSingleObject(process_info.hProcess, INFINITE); | |
| 187 CloseHandle(process_info.hThread); | |
| 188 CloseHandle(process_info.hProcess); | |
| 189 } else { | |
| 190 // debug process broken, let's just do a message box | |
| 191 MessageBoxW(NULL, cmdline.get(), L"Fatal error", MB_OK | MB_ICONHAND); | |
| 192 } | |
| 193 } | |
| 194 | |
| 195 LogMessage::LogMessage(const char* file, int line, LogSeverity severity, int) | |
| 196 : severity_(severity) { | |
| 197 Init(file, line); | |
| 198 } | |
| 199 | |
| 200 LogMessage::LogMessage(const char* file, int line, const CheckOpString& result) | |
| 201 : severity_(LOG_FATAL) { | |
| 202 Init(file, line); | |
| 203 stream_ << "Check failed: " << (*result.str_); | |
| 204 } | |
| 205 | |
| 206 LogMessage::LogMessage(const char* file, int line) | |
| 207 : severity_(LOG_INFO) { | |
| 208 Init(file, line); | |
| 209 } | |
| 210 | |
| 211 LogMessage::LogMessage(const char* file, int line, LogSeverity severity) | |
| 212 : severity_(severity) { | |
| 213 Init(file, line); | |
| 214 } | |
| 215 | |
| 216 // writes the common header info to the stream | |
| 217 void LogMessage::Init(const char* file, int line) { | |
| 218 // log only the filename | |
| 219 const char* last_slash = strrchr(file, '\\'); | |
| 220 if (last_slash) | |
| 221 file = last_slash + 1; | |
| 222 | |
| 223 // TODO(omaha): It might be nice if the columns were fixed width. | |
| 224 | |
| 225 stream_ << '['; | |
| 226 if (log_process_id) | |
| 227 stream_ << GetCurrentProcessId() << ':'; | |
| 228 if (log_thread_id) | |
| 229 stream_ << GetCurrentThreadId() << ':'; | |
| 230 if (log_timestamp) { | |
| 231 time_t t = time(NULL); | |
| 232 #if _MSC_VER >= 1400 | |
| 233 struct tm local_time = {0}; | |
| 234 localtime_s(&local_time, &t); | |
| 235 struct tm* tm_time = &local_time; | |
| 236 #else | |
| 237 struct tm* tm_time = localtime(&t); | |
| 238 #endif | |
| 239 stream_ << std::setfill('0') | |
| 240 << std::setw(2) << 1 + tm_time->tm_mon | |
| 241 << std::setw(2) << tm_time->tm_mday | |
| 242 << '/' | |
| 243 << std::setw(2) << tm_time->tm_hour | |
| 244 << std::setw(2) << tm_time->tm_min | |
| 245 << std::setw(2) << tm_time->tm_sec | |
| 246 << ':'; | |
| 247 } | |
| 248 if (log_tickcount) | |
| 249 stream_ << GetTickCount() << ':'; | |
| 250 stream_ << log_severity_names[severity_] << ":" << file << "(" << line | |
| 251 << ")] "; | |
| 252 } | |
| 253 | |
| 254 LogMessage::~LogMessage() { | |
| 255 // TODO(omaha) modify the macros so that nothing is executed when the log | |
| 256 // level is too high or there is | |
| 257 if (severity_ < min_log_level) | |
| 258 return; | |
| 259 | |
| 260 std::string str_newline(stream_.str(), stream_.pcount()); | |
| 261 str_newline.append("\r\n"); | |
| 262 if (logging_destination != LOG_ONLY_TO_FILE) | |
| 263 OutputDebugStringA(str_newline.c_str()); | |
| 264 | |
| 265 // write to log file | |
| 266 if (logging_destination != LOG_ONLY_TO_SYSTEM_DEBUG_LOG && | |
| 267 VerifyLogFileHandle()) { | |
| 268 // we can have multiple threads and/or processes, so try to prevent them | |
| 269 // from clobbering each other's writes | |
| 270 if (lock_log_file == LOCK_LOG_FILE) { | |
| 271 // Ensure that the mutex is initialized in case the client app did not | |
| 272 // call InitLogging. This is not thread safe. See below | |
| 273 InitLogMutex(); | |
| 274 | |
| 275 DWORD r = ::WaitForSingleObject(log_mutex, INFINITE); | |
| 276 DCHECK(r != WAIT_ABANDONED); | |
| 277 } else { | |
| 278 // use the critical section | |
| 279 if (!initialized_critical_section) { | |
| 280 // The client app did not call InitLogging, and so the critical section | |
| 281 // has not been created. We do this on demand, but if two threads try to | |
| 282 // do this at the same time, there will be a race condition to create | |
| 283 // the critical section. This is why InitLogging should be called from | |
| 284 // the main thread at the beginning of execution. | |
| 285 InitializeCriticalSection(&log_critical_section); | |
| 286 initialized_critical_section = true; | |
| 287 } | |
| 288 EnterCriticalSection(&log_critical_section); | |
| 289 } | |
| 290 | |
| 291 SetFilePointer(log_file, 0, 0, SEEK_END); | |
| 292 DWORD num_written; | |
| 293 WriteFile(log_file, (void*)str_newline.c_str(), (DWORD)str_newline.length(), | |
| 294 &num_written, NULL); | |
| 295 | |
| 296 if (lock_log_file == LOCK_LOG_FILE) { | |
| 297 ReleaseMutex(log_mutex); | |
| 298 } else { | |
| 299 LeaveCriticalSection(&log_critical_section); | |
| 300 } | |
| 301 } | |
| 302 | |
| 303 if (severity_ == LOG_FATAL) { | |
| 304 // display a message or break into the debugger on a fatal error | |
| 305 if (::IsDebuggerPresent()) { | |
| 306 DebugBreak(); | |
| 307 } else { | |
| 308 if (log_assert_handler) { | |
| 309 log_assert_handler(std::string(stream_.str(), stream_.pcount())); | |
| 310 } else { | |
| 311 // don't use the string with the newline, get a fresh version to send to | |
| 312 // the debug message process | |
| 313 DisplayDebugMessage(std::string(stream_.str(), stream_.pcount())); | |
| 314 TerminateProcess(GetCurrentProcess(), 1); | |
| 315 } | |
| 316 } | |
| 317 } | |
| 318 | |
| 319 // Calling stream_.str() freezes the stream buffer. A frozen buffer will | |
| 320 // not be freed during strstreambuf destruction. | |
| 321 stream_.freeze(false); | |
| 322 } | |
| 323 | |
| 324 void CloseLogFile() { | |
| 325 if (!log_file) | |
| 326 return; | |
| 327 | |
| 328 CloseHandle(log_file); | |
| 329 log_file = NULL; | |
| 330 } | |
| 331 | |
| 332 } // namespace logging | |
| 333 | |
| 334 std::ostream& operator<<(std::ostream& out, const wchar_t* wstr) { | |
| 335 if (!wstr || !wstr[0]) | |
| 336 return out; | |
| 337 | |
| 338 // compute the length of the buffer we'll need | |
| 339 int charcount = WideCharToMultiByte(CP_UTF8, 0, wstr, -1, | |
| 340 NULL, 0, NULL, NULL); | |
| 341 if (charcount == 0) | |
| 342 return out; | |
| 343 | |
| 344 // convert | |
| 345 scoped_array<char> buf(new char[charcount]); | |
| 346 WideCharToMultiByte(CP_UTF8, 0, wstr, -1, buf.get(), charcount, NULL, NULL); | |
| 347 return out << buf.get(); | |
| 348 } | |
| OLD | NEW |