chrome/chrome_watcher/chrome_watcher_main.cc

   1 // Copyright (c) 2014 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 <windows.h>
   6 #include <sddl.h>
   7
   8 #include "base/at_exit.h"
   9 #include "base/bind.h"
  10 #include "base/bind_helpers.h"
  11 #include "base/callback_helpers.h"
  12 #include "base/command_line.h"
  13 #include "base/file_version_info.h"
  14 #include "base/files/file_path.h"
  15 #include "base/logging_win.h"
  16 #include "base/macros.h"
  17 #include "base/memory/ref_counted.h"
  18 #include "base/process/process.h"
  19 #include "base/run_loop.h"
  20 #include "base/sequenced_task_runner.h"
  21 #include "base/single_thread_task_runner.h"
  22 #include "base/strings/string16.h"
  23 #include "base/strings/string_number_conversions.h"
  24 #include "base/strings/string_piece.h"
  25 #include "base/strings/utf_string_conversions.h"
  26 #include "base/synchronization/waitable_event.h"
  27 #include "base/template_util.h"
  28 #include "base/thread_task_runner_handle.h"
  29 #include "base/threading/thread.h"
  30 #include "base/time/time.h"
  31 #include "base/win/scoped_handle.h"
  32 #include "base/win/win_util.h"
  33
  34 #include "chrome/chrome_watcher/chrome_watcher_main_api.h"
  35 #include "chrome/installer/util/util_constants.h"
  36 #include "components/browser_watcher/endsession_watcher_window_win.h"
  37 #include "components/browser_watcher/exit_code_watcher_win.h"
  38 #include "components/browser_watcher/exit_funnel_win.h"
  39 #include "components/browser_watcher/window_hang_monitor_win.h"
  40
  41 #ifdef KASKO
  42 #include "syzygy/kasko/api/reporter.h"
  43 #endif
  44
  45 namespace {
  46
  47 // Use the same log facility as Chrome for convenience.
  48 // {7FE69228-633E-4f06-80C1-527FEA23E3A7}
  49 const GUID kChromeWatcherTraceProviderName = {
  50     0x7fe69228, 0x633e, 0x4f06,
  51         { 0x80, 0xc1, 0x52, 0x7f, 0xea, 0x23, 0xe3, 0xa7 } };
  52
  53 // The amount of time we wait around for a WM_ENDSESSION or a process exit.
  54 const int kDelayTimeSeconds = 30;
  55
  56 // Takes care of monitoring a browser. This class watches for a browser's exit
  57 // code, as well as listening for WM_ENDSESSION messages. Events are recorded in
  58 // an exit funnel, for reporting the next time Chrome runs.
  59 class BrowserMonitor {
  60  public:
  61   BrowserMonitor(base::RunLoop* run_loop, const base::char16* registry_path);
  62   ~BrowserMonitor();
  63
  64   // Initiates the asynchronous monitoring process, returns true on success.
  65   // |on_initialized_event| will be signaled immediately before blocking on the
  66   // exit of |process|.
  67   bool StartWatching(const base::char16* registry_path,
  68                      base::Process process,
  69                      base::win::ScopedHandle on_initialized_event);
  70
  71  private:
  72   // Called from EndSessionWatcherWindow on a end session messages.
  73   void OnEndSessionMessage(UINT message, LPARAM lparam);
  74
  75   // Blocking function that runs on |background_thread_|. Signals
  76   // |on_initialized_event| before waiting for the browser process to exit.
  77   void Watch(base::win::ScopedHandle on_initialized_event);
  78
  79   // Posted to main thread from Watch when browser exits.
  80   void BrowserExited();
  81
  82   // The funnel used to record events for this browser.
  83   browser_watcher::ExitFunnel exit_funnel_;
  84
  85   browser_watcher::ExitCodeWatcher exit_code_watcher_;
  86   browser_watcher::EndSessionWatcherWindow end_session_watcher_window_;
  87
  88   // The thread that runs Watch().
  89   base::Thread background_thread_;
  90
  91   // Set when the browser has exited, used to stretch the watcher's lifetime
  92   // when WM_ENDSESSION occurs before browser exit.
  93   base::WaitableEvent browser_exited_;
  94
  95   // The run loop for the main thread and its task runner.
  96   base::RunLoop* run_loop_;
  97   scoped_refptr<base::SequencedTaskRunner> main_thread_;
  98
  99   DISALLOW_COPY_AND_ASSIGN(BrowserMonitor);
 100 };
 101
 102 BrowserMonitor::BrowserMonitor(base::RunLoop* run_loop,
 103                                const base::char16* registry_path)
 104     : exit_code_watcher_(registry_path),
 105       end_session_watcher_window_(
 106           base::Bind(&BrowserMonitor::OnEndSessionMessage,
 107                      base::Unretained(this))),
 108       background_thread_("BrowserWatcherThread"),
 109       browser_exited_(true, false),  // manual reset, initially non-signalled.
 110       run_loop_(run_loop),
 111       main_thread_(base::ThreadTaskRunnerHandle::Get()) {
 112 }
 113
 114 BrowserMonitor::~BrowserMonitor() {
 115 }
 116
 117 bool BrowserMonitor::StartWatching(
 118     const base::char16* registry_path,
 119     base::Process process,
 120     base::win::ScopedHandle on_initialized_event) {
 121   if (!exit_code_watcher_.Initialize(process.Pass()))
 122     return false;
 123
 124   if (!exit_funnel_.Init(registry_path,
 125                          exit_code_watcher_.process().Handle())) {
 126     return false;
 127   }
 128
 129   if (!background_thread_.StartWithOptions(
 130         base::Thread::Options(base::MessageLoop::TYPE_IO, 0))) {
 131     return false;
 132   }
 133
 134   if (!background_thread_.task_runner()->PostTask(
 135           FROM_HERE, base::Bind(&BrowserMonitor::Watch, base::Unretained(this),
 136                                 base::Passed(on_initialized_event.Pass())))) {
 137     background_thread_.Stop();
 138     return false;
 139   }
 140
 141   return true;
 142 }
 143
 144 void BrowserMonitor::OnEndSessionMessage(UINT message, LPARAM lparam) {
 145   DCHECK_EQ(main_thread_, base::ThreadTaskRunnerHandle::Get());
 146
 147   if (message == WM_QUERYENDSESSION) {
 148     exit_funnel_.RecordEvent(L"WatcherQueryEndSession");
 149   } else if (message == WM_ENDSESSION) {
 150     exit_funnel_.RecordEvent(L"WatcherEndSession");
 151   }
 152   if (lparam & ENDSESSION_CLOSEAPP)
 153     exit_funnel_.RecordEvent(L"ES_CloseApp");
 154   if (lparam & ENDSESSION_CRITICAL)
 155     exit_funnel_.RecordEvent(L"ES_Critical");
 156   if (lparam & ENDSESSION_LOGOFF)
 157     exit_funnel_.RecordEvent(L"ES_Logoff");
 158   const LPARAM kKnownBits =
 159       ENDSESSION_CLOSEAPP | ENDSESSION_CRITICAL | ENDSESSION_LOGOFF;
 160   if (lparam & ~kKnownBits)
 161     exit_funnel_.RecordEvent(L"ES_Other");
 162
 163   // If the browser hasn't exited yet, dally for a bit to try and stretch this
 164   // process' lifetime to give it some more time to capture the browser exit.
 165   browser_exited_.TimedWait(base::TimeDelta::FromSeconds(kDelayTimeSeconds));
 166
 167   run_loop_->Quit();
 168 }
 169
 170 void BrowserMonitor::Watch(base::win::ScopedHandle on_initialized_event) {
 171   // This needs to run on an IO thread.
 172   DCHECK_NE(main_thread_, base::ThreadTaskRunnerHandle::Get());
 173
 174   // Signal our client now that the Kasko reporter is initialized and we have
 175   // cleared all of the obstacles that might lead to an early exit.
 176   ::SetEvent(on_initialized_event.Get());
 177   on_initialized_event.Close();
 178
 179   exit_code_watcher_.WaitForExit();
 180   exit_funnel_.RecordEvent(L"BrowserExit");
 181
 182   // Note that the browser has exited.
 183   browser_exited_.Signal();
 184
 185   main_thread_->PostTask(FROM_HERE,
 186       base::Bind(&BrowserMonitor::BrowserExited, base::Unretained(this)));
 187 }
 188
 189 void BrowserMonitor::BrowserExited() {
 190   // This runs in the main thread.
 191   DCHECK_EQ(main_thread_, base::ThreadTaskRunnerHandle::Get());
 192
 193   // Our background thread has served it's purpose.
 194   background_thread_.Stop();
 195
 196   const int exit_code = exit_code_watcher_.exit_code();
 197   if (exit_code >= 0 && exit_code <= 28) {
 198     // The browser exited with a well-known exit code, quit this process
 199     // immediately.
 200     run_loop_->Quit();
 201   } else {
 202     // The browser exited abnormally, wait around for a little bit to see
 203     // whether this instance will get a logoff message.
 204     main_thread_->PostDelayedTask(
 205         FROM_HERE,
 206         run_loop_->QuitClosure(),
 207         base::TimeDelta::FromSeconds(kDelayTimeSeconds));
 208   }
 209 }
 210
 211 void OnWindowEvent(
 212     const base::string16& registry_path,
 213     base::Process process,
 214     const base::Callback<void(const base::Process&)>& on_hung_callback,
 215     browser_watcher::WindowHangMonitor::WindowEvent window_event) {
 216   browser_watcher::ExitFunnel exit_funnel;
 217   if (exit_funnel.Init(registry_path.c_str(), process.Handle())) {
 218     switch (window_event) {
 219       case browser_watcher::WindowHangMonitor::WINDOW_NOT_FOUND:
 220         exit_funnel.RecordEvent(L"MessageWindowNotFound");
 221         break;
 222       case browser_watcher::WindowHangMonitor::WINDOW_HUNG:
 223         exit_funnel.RecordEvent(L"MessageWindowHung");
 224         if (!on_hung_callback.is_null())
 225           on_hung_callback.Run(process);
 226         break;
 227       case browser_watcher::WindowHangMonitor::WINDOW_VANISHED:
 228         exit_funnel.RecordEvent(L"MessageWindowVanished");
 229         break;
 230       default:
 231         NOTREACHED();
 232         break;
 233     }
 234   }
 235 }
 236
 237 #ifdef KASKO
 238 void DumpHungBrowserProcess(DWORD main_thread_id,
 239                             const base::string16& channel,
 240                             const base::Process& process) {
 241   // TODO(erikwright): Rather than recreating these crash keys here, it would be
 242   // ideal to read them directly from the browser process.
 243
 244   // This is looking up the version of chrome_watcher.dll, which is equivalent
 245   // for our purposes to chrome.dll.
 246   scoped_ptr<FileVersionInfo> version_info(
 247       FileVersionInfo::CreateFileVersionInfoForModule(
 248           reinterpret_cast<HMODULE>(&__ImageBase)));
 249   using CrashKeyStrings = std::pair<base::string16, base::string16>;
 250   std::vector<CrashKeyStrings> crash_key_strings;
 251   if (version_info.get()) {
 252     crash_key_strings.push_back(
 253         CrashKeyStrings(L"prod", version_info->product_short_name()));
 254     base::string16 version = version_info->product_version();
 255     if (!version_info->is_official_build())
 256       version.append(base::ASCIIToUTF16("-devel"));
 257     crash_key_strings.push_back(CrashKeyStrings(L"ver", version));
 258   } else {
 259     // No version info found. Make up the values.
 260     crash_key_strings.push_back(CrashKeyStrings(L"prod", L"Chrome"));
 261     crash_key_strings.push_back(CrashKeyStrings(L"ver", L"0.0.0.0-devel"));
 262   }
 263   crash_key_strings.push_back(CrashKeyStrings(L"channel", channel));
 264   crash_key_strings.push_back(CrashKeyStrings(L"plat", L"Win32"));
 265   crash_key_strings.push_back(CrashKeyStrings(L"ptype", L"browser"));
 266   crash_key_strings.push_back(
 267       CrashKeyStrings(L"pid", base::IntToString16(process.Pid())));
 268   crash_key_strings.push_back(CrashKeyStrings(L"hung-process", L"1"));
 269
 270   std::vector<const base::char16*> key_buffers;
 271   std::vector<const base::char16*> value_buffers;
 272   for (auto& strings : crash_key_strings) {
 273     key_buffers.push_back(strings.first.c_str());
 274     value_buffers.push_back(strings.second.c_str());
 275   }
 276   key_buffers.push_back(nullptr);
 277   value_buffers.push_back(nullptr);
 278
 279   // Synthesize an exception for the main thread.
 280   CONTEXT thread_context = {};
 281   EXCEPTION_RECORD exception_record = {};
 282   exception_record.ExceptionCode = EXCEPTION_ARRAY_BOUNDS_EXCEEDED;
 283   EXCEPTION_POINTERS exception_pointers = {&exception_record, &thread_context};
 284
 285   // TODO(erikwright): Make the dump-type channel-dependent.
 286   kasko::api::SendReportForProcess(
 287       process.Handle(), main_thread_id, &exception_pointers,
 288       kasko::api::LARGER_DUMP_TYPE, key_buffers.data(), value_buffers.data());
 289 }
 290
 291 void LoggedDeregisterEventSource(HANDLE event_source_handle) {
 292   if (!::DeregisterEventSource(event_source_handle))
 293     DPLOG(ERROR) << "DeregisterEventSource";
 294 }
 295
 296 void LoggedLocalFree(PSID sid) {
 297   if (::LocalFree(sid) != nullptr)
 298     DPLOG(ERROR) << "LocalFree";
 299 }
 300
 301 void OnCrashReportUpload(void* context,
 302                          const base::char16* report_id,
 303                          const base::char16* minidump_path,
 304                          const base::char16* const* keys,
 305                          const base::char16* const* values) {
 306   // Open the event source.
 307   HANDLE event_source_handle = ::RegisterEventSource(NULL, L"Chrome");
 308   if (!event_source_handle) {
 309     PLOG(ERROR) << "RegisterEventSource";
 310     return;
 311   }
 312   // Ensure cleanup on scope exit.
 313   base::ScopedClosureRunner deregister_event_source(
 314       base::Bind(&LoggedDeregisterEventSource, event_source_handle));
 315
 316   // Get the user's SID for the log record.
 317   base::string16 sid_string;
 318   PSID sid = nullptr;
 319   if (base::win::GetUserSidString(&sid_string)) {
 320     if (!sid_string.empty()) {
 321       if (!::ConvertStringSidToSid(sid_string.c_str(), &sid))
 322         DPLOG(ERROR) << "ConvertStringSidToSid";
 323       DCHECK(sid);
 324     }
 325   }
 326   // Ensure cleanup on scope exit.
 327   base::ScopedClosureRunner free_sid(
 328       base::Bind(&LoggedLocalFree, base::Unretained(sid)));
 329
 330   // Generate the message.
 331   // Note that the format of this message must match the consumer in
 332   // chrome/browser/crash_upload_list_win.cc.
 333   base::string16 message =
 334       L"Crash uploaded. Id=" + base::string16(report_id) + L".";
 335
 336   // Matches Omaha.
 337   const int kCrashUploadEventId = 2;
 338
 339   // Report the event.
 340   const base::char16* strings[] = {message.c_str()};
 341   if (!::ReportEvent(event_source_handle, EVENTLOG_INFORMATION_TYPE,
 342                      0,  // category
 343                      kCrashUploadEventId, sid,
 344                      1,  // count
 345                      0, strings, nullptr)) {
 346     DPLOG(ERROR);
 347   }
 348
 349   // TODO(erikwright): Copy minidump to some "last dump" location?
 350 }
 351
 352 #endif  // KASKO
 353
 354 }  // namespace
 355
 356 // The main entry point to the watcher, declared as extern "C" to avoid name
 357 // mangling.
 358 extern "C" int WatcherMain(const base::char16* registry_path,
 359                            HANDLE process_handle,
 360                            DWORD main_thread_id,
 361                            HANDLE on_initialized_event_handle,
 362                            const base::char16* browser_data_directory,
 363                            const base::char16* message_window_name,
 364                            const base::char16* channel_name) {
 365   base::Process process(process_handle);
 366   base::win::ScopedHandle on_initialized_event(on_initialized_event_handle);
 367
 368   // The exit manager is in charge of calling the dtors of singletons.
 369   base::AtExitManager exit_manager;
 370   // Initialize the commandline singleton from the environment.
 371   base::CommandLine::Init(0, nullptr);
 372
 373   logging::LogEventProvider::Initialize(kChromeWatcherTraceProviderName);
 374
 375   // Arrange to be shut down as late as possible, as we want to outlive
 376   // chrome.exe in order to report its exit status.
 377   ::SetProcessShutdownParameters(0x100, SHUTDOWN_NORETRY);
 378
 379   base::Callback<void(const base::Process&)> on_hung_callback;
 380
 381 #ifdef KASKO
 382   bool launched_kasko = kasko::api::InitializeReporter(
 383       GetKaskoEndpoint(process.Pid()).c_str(),
 384       L"https://clients2.google.com/cr/report",
 385       base::FilePath(browser_data_directory)
 386           .Append(L"Crash Reports")
 387           .value()
 388           .c_str(),
 389       base::FilePath(browser_data_directory)
 390           .Append(kPermanentlyFailedReportsSubdir)
 391           .value()
 392           .c_str(),
 393       &OnCrashReportUpload, nullptr);
 394 #ifdef KASKO_HANG_REPORTS
 395   if (launched_kasko &&
 396       base::StringPiece16(channel_name) == installer::kChromeChannelCanary) {
 397     on_hung_callback =
 398         base::Bind(&DumpHungBrowserProcess, main_thread_id, channel_name);
 399   }
 400 #endif  // KASKO_HANG_REPORTS
 401 #endif  // KASKO
 402
 403   // Run a UI message loop on the main thread.
 404   base::MessageLoop msg_loop(base::MessageLoop::TYPE_UI);
 405   msg_loop.set_thread_name("WatcherMainThread");
 406
 407   base::RunLoop run_loop;
 408   BrowserMonitor monitor(&run_loop, registry_path);
 409   if (!monitor.StartWatching(registry_path, process.Duplicate(),
 410                              on_initialized_event.Pass())) {
 411     return 1;
 412   }
 413
 414   {
 415     // Scoped to force |hang_monitor| destruction before Kasko is shut down.
 416     browser_watcher::WindowHangMonitor hang_monitor(
 417         base::TimeDelta::FromSeconds(60), base::TimeDelta::FromSeconds(20),
 418         base::Bind(&OnWindowEvent, registry_path,
 419                    base::Passed(process.Duplicate()), on_hung_callback));
 420     hang_monitor.Initialize(process.Duplicate(), message_window_name);
 421
 422     run_loop.Run();
 423   }
 424
 425 #ifdef KASKO
 426   if (launched_kasko)
 427     kasko::api::ShutdownReporter();
 428 #endif  // KASKO
 429
 430   // Wind logging down.
 431   logging::LogEventProvider::Uninitialize();
 432
 433   return 0;
 434 }
 435
 436 static_assert(
 437     base::is_same<decltype(&WatcherMain), ChromeWatcherMainFunction>::value,
 438     "WatcherMain() has wrong type");