blob: 9bbb878935a59bfc194a32156b8022841f8721b3 [file] [log] [blame]
[email protected]c83dd912010-04-06 18:50:511// Copyright (c) 2010 The Chromium Authors. All rights reserved.
license.botbf09a502008-08-24 00:55:552// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
initial.commit09911bf2008-07-26 23:55:294
[email protected]ec657802008-11-07 20:05:395#include "build/build_config.h"
6
[email protected]d55aaa132009-09-28 21:08:047// 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 "chrome/common/devtools_messages.h"
20#include "chrome/common/plugin_messages.h"
21#include "chrome/common/render_messages.h"
22#include "chrome/common/worker_messages.h"
23#endif
24
[email protected]ec657802008-11-07 20:05:3925#if defined(OS_WIN)
initial.commit09911bf2008-07-26 23:55:2926#include <windows.h>
[email protected]ec657802008-11-07 20:05:3927#endif
initial.commit09911bf2008-07-26 23:55:2928
initial.commit09911bf2008-07-26 23:55:2929#include <fstream>
30
31#include "chrome/common/logging_chrome.h"
32
33#include "base/command_line.h"
[email protected]0eb9f4342008-11-21 18:48:5234#include "base/compiler_specific.h"
[email protected]58580352010-10-26 04:07:5035#include "base/debug/debugger.h"
[email protected]76b90d312010-08-03 03:00:5036#include "base/environment.h"
[email protected]73e23482009-08-13 00:26:5837#include "base/file_path.h"
initial.commit09911bf2008-07-26 23:55:2938#include "base/file_util.h"
39#include "base/logging.h"
40#include "base/path_service.h"
[email protected]528c56d2010-07-30 19:28:4441#include "base/string_number_conversions.h"
[email protected]5d91c9e2010-07-28 17:25:2842#include "base/string_util.h"
[email protected]77ee1b12010-06-14 16:21:3043#include "base/time.h"
[email protected]4197e092010-03-10 00:35:0544#include "base/utf_string_conversions.h"
initial.commit09911bf2008-07-26 23:55:2945#include "chrome/common/chrome_paths.h"
46#include "chrome/common/chrome_switches.h"
initial.commit09911bf2008-07-26 23:55:2947#include "chrome/common/env_vars.h"
[email protected]51d5e162009-07-27 19:23:5448#include "ipc/ipc_logging.h"
[email protected]2b07b8412009-11-25 15:26:3449#if defined(OS_WIN)
50#include "base/logging_win.h"
51#include <initguid.h>
52#endif
initial.commit09911bf2008-07-26 23:55:2953
54// When true, this means that error dialogs should not be shown.
55static bool dialogs_are_suppressed_ = false;
56
57// This should be true for exactly the period between the end of
58// InitChromeLogging() and the beginning of CleanupChromeLogging().
59static bool chrome_logging_initialized_ = false;
60
[email protected]30f547c2010-08-04 01:00:0161// This should be true for exactly the period between the end of
62// InitChromeLogging() and the beginning of CleanupChromeLogging().
63static bool chrome_logging_redirected_ = false;
64
[email protected]2b07b8412009-11-25 15:26:3465#if defined(OS_WIN)
66// {7FE69228-633E-4f06-80C1-527FEA23E3A7}
67DEFINE_GUID(kChromeTraceProviderName,
68 0x7fe69228, 0x633e, 0x4f06, 0x80, 0xc1, 0x52, 0x7f, 0xea, 0x23, 0xe3, 0xa7);
69#endif
70
initial.commit09911bf2008-07-26 23:55:2971// Assertion handler for logging errors that occur when dialogs are
72// silenced. To record a new error, pass the log string associated
73// with that error in the str parameter.
[email protected]0eb9f4342008-11-21 18:48:5274MSVC_DISABLE_OPTIMIZE();
initial.commit09911bf2008-07-26 23:55:2975static void SilentRuntimeAssertHandler(const std::string& str) {
[email protected]58580352010-10-26 04:07:5076 base::debug::BreakDebugger();
initial.commit09911bf2008-07-26 23:55:2977}
[email protected]6cc67d7f2009-02-12 06:48:2478static void SilentRuntimeReportHandler(const std::string& str) {
79}
[email protected]0eb9f4342008-11-21 18:48:5280MSVC_ENABLE_OPTIMIZE();
initial.commit09911bf2008-07-26 23:55:2981
82// Suppresses error/assertion dialogs and enables the logging of
83// those errors into silenced_errors_.
84static void SuppressDialogs() {
85 if (dialogs_are_suppressed_)
86 return;
87
88 logging::SetLogAssertHandler(SilentRuntimeAssertHandler);
[email protected]6cc67d7f2009-02-12 06:48:2489 logging::SetLogReportHandler(SilentRuntimeReportHandler);
initial.commit09911bf2008-07-26 23:55:2990
[email protected]ec657802008-11-07 20:05:3991#if defined(OS_WIN)
initial.commit09911bf2008-07-26 23:55:2992 UINT new_flags = SEM_FAILCRITICALERRORS |
93 SEM_NOGPFAULTERRORBOX |
94 SEM_NOOPENFILEERRORBOX;
95
96 // Preserve existing error mode, as discussed at http://t/dmea
97 UINT existing_flags = SetErrorMode(new_flags);
98 SetErrorMode(existing_flags | new_flags);
[email protected]ec657802008-11-07 20:05:3999#endif
initial.commit09911bf2008-07-26 23:55:29100
101 dialogs_are_suppressed_ = true;
102}
103
104namespace logging {
105
[email protected]77ee1b12010-06-14 16:21:30106LoggingDestination DetermineLogMode(const CommandLine& command_line) {
initial.commit09911bf2008-07-26 23:55:29107 // only use OutputDebugString in debug mode
108#ifdef NDEBUG
109 bool enable_logging = false;
[email protected]b7e0a2a2009-10-13 02:07:25110 const char *kInvertLoggingSwitch = switches::kEnableLogging;
initial.commit09911bf2008-07-26 23:55:29111 const logging::LoggingDestination kDefaultLoggingMode =
112 logging::LOG_ONLY_TO_FILE;
113#else
114 bool enable_logging = true;
[email protected]b7e0a2a2009-10-13 02:07:25115 const char *kInvertLoggingSwitch = switches::kDisableLogging;
initial.commit09911bf2008-07-26 23:55:29116 const logging::LoggingDestination kDefaultLoggingMode =
117 logging::LOG_TO_BOTH_FILE_AND_SYSTEM_DEBUG_LOG;
118#endif
119
120 if (command_line.HasSwitch(kInvertLoggingSwitch))
121 enable_logging = !enable_logging;
122
123 logging::LoggingDestination log_mode;
124 if (enable_logging) {
[email protected]3bba9582009-08-05 01:29:12125 // Let --enable-logging=stderr force only stderr, particularly useful for
126 // non-debug builds where otherwise you can't get logs to stderr at all.
[email protected]c4e52f0d2009-11-06 19:55:16127 if (command_line.GetSwitchValueASCII(switches::kEnableLogging) == "stderr")
[email protected]3bba9582009-08-05 01:29:12128 log_mode = logging::LOG_ONLY_TO_SYSTEM_DEBUG_LOG;
129 else
130 log_mode = kDefaultLoggingMode;
initial.commit09911bf2008-07-26 23:55:29131 } else {
132 log_mode = logging::LOG_NONE;
133 }
[email protected]77ee1b12010-06-14 16:21:30134 return log_mode;
135}
initial.commit09911bf2008-07-26 23:55:29136
[email protected]77ee1b12010-06-14 16:21:30137#if defined(OS_CHROMEOS)
[email protected]c7d5da992010-10-28 00:20:21138namespace {
139FilePath GenerateTimestampedName(const FilePath& base_path,
140 base::Time timestamp) {
[email protected]77ee1b12010-06-14 16:21:30141 base::Time::Exploded time_deets;
142 timestamp.LocalExplode(&time_deets);
143 std::string suffix = StringPrintf("_%02d%02d%02d-%02d%02d%02d",
144 time_deets.year,
145 time_deets.month,
146 time_deets.day_of_month,
147 time_deets.hour,
148 time_deets.minute,
149 time_deets.second);
[email protected]c7d5da992010-10-28 00:20:21150 return base_path.InsertBeforeExtension(suffix);
[email protected]77ee1b12010-06-14 16:21:30151}
152
[email protected]c7d5da992010-10-28 00:20:21153FilePath SetUpSymlinkIfNeeded(const FilePath& symlink_path, bool new_log) {
154 // If not starting a new log, then just log through the existing
155 // symlink, but if the symlink doesn't exist, create it. If
156 // starting a new log, then delete the old symlink and make a new
157 // one to a fresh log file.
158 FilePath target_path;
159 if (new_log || !file_util::PathExists(symlink_path)) {
160 target_path = GenerateTimestampedName(symlink_path, base::Time::Now());
161
162 // We don't care if the unlink fails; we're going to continue anyway.
163 if (unlink(symlink_path.value().c_str()) == -1) {
164 if (new_log) // only warn if we might expect it to succeed.
165 PLOG(WARNING) << "Unable to unlink " << symlink_path.value();
166 }
167 if (symlink(target_path.value().c_str(),
168 symlink_path.value().c_str()) == -1) {
169 PLOG(ERROR) << "Unable to create symlink " << symlink_path.value()
170 << " pointing at " << target_path.value();
171 }
172 } else {
173 char buf[1024];
174 size_t count = readlink(target_path.value().c_str(), buf, sizeof(buf));
175 if (count > 0) {
176 target_path = FilePath(FilePath::StringType(buf));
177 } else {
178 PLOG(ERROR) << "Unable to read symlink " << symlink_path.value();
179 }
180 }
181 return target_path;
182}
183
184void RemoveSymlinkAndLog(const FilePath& link_path,
185 const FilePath& target_path) {
186 if (::unlink(link_path.value().c_str()) == -1)
187 PLOG(WARNING) << "Unable to unlink symlink " << link_path.value();
188 if (::unlink(target_path.value().c_str()) == -1)
189 PLOG(WARNING) << "Unable to unlink log file " << target_path.value();
190}
191
192} // anonymous namespace
193
[email protected]77ee1b12010-06-14 16:21:30194void RedirectChromeLogging(const FilePath& new_log_dir,
[email protected]c7d5da992010-10-28 00:20:21195 const CommandLine& command_line) {
[email protected]30f547c2010-08-04 01:00:01196 DCHECK(!chrome_logging_redirected_) <<
197 "Attempted to redirect logging when it was already initialized.";
[email protected]c7d5da992010-10-28 00:20:21198 FilePath orig_log_path = GetLogFileName();
199 FilePath log_path = new_log_dir.Append(orig_log_path.BaseName());
200
201 // Always force a new symlink when redirecting.
202 FilePath target_path = SetUpSymlinkIfNeeded(log_path, true);
203
204 // ChromeOS always logs through the symlink, so it shouldn't be
205 // deleted if it already exists.
206 if (!InitLogging(log_path.value().c_str(),
207 DetermineLogMode(command_line),
208 logging::LOCK_LOG_FILE,
209 logging::APPEND_TO_OLD_LOG_FILE)) {
210 LOG(ERROR) << "Unable to initialize logging to " << log_path.value();
211 RemoveSymlinkAndLog(log_path, target_path);
212 } else {
213 chrome_logging_redirected_ = true;
214 }
[email protected]77ee1b12010-06-14 16:21:30215}
216#endif
217
218void InitChromeLogging(const CommandLine& command_line,
219 OldFileDeletionState delete_old_log_file) {
220 DCHECK(!chrome_logging_initialized_) <<
221 "Attempted to initialize logging when it was already initialized.";
222
223#if defined(OS_POSIX) && defined(IPC_MESSAGE_LOG_ENABLED)
224 IPC::Logging::SetLoggerFunctions(g_log_function_mapping);
225#endif
226
227 FilePath log_path = GetLogFileName();
[email protected]c7d5da992010-10-28 00:20:21228
[email protected]77ee1b12010-06-14 16:21:30229#if defined(OS_CHROMEOS)
[email protected]c7d5da992010-10-28 00:20:21230 // On ChromeOS we log to the symlink. We force creation of a new
231 // symlink if we've been asked to delete the old log, since that
232 // indicates the start of a new session.
233 FilePath target_path = SetUpSymlinkIfNeeded(
234 log_path, delete_old_log_file == logging::DELETE_OLD_LOG_FILE);
235
236 // Because ChromeOS manages the move to a new session by redirecting
237 // the link, it shouldn't remove the old file in the logging code,
238 // since that will remove the newly created link instead.
239 delete_old_log_file = logging::APPEND_TO_OLD_LOG_FILE;
[email protected]77ee1b12010-06-14 16:21:30240#endif
241
[email protected]c7d5da992010-10-28 00:20:21242 bool success = InitLogging(log_path.value().c_str(),
243 DetermineLogMode(command_line),
244 logging::LOCK_LOG_FILE,
245 delete_old_log_file);
246
247#if defined(OS_CHROMEOS)
248 if (!success) {
249 PLOG(ERROR) << "Unable to initialize logging to " << log_path.value()
250 << " (which should be a link to " << target_path.value() << ")";
251 RemoveSymlinkAndLog(log_path, target_path);
252 return;
253 }
254#else
255 if (!success) {
256 PLOG(ERROR) << "Unable to initialize logging to " << log_path.value();
257 return;
258 }
259#endif
initial.commit09911bf2008-07-26 23:55:29260
[email protected]81e0a852010-08-17 00:38:12261 // Default to showing error dialogs.
262 if (!CommandLine::ForCurrentProcess()->HasSwitch(switches::kNoErrorDialogs))
263 logging::SetShowErrorDialogs(true);
264
initial.commit09911bf2008-07-26 23:55:29265 // we want process and thread IDs because we have a lot of things running
[email protected]c7d5da992010-10-28 00:20:21266 logging::SetLogItems(true, // enable_process_id
267 true, // enable_thread_id
268 false, // enable_timestamp
269 true); // enable_tickcount
initial.commit09911bf2008-07-26 23:55:29270
271 // We call running in unattended mode "headless", and allow
272 // headless mode to be configured either by the Environment
273 // Variable or by the Command Line Switch. This is for
274 // automated test purposes.
[email protected]76b90d312010-08-03 03:00:50275 scoped_ptr<base::Environment> env(base::Environment::Create());
[email protected]9432ade2010-08-04 23:43:20276 if (env->HasVar(env_vars::kHeadless) ||
initial.commit09911bf2008-07-26 23:55:29277 command_line.HasSwitch(switches::kNoErrorDialogs))
278 SuppressDialogs();
279
[email protected]3deeb6b32010-10-05 21:53:52280 // Use a minimum log level if the command line asks for one,
281 // otherwise leave it at the default level (INFO).
282 if (command_line.HasSwitch(switches::kLoggingLevel)) {
283 std::string log_level = command_line.GetSwitchValueASCII(
284 switches::kLoggingLevel);
285 int level = 0;
286 if (base::StringToInt(log_level, &level) &&
287 level >= 0 && level < LOG_NUM_SEVERITIES) {
[email protected]bb5185c52008-08-29 19:51:06288 logging::SetMinLogLevel(level);
[email protected]3deeb6b32010-10-05 21:53:52289 } else {
290 LOG(WARNING) << "Bad log level: " << log_level;
291 }
[email protected]bb5185c52008-08-29 19:51:06292 }
293
[email protected]2b07b8412009-11-25 15:26:34294#if defined(OS_WIN)
295 // Enable trace control and transport through event tracing for Windows.
[email protected]9432ade2010-08-04 23:43:20296 if (env->HasVar(env_vars::kEtwLogging))
[email protected]2b07b8412009-11-25 15:26:34297 logging::LogEventProvider::Initialize(kChromeTraceProviderName);
298#endif
299
initial.commit09911bf2008-07-26 23:55:29300 chrome_logging_initialized_ = true;
301}
302
303// This is a no-op, but we'll keep it around in case
304// we need to do more cleanup in the future.
305void CleanupChromeLogging() {
306 DCHECK(chrome_logging_initialized_) <<
307 "Attempted to clean up logging when it wasn't initialized.";
308
309 CloseLogFile();
310
311 chrome_logging_initialized_ = false;
[email protected]30f547c2010-08-04 01:00:01312 chrome_logging_redirected_ = false;
initial.commit09911bf2008-07-26 23:55:29313}
314
[email protected]73e23482009-08-13 00:26:58315FilePath GetLogFileName() {
[email protected]c83dd912010-04-06 18:50:51316 std::string filename;
[email protected]76b90d312010-08-03 03:00:50317 scoped_ptr<base::Environment> env(base::Environment::Create());
[email protected]3ba7e082010-08-07 02:57:59318 if (env->GetVar(env_vars::kLogFileName, &filename) && !filename.empty()) {
[email protected]c83dd912010-04-06 18:50:51319#if defined(OS_WIN)
320 return FilePath(UTF8ToWide(filename).c_str());
321#elif defined(OS_POSIX)
322 return FilePath(filename.c_str());
323#endif
324 }
initial.commit09911bf2008-07-26 23:55:29325
[email protected]73e23482009-08-13 00:26:58326 const FilePath log_filename(FILE_PATH_LITERAL("chrome_debug.log"));
327 FilePath log_path;
initial.commit09911bf2008-07-26 23:55:29328
329 if (PathService::Get(chrome::DIR_LOGS, &log_path)) {
[email protected]73e23482009-08-13 00:26:58330 log_path = log_path.Append(log_filename);
initial.commit09911bf2008-07-26 23:55:29331 return log_path;
332 } else {
333 // error with path service, just use some default file somewhere
334 return log_filename;
335 }
336}
337
338bool DialogsAreSuppressed() {
339 return dialogs_are_suppressed_;
340}
341
342size_t GetFatalAssertions(AssertionList* assertions) {
343 // In this function, we don't assume that assertions is non-null, so
344 // that if you just want an assertion count, you can pass in NULL.
345 if (assertions)
346 assertions->clear();
347 size_t assertion_count = 0;
348
349 std::ifstream log_file;
[email protected]73e23482009-08-13 00:26:58350 log_file.open(GetLogFileName().value().c_str());
initial.commit09911bf2008-07-26 23:55:29351 if (!log_file.is_open())
352 return 0;
353
354 std::string utf8_line;
355 std::wstring wide_line;
[email protected]4a3dab22009-11-11 17:36:50356 while (!log_file.eof()) {
initial.commit09911bf2008-07-26 23:55:29357 getline(log_file, utf8_line);
358 if (utf8_line.find(":FATAL:") != std::string::npos) {
359 wide_line = UTF8ToWide(utf8_line);
360 if (assertions)
361 assertions->push_back(wide_line);
362 ++assertion_count;
363 }
364 }
365 log_file.close();
366
367 return assertion_count;
368}
369
[email protected]c83dd912010-04-06 18:50:51370} // namespace logging