syslogs_provider.cc revision b2df76ea8fec9e32f6f3718986dba0d95315b29c
1cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)// Copyright (c) 2012 The Chromium Authors. All rights reserved. 25821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// Use of this source code is governed by a BSD-style license that can be 35821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// found in the LICENSE file. 45821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 5cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "chrome/browser/chromeos/system/syslogs_provider.h" 6cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 75821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "ash/shell.h" 868043e1e95eeb07d5cae7aca370b26518b0867d6Torne (Richard Coles)#include "base/bind.h" 95821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/bind_helpers.h" 10cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/command_line.h" 115821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/compiler_specific.h" 125821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)#include "base/file_util.h" 13cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/files/file_path.h" 14cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/logging.h" 15cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/memory/scoped_ptr.h" 16cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/memory/singleton.h" 17cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/message_loop/message_loop_proxy.h" 18cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/string_util.h" 19cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/task_runner.h" 20cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "base/threading/sequenced_worker_pool.h" 21cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "chrome/browser/feedback/feedback_util.h" 22cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "chrome/browser/memory_details.h" 23cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "chrome/common/chrome_switches.h" 24cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "chromeos/network/network_event_log.h" 25cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "content/public/browser/browser_thread.h" 26cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)#include "dbus/dbus_statistics.h" 27cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 28cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)using content::BrowserThread; 29cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 30cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)namespace chromeos { 31cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)namespace system { 32cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 33cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)const size_t kFeedbackMaxLength = 4 * 1024; 34cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)const size_t kFeedbackMaxLineCount = 40; 35cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 36cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles)namespace { 37cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 385821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kSysLogsScript[] = 395821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) "/usr/share/userfeedback/scripts/sysinfo_script_runner"; 405821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kBzip2Command[] = 415821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) "/bin/bzip2"; 425821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kMultilineQuote[] = "\"\"\""; 437dbb3d5cf0c15f500944d211057644d6a2f37371Ben Murdochconst char kNewLineChars[] = "\r\n"; 445821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kInvalidLogEntry[] = "<invalid characters in log entry>"; 455821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kEmptyLogEntry[] = "<no value>"; 465821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) 475821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kContextFeedback[] = "feedback"; 485821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kContextSysInfo[] = "sysinfo"; 495821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)const char kContextNetwork[] = "network"; 5068043e1e95eeb07d5cae7aca370b26518b0867d6Torne (Richard Coles) 515821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// Reads a key from the input string erasing the read values + delimiters read 525821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)// from the initial string 535821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles)std::string ReadKey(std::string* data) { 545821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) size_t equal_sign = data->find("="); 555821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (equal_sign == std::string::npos) 565821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) return std::string(""); 575821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) std::string key = data->substr(0, equal_sign); 585821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->erase(0, equal_sign); 595821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) if (data->size() > 0) { 605821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) // erase the equal to sign also 615821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) data->erase(0,1); 62cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) return key; 635821806d5e7f356e8fa4b058a389a808ea183019Torne (Richard Coles) } 64cedac228d2dd51db4b79ea1e72c7f249408ee061Torne (Richard Coles) 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 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 (!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 = file_util::ReadFileToString(temp_filename, 146 &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 file_util::Delete(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 TrimWhitespaceASCII(key, TRIM_ALL, &key); 159 if (!key.empty()) { 160 std::string value = ReadValue(&data); 161 if (IsStringUTF8(value)) { 162 TrimWhitespaceASCII(value, 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 CancelableTaskTracker::TaskId RequestSyslogs( 186 bool compress_logs, 187 SyslogsContext context, 188 const ReadCompleteCallback& callback, 189 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 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 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 228CancelableTaskTracker::TaskId SyslogsProviderImpl::RequestSyslogs( 229 bool compress_logs, 230 SyslogsContext context, 231 const ReadCompleteCallback& callback, 232 CancelableTaskTracker* tracker) { 233 CancelableTaskTracker::IsCanceledCallback is_canceled; 234 CancelableTaskTracker::TaskId id = tracker->NewTrackedTaskId(&is_canceled); 235 236 ReadCompleteCallback callback_runner = 237 base::Bind(&SyslogsProviderImpl::RunCallbackIfNotCanceled, 238 is_canceled, base::MessageLoopProxy::current(), callback); 239 240 // Schedule a task which will run the callback later when complete. 241 BrowserThread::PostBlockingPoolTask( 242 FROM_HERE, 243 base::Bind(&SyslogsProviderImpl::ReadSyslogs, base::Unretained(this), 244 is_canceled, compress_logs, context, callback_runner)); 245 return id; 246} 247 248// Derived class from memoryDetails converts the results into a single string 249// and adds a "mem_usage" entry to the logs, then forwards the result. 250// Format of entry is (one process per line, reverse-sorted by size): 251// Tab [Title1|Title2]: 50 MB 252// Browser: 30 MB 253// Tab [Title]: 20 MB 254// Extension [Title]: 10 MB 255// ... 256class SyslogsMemoryHandler : public MemoryDetails { 257 public: 258 typedef SyslogsProvider::ReadCompleteCallback ReadCompleteCallback; 259 260 // |logs| is modified (see comment above) and passed to |request|. 261 // |zip_content| is passed to |request|. 262 SyslogsMemoryHandler(const ReadCompleteCallback& callback, 263 LogDictionaryType* logs, 264 std::string* zip_content); 265 266 virtual void OnDetailsAvailable() OVERRIDE; 267 268 private: 269 virtual ~SyslogsMemoryHandler(); 270 271 ReadCompleteCallback callback_; 272 273 LogDictionaryType* logs_; 274 std::string* zip_content_; 275 276 DISALLOW_COPY_AND_ASSIGN(SyslogsMemoryHandler); 277}; 278 279SyslogsMemoryHandler::SyslogsMemoryHandler( 280 const ReadCompleteCallback& callback, 281 LogDictionaryType* logs, 282 std::string* zip_content) 283 : callback_(callback), 284 logs_(logs), 285 zip_content_(zip_content) { 286 DCHECK(!callback_.is_null()); 287} 288 289void SyslogsMemoryHandler::OnDetailsAvailable() { 290 (*logs_)["mem_usage"] = ToLogString(); 291 callback_.Run(logs_, zip_content_); 292 } 293 294SyslogsMemoryHandler::~SyslogsMemoryHandler() {} 295 296// Called from blocking pool thread. 297void SyslogsProviderImpl::ReadSyslogs( 298 const CancelableTaskTracker::IsCanceledCallback& is_canceled, 299 bool compress_logs, 300 SyslogsContext context, 301 const ReadCompleteCallback& callback) { 302 DCHECK(BrowserThread::GetBlockingPool()->RunsTasksOnCurrentThread()); 303 304 if (is_canceled.Run()) 305 return; 306 307 // Create temp file. 308 base::FilePath zip_file; 309 if (compress_logs && !file_util::CreateTemporaryFile(&zip_file)) { 310 LOG(ERROR) << "Cannot create temp file"; 311 compress_logs = false; 312 } 313 314 LogDictionaryType* logs = NULL; 315 logs = GetSystemLogs( 316 compress_logs ? &zip_file : NULL, 317 GetSyslogsContextString(context)); 318 319 std::string* zip_content = NULL; 320 if (compress_logs) { 321 // Load compressed logs. 322 zip_content = new std::string(); 323 LoadCompressedLogs(zip_file, zip_content); 324 file_util::Delete(zip_file, false); 325 } 326 327 // Include dbus statistics summary 328 (*logs)["dbus"] = dbus::statistics::GetAsString( 329 dbus::statistics::SHOW_INTERFACE, 330 dbus::statistics::FORMAT_ALL); 331 332 // Include recent network log events 333 (*logs)["network_event_log"] = chromeos::network_event_log::GetAsString( 334 chromeos::network_event_log::OLDEST_FIRST, 335 chromeos::system::kFeedbackMaxLineCount); 336 337 // SyslogsMemoryHandler will clean itself up. 338 // SyslogsMemoryHandler::OnDetailsAvailable() will modify |logs| and call 339 // request->ForwardResult(logs, zip_content). 340 scoped_refptr<SyslogsMemoryHandler> 341 handler(new SyslogsMemoryHandler(callback, logs, zip_content)); 342 // TODO(jamescook): Maybe we don't need to update histograms here? 343 handler->StartFetch(MemoryDetails::UPDATE_USER_METRICS); 344} 345 346void SyslogsProviderImpl::LoadCompressedLogs(const base::FilePath& zip_file, 347 std::string* zip_content) { 348 DCHECK(zip_content); 349 if (!file_util::ReadFileToString(zip_file, zip_content)) { 350 LOG(ERROR) << "Cannot read compressed logs file from " << 351 zip_file.value().c_str(); 352 } 353} 354 355const char* SyslogsProviderImpl::GetSyslogsContextString( 356 SyslogsContext context) { 357 switch (context) { 358 case(SYSLOGS_FEEDBACK): 359 return kContextFeedback; 360 case(SYSLOGS_SYSINFO): 361 return kContextSysInfo; 362 case(SYSLOGS_NETWORK): 363 return kContextNetwork; 364 case(SYSLOGS_DEFAULT): 365 return kContextSysInfo; 366 default: 367 NOTREACHED(); 368 return ""; 369 } 370} 371 372// static 373void SyslogsProviderImpl::RunCallbackIfNotCanceled( 374 const CancelableTaskTracker::IsCanceledCallback& is_canceled, 375 base::TaskRunner* origin_runner, 376 const ReadCompleteCallback& callback, 377 LogDictionaryType* logs, 378 std::string* zip_content) { 379 DCHECK(!is_canceled.is_null() && !callback.is_null()); 380 381 if (is_canceled.Run()) { 382 delete logs; 383 delete zip_content; 384 return; 385 } 386 387 // TODO(achuith@chromium.org): Maybe always run callback asynchronously? 388 if (origin_runner->RunsTasksOnCurrentThread()) { 389 callback.Run(logs, zip_content); 390 } else { 391 origin_runner->PostTask(FROM_HERE, base::Bind(callback, logs, zip_content)); 392 } 393} 394 395SyslogsProviderImpl* SyslogsProviderImpl::GetInstance() { 396 return Singleton<SyslogsProviderImpl, 397 DefaultSingletonTraits<SyslogsProviderImpl> >::get(); 398} 399 400SyslogsProvider* SyslogsProvider::GetInstance() { 401 return SyslogsProviderImpl::GetInstance(); 402} 403 404} // namespace system 405} // namespace chromeos 406