1 // Copyright 2013 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/extensions/api/log_private/log_private_api.h" 6 7 #include <string> 8 #include <vector> 9 10 #include "base/command_line.h" 11 #include "base/json/json_writer.h" 12 #include "base/lazy_instance.h" 13 #include "base/logging.h" 14 #include "base/memory/linked_ptr.h" 15 #include "base/memory/scoped_ptr.h" 16 #include "chrome/browser/browser_process.h" 17 #include "chrome/browser/download/download_prefs.h" 18 #include "chrome/browser/extensions/api/file_handlers/app_file_handler_util.h" 19 #include "chrome/browser/extensions/api/log_private/filter_handler.h" 20 #include "chrome/browser/extensions/api/log_private/log_parser.h" 21 #include "chrome/browser/extensions/api/log_private/syslog_parser.h" 22 #include "chrome/browser/feedback/system_logs/scrubbed_system_logs_fetcher.h" 23 #include "chrome/browser/io_thread.h" 24 #include "chrome/browser/net/chrome_net_log.h" 25 #include "chrome/browser/profiles/profile.h" 26 #include "chrome/browser/profiles/profile_manager.h" 27 #include "chrome/common/extensions/api/log_private.h" 28 #include "chrome/common/logging_chrome.h" 29 #include "content/public/browser/render_process_host.h" 30 #include "extensions/browser/event_router.h" 31 #include "extensions/browser/extension_function.h" 32 #include "extensions/browser/extension_registry.h" 33 #include "extensions/browser/granted_file_entry.h" 34 35 #if defined(OS_CHROMEOS) 36 #include "chrome/browser/chromeos/system_logs/debug_log_writer.h" 37 #endif 38 39 using content::BrowserThread; 40 41 namespace events { 42 const char kOnCapturedEvents[] = "logPrivate.onCapturedEvents"; 43 } // namespace events 44 45 namespace extensions { 46 namespace { 47 48 const char kAppLogsSubdir[] = "apps"; 49 const char kLogDumpsSubdir[] = "log_dumps"; 50 const char kLogFileNameBase[] = "net-internals"; 51 const int kNetLogEventDelayMilliseconds = 100; 52 53 // Gets sequenced task runner for file specific calls within this API. 54 scoped_refptr<base::SequencedTaskRunner> GetSequencedTaskRunner() { 55 base::SequencedWorkerPool* pool = BrowserThread::GetBlockingPool(); 56 return pool->GetSequencedTaskRunnerWithShutdownBehavior( 57 pool->GetNamedSequenceToken(FileResource::kSequenceToken), 58 base::SequencedWorkerPool::BLOCK_SHUTDOWN); 59 } 60 61 // Checks if we are running on sequenced task runner thread. 62 bool IsRunningOnSequenceThread() { 63 base::SequencedWorkerPool* pool = content::BrowserThread::GetBlockingPool(); 64 return pool->IsRunningSequenceOnCurrentThread( 65 pool->GetNamedSequenceToken(FileResource::kSequenceToken)); 66 } 67 68 scoped_ptr<LogParser> CreateLogParser(const std::string& log_type) { 69 if (log_type == "syslog") 70 return scoped_ptr<LogParser>(new SyslogParser()); 71 // TODO(shinfan): Add more parser here 72 73 NOTREACHED() << "Invalid log type: " << log_type; 74 return scoped_ptr<LogParser>(); 75 } 76 77 void CollectLogInfo( 78 FilterHandler* filter_handler, 79 system_logs::SystemLogsResponse* logs, 80 std::vector<linked_ptr<api::log_private::LogEntry> >* output) { 81 for (system_logs::SystemLogsResponse::const_iterator 82 request_it = logs->begin(); request_it != logs->end(); ++request_it) { 83 if (!filter_handler->IsValidSource(request_it->first)) { 84 continue; 85 } 86 scoped_ptr<LogParser> parser(CreateLogParser(request_it->first)); 87 if (parser) { 88 parser->Parse(request_it->second, output, filter_handler); 89 } 90 } 91 } 92 93 // Returns directory location of app-specific logs that are initiated with 94 // logPrivate.startEventRecorder() calls - /home/chronos/user/log/apps 95 base::FilePath GetAppLogDirectory() { 96 return logging::GetSessionLogDir(*CommandLine::ForCurrentProcess()) 97 .Append(kAppLogsSubdir); 98 } 99 100 // Returns directory location where logs dumps initiated with chrome.dumpLogs 101 // will be stored - /home/chronos/<user_profile_dir>/Downloads/log_dumps 102 base::FilePath GetLogDumpDirectory(content::BrowserContext* context) { 103 const DownloadPrefs* const prefs = DownloadPrefs::FromBrowserContext(context); 104 return prefs->DownloadPath().Append(kLogDumpsSubdir); 105 } 106 107 // Removes direcotry content of |logs_dumps| and |app_logs_dir| (only for the 108 // primary profile). 109 void CleanUpLeftoverLogs(bool is_primary_profile, 110 const base::FilePath& app_logs_dir, 111 const base::FilePath& logs_dumps) { 112 LOG(WARNING) << "Deleting " << app_logs_dir.value(); 113 LOG(WARNING) << "Deleting " << logs_dumps.value(); 114 115 DCHECK(IsRunningOnSequenceThread()); 116 base::DeleteFile(logs_dumps, true); 117 118 // App-specific logs are stored in /home/chronos/user/log/apps directory that 119 // is shared between all profiles in multi-profile case. We should not 120 // nuke it for non-primary profiles. 121 if (!is_primary_profile) 122 return; 123 124 base::DeleteFile(app_logs_dir, true); 125 } 126 127 } // namespace 128 129 const char FileResource::kSequenceToken[] = "log_api_files"; 130 131 FileResource::FileResource(const std::string& owner_extension_id, 132 const base::FilePath& path) 133 : ApiResource(owner_extension_id), path_(path) { 134 } 135 136 FileResource::~FileResource() { 137 base::DeleteFile(path_, true); 138 } 139 140 bool FileResource::IsPersistent() const { 141 return false; 142 } 143 144 // static 145 LogPrivateAPI* LogPrivateAPI::Get(content::BrowserContext* context) { 146 LogPrivateAPI* api = GetFactoryInstance()->Get(context); 147 api->Initialize(); 148 return api; 149 } 150 151 LogPrivateAPI::LogPrivateAPI(content::BrowserContext* context) 152 : browser_context_(context), 153 logging_net_internals_(false), 154 event_sink_(api::log_private::EVENT_SINK_CAPTURE), 155 extension_registry_observer_(this), 156 log_file_resources_(context), 157 initialized_(false) { 158 } 159 160 LogPrivateAPI::~LogPrivateAPI() { 161 } 162 163 void LogPrivateAPI::StartNetInternalsWatch( 164 const std::string& extension_id, 165 api::log_private::EventSink event_sink, 166 const base::Closure& closure) { 167 net_internal_watches_.insert(extension_id); 168 169 // Nuke any leftover app-specific or dumped log files from previous sessions. 170 BrowserThread::PostTaskAndReply( 171 BrowserThread::IO, 172 FROM_HERE, 173 base::Bind(&LogPrivateAPI::MaybeStartNetInternalLogging, 174 base::Unretained(this), 175 extension_id, 176 g_browser_process->io_thread(), 177 event_sink), 178 closure); 179 } 180 181 void LogPrivateAPI::StopNetInternalsWatch(const std::string& extension_id, 182 const base::Closure& closure) { 183 net_internal_watches_.erase(extension_id); 184 MaybeStopNetInternalLogging(closure); 185 } 186 187 void LogPrivateAPI::StopAllWatches(const std::string& extension_id, 188 const base::Closure& closure) { 189 StopNetInternalsWatch(extension_id, closure); 190 } 191 192 void LogPrivateAPI::RegisterTempFile(const std::string& owner_extension_id, 193 const base::FilePath& file_path) { 194 if (!IsRunningOnSequenceThread()) { 195 GetSequencedTaskRunner()->PostTask( 196 FROM_HERE, 197 base::Bind(&LogPrivateAPI::RegisterTempFile, 198 base::Unretained(this), 199 owner_extension_id, 200 file_path)); 201 return; 202 } 203 204 log_file_resources_.Add(new FileResource(owner_extension_id, file_path)); 205 } 206 207 static base::LazyInstance<BrowserContextKeyedAPIFactory<LogPrivateAPI> > 208 g_factory = LAZY_INSTANCE_INITIALIZER; 209 210 // static 211 BrowserContextKeyedAPIFactory<LogPrivateAPI>* 212 LogPrivateAPI::GetFactoryInstance() { 213 return g_factory.Pointer(); 214 } 215 216 void LogPrivateAPI::OnAddEntry(const net::NetLog::Entry& entry) { 217 // We could receive events on whatever thread they happen to be generated, 218 // since we are only interested in network events, we should ignore any 219 // other thread than BrowserThread::IO. 220 if (!BrowserThread::CurrentlyOn(BrowserThread::IO)) { 221 return; 222 } 223 224 if (!pending_entries_.get()) { 225 pending_entries_.reset(new base::ListValue()); 226 BrowserThread::PostDelayedTask( 227 BrowserThread::IO, FROM_HERE, 228 base::Bind(&LogPrivateAPI::PostPendingEntries, base::Unretained(this)), 229 base::TimeDelta::FromMilliseconds(kNetLogEventDelayMilliseconds)); 230 } 231 pending_entries_->Append(entry.ToValue()); 232 } 233 234 void LogPrivateAPI::PostPendingEntries() { 235 BrowserThread::PostTask( 236 BrowserThread::UI, FROM_HERE, 237 base::Bind(&LogPrivateAPI:: AddEntriesOnUI, 238 base::Unretained(this), 239 base::Passed(&pending_entries_))); 240 } 241 242 void LogPrivateAPI::AddEntriesOnUI(scoped_ptr<base::ListValue> value) { 243 DCHECK_CURRENTLY_ON(BrowserThread::UI); 244 245 for (std::set<std::string>::iterator ix = net_internal_watches_.begin(); 246 ix != net_internal_watches_.end(); ++ix) { 247 // Create the event's arguments value. 248 scoped_ptr<base::ListValue> event_args(new base::ListValue()); 249 event_args->Append(value->DeepCopy()); 250 scoped_ptr<Event> event( 251 new Event(events::kOnCapturedEvents, event_args.Pass())); 252 EventRouter::Get(browser_context_) 253 ->DispatchEventToExtension(*ix, event.Pass()); 254 } 255 } 256 257 void LogPrivateAPI::InitializeNetLogger(const std::string& owner_extension_id, 258 net::NetLogLogger** net_log_logger) { 259 DCHECK(IsRunningOnSequenceThread()); 260 (*net_log_logger) = NULL; 261 262 // Create app-specific subdirectory in session logs folder. 263 base::FilePath app_log_dir = GetAppLogDirectory().Append(owner_extension_id); 264 if (!base::DirectoryExists(app_log_dir)) { 265 if (!base::CreateDirectory(app_log_dir)) { 266 LOG(ERROR) << "Could not create dir " << app_log_dir.value(); 267 return; 268 } 269 } 270 271 base::FilePath file_path = app_log_dir.Append(kLogFileNameBase); 272 file_path = logging::GenerateTimestampedName(file_path, base::Time::Now()); 273 FILE* file = NULL; 274 file = fopen(file_path.value().c_str(), "w"); 275 if (file == NULL) { 276 LOG(ERROR) << "Could not open " << file_path.value(); 277 return; 278 } 279 280 RegisterTempFile(owner_extension_id, file_path); 281 scoped_ptr<base::Value> constants(net::NetLogLogger::GetConstants()); 282 *net_log_logger = new net::NetLogLogger(file, *constants); 283 (*net_log_logger)->set_log_level(net::NetLog::LOG_ALL_BUT_BYTES); 284 } 285 286 void LogPrivateAPI::StartObservingNetEvents( 287 IOThread* io_thread, 288 net::NetLogLogger** net_log_logger) { 289 DCHECK_CURRENTLY_ON(BrowserThread::IO); 290 if (!(*net_log_logger)) 291 return; 292 293 net_log_logger_.reset(*net_log_logger); 294 net_log_logger_->StartObserving(io_thread->net_log()); 295 } 296 297 void LogPrivateAPI::MaybeStartNetInternalLogging( 298 const std::string& caller_extension_id, 299 IOThread* io_thread, 300 api::log_private::EventSink event_sink) { 301 DCHECK_CURRENTLY_ON(BrowserThread::IO); 302 if (!logging_net_internals_) { 303 logging_net_internals_ = true; 304 event_sink_ = event_sink; 305 switch (event_sink_) { 306 case api::log_private::EVENT_SINK_CAPTURE: { 307 io_thread->net_log()->AddThreadSafeObserver( 308 this, net::NetLog::LOG_ALL_BUT_BYTES); 309 break; 310 } 311 case api::log_private::EVENT_SINK_FILE: { 312 net::NetLogLogger** net_logger_ptr = new net::NetLogLogger* [1]; 313 // Initialize net logger on the blocking pool and start observing event 314 // with in on IO thread. 315 GetSequencedTaskRunner()->PostTaskAndReply( 316 FROM_HERE, 317 base::Bind(&LogPrivateAPI::InitializeNetLogger, 318 base::Unretained(this), 319 caller_extension_id, 320 net_logger_ptr), 321 base::Bind(&LogPrivateAPI::StartObservingNetEvents, 322 base::Unretained(this), 323 io_thread, 324 base::Owned(net_logger_ptr))); 325 break; 326 } 327 case api::log_private::EVENT_SINK_NONE: { 328 NOTREACHED(); 329 break; 330 } 331 } 332 } 333 } 334 335 void LogPrivateAPI::MaybeStopNetInternalLogging(const base::Closure& closure) { 336 if (net_internal_watches_.empty()) { 337 if (closure.is_null()) { 338 BrowserThread::PostTask( 339 BrowserThread::IO, 340 FROM_HERE, 341 base::Bind(&LogPrivateAPI::StopNetInternalLogging, 342 base::Unretained(this))); 343 } else { 344 BrowserThread::PostTaskAndReply( 345 BrowserThread::IO, 346 FROM_HERE, 347 base::Bind(&LogPrivateAPI::StopNetInternalLogging, 348 base::Unretained(this)), 349 closure); 350 } 351 } 352 } 353 354 void LogPrivateAPI::StopNetInternalLogging() { 355 DCHECK_CURRENTLY_ON(BrowserThread::IO); 356 if (net_log() && logging_net_internals_) { 357 logging_net_internals_ = false; 358 switch (event_sink_) { 359 case api::log_private::EVENT_SINK_CAPTURE: 360 net_log()->RemoveThreadSafeObserver(this); 361 break; 362 case api::log_private::EVENT_SINK_FILE: 363 net_log_logger_->StopObserving(); 364 net_log_logger_.reset(); 365 break; 366 case api::log_private::EVENT_SINK_NONE: 367 NOTREACHED(); 368 break; 369 } 370 } 371 } 372 373 void LogPrivateAPI::Initialize() { 374 if (initialized_) 375 return; 376 377 // Clean up temp files and folders from the previous sessions. 378 initialized_ = true; 379 extension_registry_observer_.Add(ExtensionRegistry::Get(browser_context_)); 380 GetSequencedTaskRunner()->PostTask( 381 FROM_HERE, 382 base::Bind(&CleanUpLeftoverLogs, 383 Profile::FromBrowserContext(browser_context_) == 384 ProfileManager::GetPrimaryUserProfile(), 385 GetAppLogDirectory(), 386 GetLogDumpDirectory(browser_context_))); 387 } 388 389 void LogPrivateAPI::OnExtensionUnloaded( 390 content::BrowserContext* browser_context, 391 const Extension* extension, 392 UnloadedExtensionInfo::Reason reason) { 393 StopNetInternalsWatch(extension->id(), base::Closure()); 394 } 395 396 LogPrivateGetHistoricalFunction::LogPrivateGetHistoricalFunction() { 397 } 398 399 LogPrivateGetHistoricalFunction::~LogPrivateGetHistoricalFunction() { 400 } 401 402 bool LogPrivateGetHistoricalFunction::RunAsync() { 403 // Get parameters 404 scoped_ptr<api::log_private::GetHistorical::Params> params( 405 api::log_private::GetHistorical::Params::Create(*args_)); 406 EXTENSION_FUNCTION_VALIDATE(params.get()); 407 filter_handler_.reset(new FilterHandler(params->filter)); 408 409 system_logs::SystemLogsFetcherBase* fetcher; 410 if ((params->filter).scrub) { 411 fetcher = new system_logs::ScrubbedSystemLogsFetcher(); 412 } else { 413 fetcher = new system_logs::AboutSystemLogsFetcher(); 414 } 415 fetcher->Fetch( 416 base::Bind(&LogPrivateGetHistoricalFunction::OnSystemLogsLoaded, this)); 417 418 return true; 419 } 420 421 void LogPrivateGetHistoricalFunction::OnSystemLogsLoaded( 422 scoped_ptr<system_logs::SystemLogsResponse> sys_info) { 423 std::vector<linked_ptr<api::log_private::LogEntry> > data; 424 425 CollectLogInfo(filter_handler_.get(), sys_info.get(), &data); 426 427 // Prepare result 428 api::log_private::Result result; 429 result.data = data; 430 api::log_private::Filter::Populate( 431 *((filter_handler_->GetFilter())->ToValue()), &result.filter); 432 SetResult(result.ToValue().release()); 433 SendResponse(true); 434 } 435 436 LogPrivateStartEventRecorderFunction::LogPrivateStartEventRecorderFunction() { 437 } 438 439 LogPrivateStartEventRecorderFunction::~LogPrivateStartEventRecorderFunction() { 440 } 441 442 bool LogPrivateStartEventRecorderFunction::RunAsync() { 443 scoped_ptr<api::log_private::StartEventRecorder::Params> params( 444 api::log_private::StartEventRecorder::Params::Create(*args_)); 445 EXTENSION_FUNCTION_VALIDATE(params.get()); 446 switch (params->event_type) { 447 case api::log_private::EVENT_TYPE_NETWORK: 448 LogPrivateAPI::Get(Profile::FromBrowserContext(browser_context())) 449 ->StartNetInternalsWatch( 450 extension_id(), 451 params->sink, 452 base::Bind( 453 &LogPrivateStartEventRecorderFunction::OnEventRecorderStarted, 454 this)); 455 break; 456 case api::log_private::EVENT_TYPE_NONE: 457 NOTREACHED(); 458 return false; 459 } 460 461 return true; 462 } 463 464 void LogPrivateStartEventRecorderFunction::OnEventRecorderStarted() { 465 SendResponse(true); 466 } 467 468 LogPrivateStopEventRecorderFunction::LogPrivateStopEventRecorderFunction() { 469 } 470 471 LogPrivateStopEventRecorderFunction::~LogPrivateStopEventRecorderFunction() { 472 } 473 474 bool LogPrivateStopEventRecorderFunction::RunAsync() { 475 scoped_ptr<api::log_private::StopEventRecorder::Params> params( 476 api::log_private::StopEventRecorder::Params::Create(*args_)); 477 EXTENSION_FUNCTION_VALIDATE(params.get()); 478 switch (params->event_type) { 479 case api::log_private::EVENT_TYPE_NETWORK: 480 LogPrivateAPI::Get(Profile::FromBrowserContext(browser_context())) 481 ->StopNetInternalsWatch( 482 extension_id(), 483 base::Bind( 484 &LogPrivateStopEventRecorderFunction::OnEventRecorderStopped, 485 this)); 486 break; 487 case api::log_private::EVENT_TYPE_NONE: 488 NOTREACHED(); 489 return false; 490 } 491 return true; 492 } 493 494 void LogPrivateStopEventRecorderFunction::OnEventRecorderStopped() { 495 SendResponse(true); 496 } 497 498 LogPrivateDumpLogsFunction::LogPrivateDumpLogsFunction() { 499 } 500 501 LogPrivateDumpLogsFunction::~LogPrivateDumpLogsFunction() { 502 } 503 504 bool LogPrivateDumpLogsFunction::RunAsync() { 505 LogPrivateAPI::Get(Profile::FromBrowserContext(browser_context())) 506 ->StopAllWatches( 507 extension_id(), 508 base::Bind(&LogPrivateDumpLogsFunction::OnStopAllWatches, this)); 509 return true; 510 } 511 512 void LogPrivateDumpLogsFunction::OnStopAllWatches() { 513 chromeos::DebugLogWriter::StoreCombinedLogs( 514 GetLogDumpDirectory(browser_context()).Append(extension_id()), 515 FileResource::kSequenceToken, 516 base::Bind(&LogPrivateDumpLogsFunction::OnStoreLogsCompleted, this)); 517 } 518 519 void LogPrivateDumpLogsFunction::OnStoreLogsCompleted( 520 const base::FilePath& log_path, 521 bool succeeded) { 522 if (succeeded) { 523 LogPrivateAPI::Get(Profile::FromBrowserContext(browser_context())) 524 ->RegisterTempFile(extension_id(), log_path); 525 } 526 527 scoped_ptr<base::DictionaryValue> response(new base::DictionaryValue()); 528 extensions::GrantedFileEntry file_entry = 529 extensions::app_file_handler_util::CreateFileEntry( 530 Profile::FromBrowserContext(browser_context()), 531 extension(), 532 render_view_host_->GetProcess()->GetID(), 533 log_path, 534 false); 535 536 base::DictionaryValue* entry = new base::DictionaryValue(); 537 entry->SetString("fileSystemId", file_entry.filesystem_id); 538 entry->SetString("baseName", file_entry.registered_name); 539 entry->SetString("id", file_entry.id); 540 entry->SetBoolean("isDirectory", false); 541 base::ListValue* entry_list = new base::ListValue(); 542 entry_list->Append(entry); 543 response->Set("entries", entry_list); 544 response->SetBoolean("multiple", false); 545 SetResult(response.release()); 546 SendResponse(succeeded); 547 } 548 549 } // namespace extensions 550