src/chrome/browser/chromeos/system/syslogs_provider.cc

   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 "chrome/browser/chromeos/system/syslogs_provider.h"
   6
   7 #include "ash/shell.h"
   8 #include "base/bind.h"
   9 #include "base/bind_helpers.h"
  10 #include "base/command_line.h"
  11 #include "base/compiler_specific.h"
  12 #include "base/file_util.h"
  13 #include "base/files/file_path.h"
  14 #include "base/logging.h"
  15 #include "base/memory/scoped_ptr.h"
  16 #include "base/memory/singleton.h"
  17 #include "base/message_loop/message_loop_proxy.h"
  18 #include "base/strings/string_util.h"
  19 #include "base/task_runner.h"
  20 #include "base/threading/sequenced_worker_pool.h"
  21 #include "chrome/browser/feedback/feedback_util.h"
  22 #include "chrome/browser/memory_details.h"
  23 #include "chrome/common/chrome_switches.h"
  24 #include "chromeos/network/network_event_log.h"
  25 #include "content/public/browser/browser_thread.h"
  26 #include "dbus/dbus_statistics.h"
  27
  28 using content::BrowserThread;
  29
  30 namespace chromeos {
  31 namespace system {
  32
  33 const size_t kFeedbackMaxLength = 4 * 1024;
  34 const size_t kFeedbackMaxLineCount = 40;
  35
  36 namespace {
  37
  38 const char kSysLogsScript[] =
  39     "/usr/share/userfeedback/scripts/sysinfo_script_runner";
  40 const char kBzip2Command[] =
  41     "/bin/bzip2";
  42 const char kMultilineQuote[] = "\"\"\"";
  43 const char kNewLineChars[] = "\r\n";
  44 const char kInvalidLogEntry[] = "<invalid characters in log entry>";
  45 const char kEmptyLogEntry[] = "<no value>";
  46
  47 const char kContextFeedback[] = "feedback";
  48 const char kContextSysInfo[] = "sysinfo";
  49 const char kContextNetwork[] = "network";
  50
  51 // Reads a key from the input string erasing the read values + delimiters read
  52 // from the initial string
  53 std::string ReadKey(std::string* data) {
  54   size_t equal_sign = data->find("=");
  55   if (equal_sign == std::string::npos)
  56     return std::string("");
  57   std::string key = data->substr(0, equal_sign);
  58   data->erase(0, equal_sign);
  59   if (data->size() > 0) {
  60     // erase the equal to sign also
  61     data->erase(0,1);
  62     return key;
  63   }
  64   return std::string();
  65 }
  66
  67 // Reads a value from the input string; erasing the read values from
  68 // the initial string; detects if the value is multiline and reads
  69 // accordingly
  70 std::string ReadValue(std::string* data) {
  71   // Trim the leading spaces and tabs. In order to use a multi-line
  72   // value, you have to place the multi-line quote on the same line as
  73   // the equal sign.
  74   //
  75   // Why not use TrimWhitespace? Consider the following input:
  76   //
  77   // KEY1=
  78   // KEY2=VALUE
  79   //
  80   // If we use TrimWhitespace, we will incorrectly trim the new line
  81   // and assume that KEY1's value is "KEY2=VALUE" rather than empty.
  82   TrimString(*data, " \t", data);
  83
  84   // If multiline value
  85   if (StartsWithASCII(*data, std::string(kMultilineQuote), false)) {
  86     data->erase(0, strlen(kMultilineQuote));
  87     size_t next_multi = data->find(kMultilineQuote);
  88     if (next_multi == std::string::npos) {
  89       // Error condition, clear data to stop further processing
  90       data->erase();
  91       return std::string();
  92     }
  93     std::string value = data->substr(0, next_multi);
  94     data->erase(0, next_multi + 3);
  95     return value;
  96   } else { // single line value
  97     size_t endl_pos = data->find_first_of(kNewLineChars);
  98     // if we don't find a new line, we just return the rest of the data
  99     std::string value = data->substr(0, endl_pos);
 100     data->erase(0, endl_pos);
 101     return value;
 102   }
 103 }
 104
 105 // Returns a map of system log keys and values.
 106 //
 107 // Parameters:
 108 // temp_filename: This is an out parameter that holds the name of a file in
 109 // Reads a value from the input string; erasing the read values from
 110 // the initial string; detects if the value is multiline and reads
 111 // accordingly
 112 //                /tmp that contains the system logs in a KEY=VALUE format.
 113 //                If this parameter is NULL, system logs are not retained on
 114 //                the filesystem after this call completes.
 115 // context:       This is an in parameter specifying what context should be
 116 //                passed to the syslog collection script; currently valid
 117 //                values are "sysinfo" or "feedback"; in case of an invalid
 118 //                value, the script will currently default to "sysinfo"
 119
 120 LogDictionaryType* GetSystemLogs(base::FilePath* zip_file_name,
 121                                  const std::string& context) {
 122   // Create the temp file, logs will go here
 123   base::FilePath temp_filename;
 124
 125   if (!file_util::CreateTemporaryFile(&temp_filename))
 126     return NULL;
 127
 128   std::string cmd = std::string(kSysLogsScript) + " " + context + " >> " +
 129       temp_filename.value();
 130
 131   // Ignore the return value - if the script execution didn't work
 132   // stderr won't go into the output file anyway.
 133   if (::system(cmd.c_str()) == -1)
 134     LOG(WARNING) << "Command " << cmd << " failed to run";
 135
 136   // Compress the logs file if requested.
 137   if (zip_file_name) {
 138     cmd = std::string(kBzip2Command) + " -c " + temp_filename.value() + " > " +
 139         zip_file_name->value();
 140     if (::system(cmd.c_str()) == -1)
 141       LOG(WARNING) << "Command " << cmd << " failed to run";
 142   }
 143   // Read logs from the temp file
 144   std::string data;
 145   bool read_success = base::ReadFileToString(temp_filename, &data);
 146   // if we were using an internal temp file, the user does not need the
 147   // logs to stay past the ReadFile call - delete the file
 148   base::DeleteFile(temp_filename, false);
 149
 150   if (!read_success)
 151     return NULL;
 152
 153   // Parse the return data into a dictionary
 154   LogDictionaryType* logs = new LogDictionaryType();
 155   while (data.length() > 0) {
 156     std::string key = ReadKey(&data);
 157     TrimWhitespaceASCII(key, TRIM_ALL, &key);
 158     if (!key.empty()) {
 159       std::string value = ReadValue(&data);
 160       if (IsStringUTF8(value)) {
 161         TrimWhitespaceASCII(value, TRIM_ALL, &value);
 162         if (value.empty())
 163           (*logs)[key] = kEmptyLogEntry;
 164         else
 165           (*logs)[key] = value;
 166       } else {
 167         LOG(WARNING) << "Invalid characters in system log entry: " << key;
 168         (*logs)[key] = kInvalidLogEntry;
 169       }
 170     } else {
 171       // no more keys, we're done
 172       break;
 173     }
 174   }
 175
 176   return logs;
 177 }
 178
 179 }  // namespace
 180
 181 class SyslogsProviderImpl : public SyslogsProvider {
 182  public:
 183   // SyslogsProvider implementation:
 184   virtual CancelableTaskTracker::TaskId RequestSyslogs(
 185       bool compress_logs,
 186       SyslogsContext context,
 187       const ReadCompleteCallback& callback,
 188       CancelableTaskTracker* tracker) OVERRIDE;
 189
 190   static SyslogsProviderImpl* GetInstance();
 191
 192  private:
 193   friend struct DefaultSingletonTraits<SyslogsProviderImpl>;
 194
 195   // Reads system logs, compresses content if requested.
 196   // Called from blocking pool thread.
 197   void ReadSyslogs(
 198       const CancelableTaskTracker::IsCanceledCallback& is_canceled,
 199       bool compress_logs,
 200       SyslogsContext context,
 201       const ReadCompleteCallback& callback);
 202
 203   // Loads compressed logs and writes into |zip_content|.
 204   void LoadCompressedLogs(const base::FilePath& zip_file,
 205                           std::string* zip_content);
 206
 207   SyslogsProviderImpl();
 208
 209   // Gets syslogs context string from the enum value.
 210   const char* GetSyslogsContextString(SyslogsContext context);
 211
 212   // If not canceled, run callback on originating thread (the thread on which
 213   // ReadSyslogs was run).
 214   static void RunCallbackIfNotCanceled(
 215       const CancelableTaskTracker::IsCanceledCallback& is_canceled,
 216       base::TaskRunner* origin_runner,
 217       const ReadCompleteCallback& callback,
 218       LogDictionaryType* logs,
 219       std::string* zip_content);
 220
 221   DISALLOW_COPY_AND_ASSIGN(SyslogsProviderImpl);
 222 };
 223
 224 SyslogsProviderImpl::SyslogsProviderImpl() {
 225 }
 226
 227 CancelableTaskTracker::TaskId SyslogsProviderImpl::RequestSyslogs(
 228     bool compress_logs,
 229     SyslogsContext context,
 230     const ReadCompleteCallback& callback,
 231     CancelableTaskTracker* tracker) {
 232   CancelableTaskTracker::IsCanceledCallback is_canceled;
 233   CancelableTaskTracker::TaskId id = tracker->NewTrackedTaskId(&is_canceled);
 234
 235   ReadCompleteCallback callback_runner =
 236       base::Bind(&SyslogsProviderImpl::RunCallbackIfNotCanceled,
 237                  is_canceled, base::MessageLoopProxy::current(), callback);
 238
 239   // Schedule a task which will run the callback later when complete.
 240   BrowserThread::PostBlockingPoolTask(
 241       FROM_HERE,
 242       base::Bind(&SyslogsProviderImpl::ReadSyslogs, base::Unretained(this),
 243                  is_canceled, compress_logs, context, callback_runner));
 244   return id;
 245 }
 246
 247 // Derived class from memoryDetails converts the results into a single string
 248 // and adds a "mem_usage" entry to the logs, then forwards the result.
 249 // Format of entry is (one process per line, reverse-sorted by size):
 250 //   Tab [Title1|Title2]: 50 MB
 251 //   Browser: 30 MB
 252 //   Tab [Title]: 20 MB
 253 //   Extension [Title]: 10 MB
 254 // ...
 255 class SyslogsMemoryHandler : public MemoryDetails {
 256  public:
 257   typedef SyslogsProvider::ReadCompleteCallback ReadCompleteCallback;
 258
 259   // |logs| is modified (see comment above) and passed to |request|.
 260   // |zip_content| is passed to |request|.
 261   SyslogsMemoryHandler(const ReadCompleteCallback& callback,
 262                        LogDictionaryType* logs,
 263                        std::string* zip_content);
 264
 265   virtual void OnDetailsAvailable() OVERRIDE;
 266
 267  private:
 268   virtual ~SyslogsMemoryHandler();
 269
 270   ReadCompleteCallback callback_;
 271
 272   LogDictionaryType* logs_;
 273   std::string* zip_content_;
 274
 275   DISALLOW_COPY_AND_ASSIGN(SyslogsMemoryHandler);
 276 };
 277
 278 SyslogsMemoryHandler::SyslogsMemoryHandler(
 279     const ReadCompleteCallback& callback,
 280     LogDictionaryType* logs,
 281     std::string* zip_content)
 282     : callback_(callback),
 283       logs_(logs),
 284       zip_content_(zip_content) {
 285   DCHECK(!callback_.is_null());
 286 }
 287
 288 void SyslogsMemoryHandler::OnDetailsAvailable() {
 289     (*logs_)["mem_usage"] = ToLogString();
 290     callback_.Run(logs_, zip_content_);
 291   }
 292
 293 SyslogsMemoryHandler::~SyslogsMemoryHandler() {}
 294
 295 // Called from blocking pool thread.
 296 void SyslogsProviderImpl::ReadSyslogs(
 297     const CancelableTaskTracker::IsCanceledCallback& is_canceled,
 298     bool compress_logs,
 299     SyslogsContext context,
 300     const ReadCompleteCallback& callback) {
 301   DCHECK(BrowserThread::GetBlockingPool()->RunsTasksOnCurrentThread());
 302
 303   if (is_canceled.Run())
 304     return;
 305
 306   // Create temp file.
 307   base::FilePath zip_file;
 308   if (compress_logs && !file_util::CreateTemporaryFile(&zip_file)) {
 309     LOG(ERROR) << "Cannot create temp file";
 310     compress_logs = false;
 311   }
 312
 313   LogDictionaryType* logs = NULL;
 314   logs = GetSystemLogs(
 315       compress_logs ? &zip_file : NULL,
 316       GetSyslogsContextString(context));
 317
 318   std::string* zip_content = NULL;
 319   if (compress_logs) {
 320     // Load compressed logs.
 321     zip_content = new std::string();
 322     LoadCompressedLogs(zip_file, zip_content);
 323     base::DeleteFile(zip_file, false);
 324   }
 325
 326   // Include dbus statistics summary
 327   (*logs)["dbus"] = dbus::statistics::GetAsString(
 328       dbus::statistics::SHOW_INTERFACE,
 329       dbus::statistics::FORMAT_ALL);
 330
 331   // Include recent network log events
 332   (*logs)["network_event_log"] = network_event_log::GetAsString(
 333       network_event_log::OLDEST_FIRST,
 334       "time,file,desc",
 335       network_event_log::kDefaultLogLevel,
 336       system::kFeedbackMaxLineCount);
 337
 338   // SyslogsMemoryHandler will clean itself up.
 339   // SyslogsMemoryHandler::OnDetailsAvailable() will modify |logs| and call
 340   // request->ForwardResult(logs, zip_content).
 341   scoped_refptr<SyslogsMemoryHandler>
 342       handler(new SyslogsMemoryHandler(callback, logs, zip_content));
 343   // TODO(jamescook): Maybe we don't need to update histograms here?
 344   handler->StartFetch(MemoryDetails::UPDATE_USER_METRICS);
 345 }
 346
 347 void SyslogsProviderImpl::LoadCompressedLogs(const base::FilePath& zip_file,
 348                                             std::string* zip_content) {
 349   DCHECK(zip_content);
 350   if (!base::ReadFileToString(zip_file, zip_content)) {
 351     LOG(ERROR) << "Cannot read compressed logs file from " <<
 352         zip_file.value().c_str();
 353   }
 354 }
 355
 356 const char* SyslogsProviderImpl::GetSyslogsContextString(
 357     SyslogsContext context) {
 358   switch (context) {
 359     case(SYSLOGS_FEEDBACK):
 360       return kContextFeedback;
 361     case(SYSLOGS_SYSINFO):
 362       return kContextSysInfo;
 363     case(SYSLOGS_NETWORK):
 364       return kContextNetwork;
 365     case(SYSLOGS_DEFAULT):
 366       return kContextSysInfo;
 367     default:
 368       NOTREACHED();
 369       return "";
 370   }
 371 }
 372
 373 // static
 374 void SyslogsProviderImpl::RunCallbackIfNotCanceled(
 375     const CancelableTaskTracker::IsCanceledCallback& is_canceled,
 376     base::TaskRunner* origin_runner,
 377     const ReadCompleteCallback& callback,
 378     LogDictionaryType* logs,
 379     std::string* zip_content) {
 380   DCHECK(!is_canceled.is_null() && !callback.is_null());
 381
 382   if (is_canceled.Run()) {
 383     delete logs;
 384     delete zip_content;
 385     return;
 386   }
 387
 388   // TODO(achuith@chromium.org): Maybe always run callback asynchronously?
 389   if (origin_runner->RunsTasksOnCurrentThread()) {
 390     callback.Run(logs, zip_content);
 391   } else {
 392     origin_runner->PostTask(FROM_HERE, base::Bind(callback, logs, zip_content));
 393   }
 394 }
 395
 396 SyslogsProviderImpl* SyslogsProviderImpl::GetInstance() {
 397   return Singleton<SyslogsProviderImpl,
 398                    DefaultSingletonTraits<SyslogsProviderImpl> >::get();
 399 }
 400
 401 SyslogsProvider* SyslogsProvider::GetInstance() {
 402   return SyslogsProviderImpl::GetInstance();
 403 }
 404
 405 }  // namespace system
 406 }  // namespace chromeos