GPU Watchdog to check I/O before terminating GPU process

content/gpu/gpu_watchdog_thread.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "content/gpu/gpu_watchdog_thread.h"
 
 #include <errno.h>
 #include <stdint.h>
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/command_line.h"
 #include "base/compiler_specific.h"
 #include "base/debug/alias.h"
+#include "base/files/file_path.h"
 #include "base/files/file_util.h"
 #include "base/location.h"
 #include "base/macros.h"
 #include "base/power_monitor/power_monitor.h"
 #include "base/process/process.h"
 #include "base/single_thread_task_runner.h"
 #include "base/threading/platform_thread.h"
+#include "base/timer/elapsed_timer.h"
 #include "build/build_config.h"
+#include "content/common/gpu_watchdog_utils.h"
 #include "content/public/common/content_switches.h"
 #include "content/public/common/result_codes.h"
 
 #if defined(OS_WIN)
 #include <windows.h>
 #endif
 
 namespace content {
 namespace {
 #if defined(USE_X11)
@@ skipping 37 matching lines @@
                                 FALSE,
                                 0);
   DCHECK(result);
 #endif
 
 #if defined(USE_X11)
   tty_file_ = base::OpenFile(base::FilePath(kTtyFilePath), "r");
   SetupXServer();
 #endif
   watched_message_loop_->AddTaskObserver(&task_observer_);
+
+#if defined(OS_WIN)
+  // Create a temp file for checking whether I/O is a bottleneck.
+  // This code runs on the main GPU thread before the sandbox is lowered.
+  base::FilePath temp_file_path;
+  if (GetGpuWatchdogTempFile(&temp_file_path)) {
+    // Please note that multiple instances of GPU process may reuse the same
+    // temporary file. That's OK because the file is written to only when
+    // the watchdog gets triggered and about to crash the process. The file
+    // should be deleted when the last handle is closed.
+    temp_file_for_io_checking_.Initialize(
+        temp_file_path, base::File::FLAG_OPEN_ALWAYS | base::File::FLAG_WRITE |
+                            base::File::FLAG_DELETE_ON_CLOSE |
+                            base::File::FLAG_SHARE_DELETE);

[ncarter (slow), 2016/06/09 16:14:43]

I imagine that running browsertests in parallel with
--enable-pixel-output-in-tests will give decent coverage of contention on this
file.

[stanisc, 2016/06/09 20:52:28]

I've tested contention on this file by running two instances of Chrome with
different profile directories. The file gets deleted when the last instance of
Chrome is closed. The file gets written to only when the hang is already
detected (15 sec on not getting acknowledge) and chrome is about to crash. If we
limit this solution to Windows only we could probably not create this file until
we are ready to write to it, but on other platforms I think it needs to be
created before the sandbox is activated (which is here, in constructor). 

+    if (!temp_file_for_io_checking_.IsValid()) {
+      LOG(ERROR) << "Couldn't create " << temp_file_path.value().c_str()
+                 << ", error: " << temp_file_for_io_checking_.error_details();
+    }
+  }
+#endif
 }
 
 void GpuWatchdogThread::PostAcknowledge() {
   // Called on the monitored thread. Responds with OnAcknowledge. Cannot use
   // the method factory. Rely on reference counting instead.
   task_runner()->PostTask(FROM_HERE,
                           base::Bind(&GpuWatchdogThread::OnAcknowledge, this));
 }
 
 void GpuWatchdogThread::CheckArmed() {
@@ skipping 127 matching lines @@
 
   // Post a task to the monitored thread that does nothing but wake up the
   // TaskObserver. Any other tasks that are pending on the watched thread will
   // also wake up the observer. This simply ensures there is at least one.
   watched_message_loop_->task_runner()->PostTask(FROM_HERE,
                                                  base::Bind(&base::DoNothing));
 
   // Post a task to the watchdog thread to exit if the monitored thread does
   // not respond in time.
   task_runner()->PostDelayedTask(
-      FROM_HERE,
-      base::Bind(&GpuWatchdogThread::DeliberatelyTerminateToRecoverFromHang,
-                 weak_factory_.GetWeakPtr()),
+      FROM_HERE, base::Bind(&GpuWatchdogThread::BeginTerminating,
+                            weak_factory_.GetWeakPtr()),
       timeout);
 }
 
-// Use the --disable-gpu-watchdog command line switch to disable this.
-void GpuWatchdogThread::DeliberatelyTerminateToRecoverFromHang() {
+void GpuWatchdogThread::BeginTerminating() {
   // Should not get here while the system is suspended.
   DCHECK(!suspended_);
 
 #if defined(OS_WIN)
   // Defer termination until a certain amount of CPU time has elapsed on the
   // watched thread.
   base::ThreadTicks current_cpu_time = GetWatchedThreadTime();
   base::TimeDelta time_since_arm = current_cpu_time - arm_cpu_time_;
   if (use_thread_cpu_time_ && (time_since_arm < timeout_)) {
     message_loop()->PostDelayedTask(
-        FROM_HERE,
-        base::Bind(
-            &GpuWatchdogThread::DeliberatelyTerminateToRecoverFromHang,
-            weak_factory_.GetWeakPtr()),
+        FROM_HERE, base::Bind(&GpuWatchdogThread::BeginTerminating,
+                              weak_factory_.GetWeakPtr()),
         timeout_ - time_since_arm);
     return;
   }
+
+  // If the machine is busy with heavy I/O activity this should defer
+  // termination until the I/O queue clears (on the drive that contains
+  // the temp directory).
+  if (temp_file_for_io_checking_.IsValid()) {
+    // Write a few bytes and wait for the write to flush.
+    const char temp_data[32] = {0};

[brucedawson, 2016/06/09 01:01:13]

VC++ still generates sub-optimal code for = {0}. You should prefer = {} instead.

I just tested and the compiler still generates *crazy* code that writes 1 byte,
then 8, 8, 8, 4, 2, 1. I only reported the bug six years ago - give them time.
On a 64-bit (release) test build this wastes 13 bytes of code.

[stanisc, 2016/06/09 20:52:28]

Done.

+    base::ElapsedTimer timer;
+    temp_file_for_io_checking_.Write(0, temp_data, sizeof(temp_data));
+    temp_file_for_io_checking_.Flush();
+    io_check_duration_ = timer.Elapsed();

[ncarter (slow), 2016/06/09 16:14:43]

Did you intend to use this for anything?

[brucedawson, 2016/06/09 17:29:05]

The io_check_duration_ member will end up in the crash dump (because 'this' is
in a register when we crash) so this value may give us some hints about how big
a factor I/O load is.

Stan - add a comment to that effect?

[manzagop (departed), 2016/06/09 19:41:54]

Drive-by question! Is memory pulled in around registers? I thought it was only
around stack addresses? (Also, is the answer for MiniDumpWriteDump or for
CrashPad?)

[ncarter (slow), 2016/06/09 20:11:20]

The memory around |*this|, for all stack frames, are captured pretty reliably in
minidumps on Windows nowadays. It regressed for about a month and a half during
the breakpad/crashpad switchover late last year, but has been decent since. No
idea about other platforms. One can use crashkeys if you want the values to be
visible on the crash/ web UI.

[stanisc, 2016/06/09 20:52:28]

I've added a comment suggested by Bruce.

Using crash key is a good idea for something like the CPU time delta for the
watched thread. I think as long as io_check_duration_ is visible when debugging
the crash dump that should be good enough.

+  }
 #endif
 
+  // Post a new task to actually terminate unless an acknowledge from the
+  // watched thread arrives in between.
+  message_loop()->PostTask(
+      FROM_HERE,
+      base::Bind(&GpuWatchdogThread::DeliberatelyTerminateToRecoverFromHang,
+                 weak_factory_.GetWeakPtr()));
+}
+
+// Use the --disable-gpu-watchdog command line switch to disable this.
+void GpuWatchdogThread::DeliberatelyTerminateToRecoverFromHang() {
+  // Should not get here while the system is suspended.
+  DCHECK(!suspended_);
+
   // If the watchdog woke up significantly behind schedule, disarm and reset
   // the watchdog check. This is to prevent the watchdog thread from terminating
   // when a machine wakes up from sleep or hibernation, which would otherwise
   // appear to be a hang.
   if (base::Time::Now() > suspension_timeout_) {
     armed_ = false;
     OnCheck(true);
     return;
   }
 
@@ skipping 65 matching lines @@
 
 // Store variables so they're available in crash dumps to help determine the
 // cause of any hang.
 #if defined(OS_WIN)
   ULONGLONG fire_interrupt_time;
   QueryUnbiasedInterruptTime(&fire_interrupt_time);
 
   // This is the time since the watchdog was armed, in 100ns intervals,
   // ignoring time where the computer is suspended.
   ULONGLONG interrupt_delay = fire_interrupt_time - arm_interrupt_time_;
+  base::debug::Alias(&interrupt_delay);
 
-  base::debug::Alias(&interrupt_delay);
+  base::ThreadTicks current_cpu_time = GetWatchedThreadTime();
   base::debug::Alias(&current_cpu_time);
+
+  base::TimeDelta time_since_arm = current_cpu_time - arm_cpu_time_;
   base::debug::Alias(&time_since_arm);
 
   bool using_thread_ticks = base::ThreadTicks::IsSupported();
   base::debug::Alias(&using_thread_ticks);
 
   bool using_high_res_timer = base::Time::IsHighResolutionTimerInUse();
   base::debug::Alias(&using_high_res_timer);
 #endif
 
   base::Time current_time = base::Time::Now();
@@ skipping 108 matching lines @@
     int tty_number;
     size_t num_res = sscanf(tty_string, "tty%d\n", &tty_number);
     if (num_res == 1)
       return tty_number;
   }
   return -1;
 }
 #endif
 
 }  // namespace content