crash-reporter: Capture and send recent update_engine logs when it crashes

We also disallow more than 4 nested crashes.  This way we know if core2md crashes for instance, but not if crash_reporter crashes while handling the core2md crash that came from crash_reporter.  Note that the kernel does not know about parent/child process relationships, it just counts concurrent handling, so it is possible that some of many crashing processes will be discarded.

See crash report id 473c22ed428d33a9 for an example report with update_engine logs.

Change-Id: I9ff9f03a94dc87d2d42840511c2e5e42ee37cea8

BUG=9176
TEST=UserCrash,CrashSender,unit tests

Review URL: http://codereview.chromium.org/5814001

crash_reporter/crash_collector.cc

@@ -21,6 +21,7 @@
 
 static const char kDefaultUserName[] = "chronos";
 static const char kLsbRelease[] = "/etc/lsb-release";
+static const char kShellPath[] = "/bin/sh";
 static const char kSystemCrashPath[] = "/var/spool/crash";
 static const char kUserCrashPath[] = "/home/chronos/user/crash";
 
@@ -109,7 +110,7 @@ int CrashCollector::ForkExecAndPipe(std::vector<const char *> &arguments,
   }
 
   if (pid == 0) {
-    int output_handle = HANDLE_EINTR(creat(output_file, 0700));
+    int output_handle = HANDLE_EINTR(creat(output_file, 0600));
     if (output_handle < 0) {
       logger_->LogError("Could not create %s: %d", output_file, errno);
       // Avoid exit() to avoid atexit handlers from parent.
@@ -307,6 +308,11 @@ bool CrashCollector::CheckHasCapacity(const FilePath &crash_directory) {
   return !full;
 }
 
+bool CrashCollector::IsCommentLine(const std::string &line) {
+  size_t found = line.find_first_not_of(" ");
+  return found != std::string::npos && line[found] == '#';
+}
+
 bool CrashCollector::ReadKeyValueFile(
     const FilePath &path,
     const char separator,
@@ -324,6 +330,9 @@ bool CrashCollector::ReadKeyValueFile(
     // Allow empty strings.
     if (line->empty())
       continue;
+    // Allow comment lines.
+    if (IsCommentLine(*line))
+      continue;
     StringVector sides;
     SplitString(*line, separator, &sides);
     if (sides.size() != 2) {
@@ -335,6 +344,34 @@ bool CrashCollector::ReadKeyValueFile(
   return !any_errors;
 }
 
+bool CrashCollector::GetLogContents(const FilePath &config_path,
+                                    const std::string &exec_name,
+                                    const FilePath &output_file) {
+  std::map<std::string, std::string> log_commands;
+  if (!ReadKeyValueFile(config_path, ':', &log_commands)) {
+    logger_->LogInfo("Unable to read log configuration file %s",
+                     config_path.value().c_str());
+    return false;
+  }
+
+  if (log_commands.find(exec_name) == log_commands.end())
+    return false;
+
+  std::vector<const char *> command;
+  command.push_back(kShellPath);
+  command.push_back("-c");
+  std::string shell_command = log_commands[exec_name];
+  command.push_back(shell_command.c_str());
+
+  int fork_result = ForkExecAndPipe(command, output_file.value().c_str());
+  if (fork_result != 0) {
+    logger_->LogInfo("Running shell command %s failed with: %d",
+                     shell_command.c_str(), fork_result);
+    return false;
+  }
+  return true;
+}
+
 void CrashCollector::AddCrashMetaData(const std::string &key,
                                       const std::string &value) {
   extra_metadata_.append(StringPrintf("%s=%s\n", key.c_str(), value.c_str()));

crash_reporter/crash_collector.h

@@ -39,9 +39,11 @@ class CrashCollector {
   FRIEND_TEST(CrashCollectorTest, CheckHasCapacityUsual);
   FRIEND_TEST(CrashCollectorTest, GetCrashDirectoryInfo);
   FRIEND_TEST(CrashCollectorTest, GetCrashPath);
+  FRIEND_TEST(CrashCollectorTest, GetLogContents);
   FRIEND_TEST(CrashCollectorTest, ForkExecAndPipe);
   FRIEND_TEST(CrashCollectorTest, FormatDumpBasename);
   FRIEND_TEST(CrashCollectorTest, Initialize);
+  FRIEND_TEST(CrashCollectorTest, IsCommentLine);
   FRIEND_TEST(CrashCollectorTest, MetaData);
   FRIEND_TEST(CrashCollectorTest, ReadKeyValueFile);
   FRIEND_TEST(CrashCollectorTest, Sanitize);
@@ -102,12 +104,21 @@ class CrashCollector {
   // crash.
   bool CheckHasCapacity(const FilePath &crash_directory);
 
+  // Checks if the line starts with '#' after optional whitespace.
+  static bool IsCommentLine(const std::string &line);
+
   // Read the given file of form [<key><separator><value>\n...] and return
   // a map of its contents.
   bool ReadKeyValueFile(const FilePath &file,
                         char separator,
                         std::map<std::string, std::string> *dictionary);
 
+  // Write a log applicable to |exec_name| to |output_file| based on the
+  // log configuration file at |config_path|.
+  bool GetLogContents(const FilePath &config_path,
+                      const std::string &exec_name,
+                      const FilePath &output_file);
+
   // Add non-standard meta data to the crash metadata file.  Call
   // before calling WriteCrashMetaData.  Key must not contain "=" or
   // "\n" characters.  Value must not contain "\n" characters.

crash_reporter/crash_collector_test.cc

@@ -271,6 +271,15 @@ TEST_F(CrashCollectorTest, CheckHasCapacityStrangeNames) {
   EXPECT_FALSE(CheckHasCapacity());
 }
 
+TEST_F(CrashCollectorTest, IsCommentLine) {
+  EXPECT_FALSE(CrashCollector::IsCommentLine(""));
+  EXPECT_TRUE(CrashCollector::IsCommentLine("#"));
+  EXPECT_TRUE(CrashCollector::IsCommentLine("#real comment"));
+  EXPECT_TRUE(CrashCollector::IsCommentLine(" # real comment"));
+  EXPECT_FALSE(CrashCollector::IsCommentLine("not comment"));
+  EXPECT_FALSE(CrashCollector::IsCommentLine(" not comment"));
+}
+
 TEST_F(CrashCollectorTest, ReadKeyValueFile) {
   const char *contents = ("a=b\n"
                           "\n"
@@ -294,10 +303,13 @@ TEST_F(CrashCollectorTest, ReadKeyValueFile) {
               " f g = h\n"
               "i=j\n"
               "=k\n"
+              "#comment=0\n"
               "l=\n");
   file_util::WriteFile(path, contents, strlen(contents));
 
   EXPECT_FALSE(collector_.ReadKeyValueFile(path, '=', &dictionary));
+  EXPECT_EQ(5, dictionary.size());
+
   i = dictionary.find("a");
   EXPECT_TRUE(i != dictionary.end() && i->second == "b c d");
   i = dictionary.find("e");
@@ -369,6 +381,27 @@ TEST_F(CrashCollectorTest, MetaData) {
   EXPECT_NE(std::string::npos, logging_.log().find("Unable to write"));
 }
 
+TEST_F(CrashCollectorTest, GetLogContents) {
+  FilePath config_file = test_dir_.Append("crash_config");
+  FilePath output_file = test_dir_.Append("crash_log");
+  const char kConfigContents[] =
+      "foobar:echo hello there | sed -e \"s/there/world/\"";
+  ASSERT_TRUE(
+      file_util::WriteFile(config_file,
+                           kConfigContents, strlen(kConfigContents)));
+  EXPECT_FALSE(collector_.GetLogContents(config_file,
+                                         "barfoo",
+                                         output_file));
+  EXPECT_FALSE(file_util::PathExists(output_file));
+  EXPECT_TRUE(collector_.GetLogContents(config_file,
+                                        "foobar",
+                                        output_file));
+  ASSERT_TRUE(file_util::PathExists(output_file));
+  std::string contents;
+  EXPECT_TRUE(file_util::ReadFileToString(output_file, &contents));
+  EXPECT_EQ("hello world\n", contents);
+}
+
 int main(int argc, char **argv) {
   ::testing::InitGoogleTest(&argc, argv);
   return RUN_ALL_TESTS();

crash_reporter/crash_reporter_logs.conf

@@ -0,0 +1,22 @@
+# Copyright (c) 2010 The Chromium OS Authors. All rights reserved.
+# Use of this source code is governed by a BSD-style license that can
+# be found in the LICENSE file.
+
+# This file has the format:
+# <basename>:<shell command>\n
+#
+# Where when any executable with the basename <basename> crashes, the
+# given <shell command> is executed and its standard output and
+# standard error is sent along with the crash report.
+#
+# Use caution in modifying this file.  Only run common unix commands
+# here as these commands will be run when a crash has recently
+# occurred and we should avoid running anything that might cause
+# another crash.  Similarly these command block the notification of
+# the crash to parent processes, so commands should execute quickly.
+#
+update_engine:cat $(ls -1tr /var/log/update_engine | tail -5 | sed s.^./var/log/update_engine/.) | tail -c 50000
+
+# The following rules are only for testing purposes.
+crash_log_test:echo hello world
+crash_log_recursion_test:sleep 1 && /home/autotest/tests/crash_log_recursion_test

crash_reporter/crash_sender

@@ -209,6 +209,7 @@ send_crash() {
   local board="$(get_board)"
   local hwclass="$(get_hardware_class)"
   local write_payload_size="$(get_key_value "${meta_path}" "payload_size")"
+  local log="$(get_key_value "${meta_path}" "log")"
   local sig="$(get_key_value "${meta_path}" "sig")"
   local send_payload_size="$(stat --printf=%s "${report_payload}" 2>/dev/null)"
 
@@ -221,6 +222,10 @@ send_crash() {
     extra_value1="${sig}"
     extra_key2="sig2"
     extra_value2="${sig}"
+  elif [ "${log}" != "undefined" ]; then
+    # Upload a log file if it was specified.
+    extra_key1="log"
+    extra_value1="@${log}"
   fi
 
   lecho "Sending crash:"

crash_reporter/user_collector.cc

@@ -30,15 +30,22 @@ static const char kCollectionErrorSignature[] =
 // instead pipe the core file into a user space process.  See
 // core(5) man page.
 static const char kCorePatternFile[] = "/proc/sys/kernel/core_pattern";
+static const char kCorePipeLimitFile[] = "/proc/sys/kernel/core_pipe_limit";
+// Set core_pipe_limit to 4 so that we can catch a few unrelated concurrent
+// crashes, but finite to avoid infinitely recursing on crash handling.
+static const char kCorePipeLimit[] = "4";
 static const char kCoreToMinidumpConverterPath[] = "/usr/bin/core2md";
 static const char kLeaveCoreFile[] = "/root/.leave_core";
 
+static const char kDefaultLogConfig[] = "/etc/crash_reporter_logs.conf";
+
 const char *UserCollector::kUserId = "Uid:\t";
 const char *UserCollector::kGroupId = "Gid:\t";
 
 UserCollector::UserCollector()
     : generate_diagnostics_(false),
       core_pattern_file_(kCorePatternFile),
+      core_pipe_limit_file_(kCorePipeLimitFile),
       initialized_(false) {
 }
 
@@ -71,6 +78,13 @@ bool UserCollector::SetUpInternal(bool enabled) {
   CHECK(initialized_);
   logger_->LogInfo("%s user crash handling",
                    enabled ? "Enabling" : "Disabling");
+  if (file_util::WriteFile(FilePath(core_pipe_limit_file_),
+                           kCorePipeLimit,
+                           strlen(kCorePipeLimit)) !=
+      static_cast<int>(strlen(kCorePipeLimit))) {
+    logger_->LogError("Unable to write %s", core_pipe_limit_file_.c_str());
+    return false;
+  }
   std::string pattern = GetPattern(enabled);
   if (file_util::WriteFile(FilePath(core_pattern_file_),
                            pattern.c_str(),
@@ -332,6 +346,10 @@ bool UserCollector::ConvertAndEnqueueCrash(int pid,
   FilePath core_path = GetCrashPath(crash_path, dump_basename, "core");
   FilePath meta_path = GetCrashPath(crash_path, dump_basename, "meta");
   FilePath minidump_path = GetCrashPath(crash_path, dump_basename, "dmp");
+  FilePath log_path = GetCrashPath(crash_path, dump_basename, "log");
+
+  if (GetLogContents(FilePath(kDefaultLogConfig), exec, log_path))
+    AddCrashMetaData("log", log_path.value());
 
   if (!ConvertCoreToMinidump(pid, container_dir, core_path,
                             minidump_path)) {

crash_reporter/user_collector.h

@@ -47,6 +47,11 @@ class UserCollector : public CrashCollector {
     core_pattern_file_ = pattern;
   }
 
+  // Set (override the default) core pipe limit file.
+  void set_core_pipe_limit_file(const std::string &path) {
+    core_pipe_limit_file_ = path;
+  }
+
  private:
   friend class UserCollectorTest;
   FRIEND_TEST(UserCollectorTest, CopyOffProcFilesBadPath);
@@ -107,6 +112,7 @@ class UserCollector : public CrashCollector {
 
   bool generate_diagnostics_;
   std::string core_pattern_file_;
+  std::string core_pipe_limit_file_;
   std::string our_path_;
   bool initialized_;
 

crash_reporter/user_collector_test.cc

@@ -32,8 +32,10 @@ class UserCollectorTest : public ::testing::Test {
                           IsMetrics,
                           &logging_,
                           false);
+    file_util::Delete(FilePath("test"), true);
     mkdir("test", 0777);
     collector_.set_core_pattern_file("test/core_pattern");
+    collector_.set_core_pipe_limit_file("test/core_pipe_limit");
     pid_ = getpid();
   }
  protected:
@@ -53,12 +55,13 @@ class UserCollectorTest : public ::testing::Test {
 TEST_F(UserCollectorTest, EnableOK) {
   ASSERT_TRUE(collector_.Enable());
   ExpectFileEquals("|/my/path --signal=%s --pid=%p", "test/core_pattern");
+  ExpectFileEquals("4", "test/core_pipe_limit");
   ASSERT_EQ(s_crashes, 0);
   ASSERT_NE(logging_.log().find("Enabling user crash handling"),
             std::string::npos);
 }
 
-TEST_F(UserCollectorTest, EnableNoFileAccess) {
+TEST_F(UserCollectorTest, EnableNoPatternFileAccess) {
   collector_.set_core_pattern_file("/does_not_exist");
   ASSERT_FALSE(collector_.Enable());
   ASSERT_EQ(s_crashes, 0);
@@ -68,6 +71,19 @@ TEST_F(UserCollectorTest, EnableNoFileAccess) {
             std::string::npos);
 }
 
+TEST_F(UserCollectorTest, EnableNoPipeLimitFileAccess) {
+  collector_.set_core_pipe_limit_file("/does_not_exist");
+  ASSERT_FALSE(collector_.Enable());
+  ASSERT_EQ(s_crashes, 0);
+  // Core pattern should not be written if we cannot access the pipe limit
+  // or otherwise we may set a pattern that results in infinite recursion.
+  ASSERT_FALSE(file_util::PathExists(FilePath("test/core_pattern")));
+  ASSERT_NE(logging_.log().find("Enabling user crash handling"),
+            std::string::npos);
+  ASSERT_NE(logging_.log().find("Unable to write /does_not_exist"),
+            std::string::npos);
+}
+
 TEST_F(UserCollectorTest, DisableOK) {
   ASSERT_TRUE(collector_.Disable());
   ExpectFileEquals("core", "test/core_pattern");