Home | History | Annotate | Download | only in log_private 
      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