1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style license that can be 3 // found in the LICENSE file. 4 5 #include "build/build_config.h" 6 7 // Need to include this before most other files because it defines 8 // IPC_MESSAGE_LOG_ENABLED. We need to use it to define 9 // IPC_MESSAGE_MACROS_LOG_ENABLED so render_messages.h will generate the 10 // ViewMsgLog et al. functions. 11 #include "ipc/ipc_message.h" 12 13 // On Windows, the about:ipc dialog shows IPCs; on POSIX, we hook up a 14 // logger in this file. (We implement about:ipc on Mac but implement 15 // the loggers here anyway). We need to do this real early to be sure 16 // IPC_MESSAGE_MACROS_LOG_ENABLED doesn't get undefined. 17 #if defined(OS_POSIX) && defined(IPC_MESSAGE_LOG_ENABLED) 18 #define IPC_MESSAGE_MACROS_LOG_ENABLED 19 #include "content/public/common/content_ipc_logging.h" 20 #define IPC_LOG_TABLE_ADD_ENTRY(msg_id, logger) \ 21 content::RegisterIPCLogger(msg_id, logger) 22 #include "chrome/common/all_messages.h" 23 #endif 24 25 #if defined(OS_WIN) 26 #include <windows.h> 27 #endif 28 29 #include <fstream> 30 31 #include "chrome/common/logging_chrome.h" 32 33 #include "base/command_line.h" 34 #include "base/compiler_specific.h" 35 #include "base/debug/debugger.h" 36 #include "base/debug/dump_without_crashing.h" 37 #include "base/environment.h" 38 #include "base/files/file_path.h" 39 #include "base/files/file_util.h" 40 #include "base/logging.h" 41 #include "base/path_service.h" 42 #include "base/strings/string_number_conversions.h" 43 #include "base/strings/string_util.h" 44 #include "base/strings/stringprintf.h" 45 #include "base/strings/utf_string_conversions.h" 46 #include "base/threading/thread_restrictions.h" 47 #include "base/time/time.h" 48 #include "chrome/common/chrome_constants.h" 49 #include "chrome/common/chrome_paths.h" 50 #include "chrome/common/chrome_switches.h" 51 #include "chrome/common/env_vars.h" 52 #include "ipc/ipc_logging.h" 53 54 #if defined(OS_CHROMEOS) 55 #include "chromeos/chromeos_switches.h" 56 #endif 57 58 #if defined(OS_WIN) 59 #include <initguid.h> 60 #include "base/logging_win.h" 61 #endif 62 63 namespace { 64 65 // When true, this means that error dialogs should not be shown. 66 bool dialogs_are_suppressed_ = false; 67 68 // This should be true for exactly the period between the end of 69 // InitChromeLogging() and the beginning of CleanupChromeLogging(). 70 bool chrome_logging_initialized_ = false; 71 72 // Set if we called InitChromeLogging() but failed to initialize. 73 bool chrome_logging_failed_ = false; 74 75 // This should be true for exactly the period between the end of 76 // InitChromeLogging() and the beginning of CleanupChromeLogging(). 77 bool chrome_logging_redirected_ = false; 78 79 #if defined(OS_WIN) 80 // {7FE69228-633E-4f06-80C1-527FEA23E3A7} 81 const GUID kChromeTraceProviderName = { 82 0x7fe69228, 0x633e, 0x4f06, 83 { 0x80, 0xc1, 0x52, 0x7f, 0xea, 0x23, 0xe3, 0xa7 } }; 84 #endif 85 86 // Assertion handler for logging errors that occur when dialogs are 87 // silenced. To record a new error, pass the log string associated 88 // with that error in the str parameter. 89 MSVC_DISABLE_OPTIMIZE(); 90 void SilentRuntimeAssertHandler(const std::string& str) { 91 base::debug::BreakDebugger(); 92 } 93 MSVC_ENABLE_OPTIMIZE(); 94 95 // Suppresses error/assertion dialogs and enables the logging of 96 // those errors into silenced_errors_. 97 void SuppressDialogs() { 98 if (dialogs_are_suppressed_) 99 return; 100 101 logging::SetLogAssertHandler(SilentRuntimeAssertHandler); 102 103 #if defined(OS_WIN) 104 UINT new_flags = SEM_FAILCRITICALERRORS | 105 SEM_NOGPFAULTERRORBOX | 106 SEM_NOOPENFILEERRORBOX; 107 108 // Preserve existing error mode, as discussed at http://t/dmea 109 UINT existing_flags = SetErrorMode(new_flags); 110 SetErrorMode(existing_flags | new_flags); 111 #endif 112 113 dialogs_are_suppressed_ = true; 114 } 115 116 } // anonymous namespace 117 118 namespace logging { 119 120 LoggingDestination DetermineLogMode(const CommandLine& command_line) { 121 // only use OutputDebugString in debug mode 122 #ifdef NDEBUG 123 bool enable_logging = false; 124 const char *kInvertLoggingSwitch = switches::kEnableLogging; 125 const logging::LoggingDestination kDefaultLoggingMode = logging::LOG_TO_FILE; 126 #else 127 bool enable_logging = true; 128 const char *kInvertLoggingSwitch = switches::kDisableLogging; 129 const logging::LoggingDestination kDefaultLoggingMode = logging::LOG_TO_ALL; 130 #endif 131 132 if (command_line.HasSwitch(kInvertLoggingSwitch)) 133 enable_logging = !enable_logging; 134 135 logging::LoggingDestination log_mode; 136 if (enable_logging) { 137 // Let --enable-logging=stderr force only stderr, particularly useful for 138 // non-debug builds where otherwise you can't get logs to stderr at all. 139 if (command_line.GetSwitchValueASCII(switches::kEnableLogging) == "stderr") 140 log_mode = logging::LOG_TO_SYSTEM_DEBUG_LOG; 141 else 142 log_mode = kDefaultLoggingMode; 143 } else { 144 log_mode = logging::LOG_NONE; 145 } 146 return log_mode; 147 } 148 149 #if defined(OS_CHROMEOS) 150 namespace { 151 base::FilePath SetUpSymlinkIfNeeded(const base::FilePath& symlink_path, 152 bool new_log) { 153 DCHECK(!symlink_path.empty()); 154 155 // If not starting a new log, then just log through the existing 156 // symlink, but if the symlink doesn't exist, create it. If 157 // starting a new log, then delete the old symlink and make a new 158 // one to a fresh log file. 159 base::FilePath target_path; 160 bool symlink_exists = base::PathExists(symlink_path); 161 if (new_log || !symlink_exists) { 162 target_path = GenerateTimestampedName(symlink_path, base::Time::Now()); 163 164 // We don't care if the unlink fails; we're going to continue anyway. 165 if (::unlink(symlink_path.value().c_str()) == -1) { 166 if (symlink_exists) // only warn if we might expect it to succeed. 167 DPLOG(WARNING) << "Unable to unlink " << symlink_path.value(); 168 } 169 if (!base::CreateSymbolicLink(target_path, symlink_path)) { 170 DPLOG(ERROR) << "Unable to create symlink " << symlink_path.value() 171 << " pointing at " << target_path.value(); 172 } 173 } else { 174 if (!base::ReadSymbolicLink(symlink_path, &target_path)) 175 DPLOG(ERROR) << "Unable to read symlink " << symlink_path.value(); 176 } 177 return target_path; 178 } 179 180 void RemoveSymlinkAndLog(const base::FilePath& link_path, 181 const base::FilePath& target_path) { 182 if (::unlink(link_path.value().c_str()) == -1) 183 DPLOG(WARNING) << "Unable to unlink symlink " << link_path.value(); 184 if (::unlink(target_path.value().c_str()) == -1) 185 DPLOG(WARNING) << "Unable to unlink log file " << target_path.value(); 186 } 187 188 } // anonymous namespace 189 190 base::FilePath GetSessionLogDir(const CommandLine& command_line) { 191 base::FilePath log_dir; 192 std::string log_dir_str; 193 scoped_ptr<base::Environment> env(base::Environment::Create()); 194 if (env->GetVar(env_vars::kSessionLogDir, &log_dir_str) && 195 !log_dir_str.empty()) { 196 log_dir = base::FilePath(log_dir_str); 197 } else if (command_line.HasSwitch(chromeos::switches::kLoginProfile)) { 198 PathService::Get(chrome::DIR_USER_DATA, &log_dir); 199 base::FilePath profile_dir; 200 std::string login_profile_value = 201 command_line.GetSwitchValueASCII(chromeos::switches::kLoginProfile); 202 if (login_profile_value == chrome::kLegacyProfileDir || 203 login_profile_value == chrome::kTestUserProfileDir) { 204 profile_dir = base::FilePath(login_profile_value); 205 } else { 206 // We could not use g_browser_process > profile_helper() here. 207 std::string profile_dir_str = chrome::kProfileDirPrefix; 208 profile_dir_str.append(login_profile_value); 209 profile_dir = base::FilePath(profile_dir_str); 210 } 211 log_dir = log_dir.Append(profile_dir); 212 } 213 return log_dir; 214 } 215 216 base::FilePath GetSessionLogFile(const CommandLine& command_line) { 217 return GetSessionLogDir(command_line).Append(GetLogFileName().BaseName()); 218 } 219 220 void RedirectChromeLogging(const CommandLine& command_line) { 221 if (chrome_logging_redirected_) { 222 // TODO(nkostylev): Support multiple active users. http://crbug.com/230345 223 LOG(WARNING) << "NOT redirecting logging for multi-profiles case."; 224 return; 225 } 226 227 DCHECK(!chrome_logging_redirected_) << 228 "Attempted to redirect logging when it was already initialized."; 229 230 // Redirect logs to the session log directory, if set. Otherwise 231 // defaults to the profile dir. 232 base::FilePath log_path = GetSessionLogFile(command_line); 233 234 // Creating symlink causes us to do blocking IO on UI thread. 235 // Temporarily allow it until we fix http://crbug.com/61143 236 base::ThreadRestrictions::ScopedAllowIO allow_io; 237 // Always force a new symlink when redirecting. 238 base::FilePath target_path = SetUpSymlinkIfNeeded(log_path, true); 239 240 // ChromeOS always logs through the symlink, so it shouldn't be 241 // deleted if it already exists. 242 logging::LoggingSettings settings; 243 settings.logging_dest = DetermineLogMode(command_line); 244 settings.log_file = log_path.value().c_str(); 245 if (!logging::InitLogging(settings)) { 246 DLOG(ERROR) << "Unable to initialize logging to " << log_path.value(); 247 RemoveSymlinkAndLog(log_path, target_path); 248 } else { 249 chrome_logging_redirected_ = true; 250 } 251 } 252 253 #endif // OS_CHROMEOS 254 255 void InitChromeLogging(const CommandLine& command_line, 256 OldFileDeletionState delete_old_log_file) { 257 DCHECK(!chrome_logging_initialized_) << 258 "Attempted to initialize logging when it was already initialized."; 259 260 LoggingDestination logging_dest = DetermineLogMode(command_line); 261 LogLockingState log_locking_state = LOCK_LOG_FILE; 262 base::FilePath log_path; 263 #if defined(OS_CHROMEOS) 264 base::FilePath target_path; 265 #endif 266 267 // Don't resolve the log path unless we need to. Otherwise we leave an open 268 // ALPC handle after sandbox lockdown on Windows. 269 if ((logging_dest & LOG_TO_FILE) != 0) { 270 log_path = GetLogFileName(); 271 272 #if defined(OS_CHROMEOS) 273 // For BWSI (Incognito) logins, we want to put the logs in the user 274 // profile directory that is created for the temporary session instead 275 // of in the system log directory, for privacy reasons. 276 if (command_line.HasSwitch(chromeos::switches::kGuestSession)) 277 log_path = GetSessionLogFile(command_line); 278 279 // On ChromeOS we log to the symlink. We force creation of a new 280 // symlink if we've been asked to delete the old log, since that 281 // indicates the start of a new session. 282 target_path = SetUpSymlinkIfNeeded( 283 log_path, delete_old_log_file == logging::DELETE_OLD_LOG_FILE); 284 285 // Because ChromeOS manages the move to a new session by redirecting 286 // the link, it shouldn't remove the old file in the logging code, 287 // since that will remove the newly created link instead. 288 delete_old_log_file = logging::APPEND_TO_OLD_LOG_FILE; 289 #endif 290 } else { 291 log_locking_state = DONT_LOCK_LOG_FILE; 292 } 293 294 logging::LoggingSettings settings; 295 settings.logging_dest = logging_dest; 296 settings.log_file = log_path.value().c_str(); 297 settings.lock_log = log_locking_state; 298 settings.delete_old = delete_old_log_file; 299 bool success = logging::InitLogging(settings); 300 301 #if defined(OS_CHROMEOS) 302 if (!success) { 303 DPLOG(ERROR) << "Unable to initialize logging to " << log_path.value() 304 << " (which should be a link to " << target_path.value() << ")"; 305 RemoveSymlinkAndLog(log_path, target_path); 306 chrome_logging_failed_ = true; 307 return; 308 } 309 #else 310 if (!success) { 311 DPLOG(ERROR) << "Unable to initialize logging to " << log_path.value(); 312 chrome_logging_failed_ = true; 313 return; 314 } 315 #endif 316 317 // Default to showing error dialogs. 318 if (!CommandLine::ForCurrentProcess()->HasSwitch(switches::kNoErrorDialogs)) 319 logging::SetShowErrorDialogs(true); 320 321 // we want process and thread IDs because we have a lot of things running 322 logging::SetLogItems(true, // enable_process_id 323 true, // enable_thread_id 324 true, // enable_timestamp 325 false); // enable_tickcount 326 327 // We call running in unattended mode "headless", and allow 328 // headless mode to be configured either by the Environment 329 // Variable or by the Command Line Switch. This is for 330 // automated test purposes. 331 scoped_ptr<base::Environment> env(base::Environment::Create()); 332 if (env->HasVar(env_vars::kHeadless) || 333 command_line.HasSwitch(switches::kNoErrorDialogs)) 334 SuppressDialogs(); 335 336 // Use a minimum log level if the command line asks for one, 337 // otherwise leave it at the default level (INFO). 338 if (command_line.HasSwitch(switches::kLoggingLevel)) { 339 std::string log_level = command_line.GetSwitchValueASCII( 340 switches::kLoggingLevel); 341 int level = 0; 342 if (base::StringToInt(log_level, &level) && 343 level >= 0 && level < LOG_NUM_SEVERITIES) { 344 logging::SetMinLogLevel(level); 345 } else { 346 DLOG(WARNING) << "Bad log level: " << log_level; 347 } 348 } 349 350 #if defined(OS_WIN) 351 // Enable trace control and transport through event tracing for Windows. 352 logging::LogEventProvider::Initialize(kChromeTraceProviderName); 353 #endif 354 355 chrome_logging_initialized_ = true; 356 } 357 358 // This is a no-op, but we'll keep it around in case 359 // we need to do more cleanup in the future. 360 void CleanupChromeLogging() { 361 if (chrome_logging_failed_) 362 return; // We failed to initiailize logging, no cleanup. 363 364 DCHECK(chrome_logging_initialized_) << 365 "Attempted to clean up logging when it wasn't initialized."; 366 367 CloseLogFile(); 368 369 chrome_logging_initialized_ = false; 370 chrome_logging_redirected_ = false; 371 } 372 373 base::FilePath GetLogFileName() { 374 std::string filename; 375 scoped_ptr<base::Environment> env(base::Environment::Create()); 376 if (env->GetVar(env_vars::kLogFileName, &filename) && !filename.empty()) 377 return base::FilePath::FromUTF8Unsafe(filename); 378 379 const base::FilePath log_filename(FILE_PATH_LITERAL("chrome_debug.log")); 380 base::FilePath log_path; 381 382 if (PathService::Get(chrome::DIR_LOGS, &log_path)) { 383 log_path = log_path.Append(log_filename); 384 return log_path; 385 } else { 386 // error with path service, just use some default file somewhere 387 return log_filename; 388 } 389 } 390 391 bool DialogsAreSuppressed() { 392 return dialogs_are_suppressed_; 393 } 394 395 size_t GetFatalAssertions(AssertionList* assertions) { 396 // In this function, we don't assume that assertions is non-null, so 397 // that if you just want an assertion count, you can pass in NULL. 398 if (assertions) 399 assertions->clear(); 400 size_t assertion_count = 0; 401 402 std::ifstream log_file; 403 log_file.open(GetLogFileName().value().c_str()); 404 if (!log_file.is_open()) 405 return 0; 406 407 std::string utf8_line; 408 std::wstring wide_line; 409 while (!log_file.eof()) { 410 getline(log_file, utf8_line); 411 if (utf8_line.find(":FATAL:") != std::string::npos) { 412 wide_line = base::UTF8ToWide(utf8_line); 413 if (assertions) 414 assertions->push_back(wide_line); 415 ++assertion_count; 416 } 417 } 418 log_file.close(); 419 420 return assertion_count; 421 } 422 423 base::FilePath GenerateTimestampedName(const base::FilePath& base_path, 424 base::Time timestamp) { 425 base::Time::Exploded time_deets; 426 timestamp.LocalExplode(&time_deets); 427 std::string suffix = base::StringPrintf("_%02d%02d%02d-%02d%02d%02d", 428 time_deets.year, 429 time_deets.month, 430 time_deets.day_of_month, 431 time_deets.hour, 432 time_deets.minute, 433 time_deets.second); 434 return base_path.InsertBeforeExtensionASCII(suffix); 435 } 436 437 } // namespace logging 438
