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