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/files/file_path.h"
13#include "base/files/file_util.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/memory_details.h"
22#include "chrome/common/chrome_switches.h"
23#include "chromeos/network/network_event_log.h"
24#include "components/feedback/feedback_util.h"
25#include "content/public/browser/browser_thread.h"
26#include "dbus/dbus_statistics.h"
27
28using content::BrowserThread;
29
30namespace chromeos {
31namespace system {
32
33const size_t kFeedbackMaxLength = 4 * 1024;
34const size_t kFeedbackMaxLineCount = 40;
35
36namespace {
37
38const char kSysLogsScript[] =
39    "/usr/share/userfeedback/scripts/sysinfo_script_runner";
40const char kBzip2Command[] =
41    "/bin/bzip2";
42const char kMultilineQuote[] = "\"\"\"";
43const char kNewLineChars[] = "\r\n";
44const char kInvalidLogEntry[] = "<invalid characters in log entry>";
45const char kEmptyLogEntry[] = "<no value>";
46
47const char kContextFeedback[] = "feedback";
48const char kContextSysInfo[] = "sysinfo";
49const char kContextNetwork[] = "network";
50
51// Reads a key from the input string erasing the read values + delimiters read
52// from the initial string
53std::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
70std::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
121LogDictionaryType* 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 (base::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
182class 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
225SyslogsProviderImpl::SyslogsProviderImpl() {
226}
227
228base::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// ...
257class 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
280SyslogsMemoryHandler::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
290void SyslogsMemoryHandler::OnDetailsAvailable() {
291    (*logs_)["mem_usage"] = ToLogString();
292    callback_.Run(logs_, zip_content_);
293  }
294
295SyslogsMemoryHandler::~SyslogsMemoryHandler() {}
296
297// Called from blocking pool thread.
298void 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
349void 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
358const 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
376void 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
398SyslogsProviderImpl* SyslogsProviderImpl::GetInstance() {
399  return Singleton<SyslogsProviderImpl,
400                   DefaultSingletonTraits<SyslogsProviderImpl> >::get();
401}
402
403SyslogsProvider* SyslogsProvider::GetInstance() {
404  return SyslogsProviderImpl::GetInstance();
405}
406
407}  // namespace system
408}  // namespace chromeos
409