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 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 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 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 { // 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 120LogDictionaryType* 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 (!base::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 181class 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 224SyslogsProviderImpl::SyslogsProviderImpl() { 225} 226 227CancelableTaskTracker::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// ... 255class 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 278SyslogsMemoryHandler::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 288void SyslogsMemoryHandler::OnDetailsAvailable() { 289 (*logs_)["mem_usage"] = ToLogString(); 290 callback_.Run(logs_, zip_content_); 291 } 292 293SyslogsMemoryHandler::~SyslogsMemoryHandler() {} 294 295// Called from blocking pool thread. 296void 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 && !base::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 347void 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 356const 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 374void 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 396SyslogsProviderImpl* SyslogsProviderImpl::GetInstance() { 397 return Singleton<SyslogsProviderImpl, 398 DefaultSingletonTraits<SyslogsProviderImpl> >::get(); 399} 400 401SyslogsProvider* SyslogsProvider::GetInstance() { 402 return SyslogsProviderImpl::GetInstance(); 403} 404 405} // namespace system 406} // namespace chromeos 407