Present drivefs logs on drive-internals page.

BUG=chromium:856874

Change-Id: I9e7e9645d120b27868618053cffd5953908b99b1
Reviewed-on: https://chromium-review.googlesource.com/1184801Reviewed-by: Luciano Pacheco <lucmult@chromium.org>
Reviewed-by: Sam McNally <sammc@chromium.org>
Commit-Queue: Sergei Datsenko <dats@chromium.org>
Cr-Commit-Position: refs/heads/master@{#585718}

chrome/browser/chromeos/drive/drive_integration_service.cc

@@ -559,6 +559,13 @@ base::FilePath DriveIntegrationService::GetMountPointPath() const {
                          : drive::util::GetDriveMountPointPath(profile_);
 }
 
+base::FilePath DriveIntegrationService::GetDriveFsLogPath() const {
+  return drivefs_holder_
+             ? drivefs_holder_->drivefs_host()->GetDataPath().Append(
+                   "Logs/drivefs.txt")
+             : base::FilePath();
+}
+
 bool DriveIntegrationService::GetRelativeDrivePath(
     const base::FilePath& local_path,
     base::FilePath* drive_path) const {

chrome/browser/chromeos/drive/drive_integration_service.h

@@ -115,6 +115,9 @@ class DriveIntegrationService : public KeyedService,
   // |IsMounted()|.
   base::FilePath GetMountPointPath() const;
 
+  // Returns the path of DriveFS log if enabled or empty path.
+  base::FilePath GetDriveFsLogPath() const;
+
   // Returns true if |local_path| resides inside |GetMountPointPath()|.
   // In this case |drive_path| will contain 'drive' path of this file, e.g.
   // reparented to the mount point.

chrome/browser/resources/chromeos/drive_internals.html

@@ -142,5 +142,9 @@
     <h2 id="event-log-section">Event Log</h2>
     <ul id="event-log">
     </ul>
+
+    <h2 id="service-log-section">Service Log</h2>
+    <ul id="service-log">
+    </ul>
   </body>
 </html>

chrome/browser/resources/chromeos/drive_internals.js

@@ -221,6 +221,15 @@ function updateEventLog(log) {
   updateKeyValueList(ul, log);
 }
 
+/**
+ * Updates the service log section.
+ * @param {Array} log Log lines.
+ */
+function updateServiceLog(log) {
+  var ul = $('service-log');
+  updateKeyValueList(ul, log);
+}
+
 /**
  * Creates an element named |elementName| containing the content |text|.
  * @param {string} elementName Name of the new element to be created.

chrome/browser/ui/webui/chromeos/drive_internals_ui.cc

@@ -7,6 +7,7 @@
 #include <stddef.h>
 #include <stdint.h>
 
+#include <fstream>
 #include <memory>
 #include <utility>
 
@@ -17,6 +18,8 @@
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
 #include "base/path_service.h"
+#include "base/strings/pattern.h"
+#include "base/strings/strcat.h"
 #include "base/strings/stringprintf.h"
 #include "base/sys_info.h"
 #include "base/task/post_task.h"
@@ -52,6 +55,32 @@ namespace chromeos {
 
 namespace {
 
+constexpr char kKey[] = "key";
+constexpr char kValue[] = "value";
+constexpr char kClass[] = "class";
+
+constexpr const char* const kLogLevelName[] = {"info", "warning", "error"};
+
+size_t SeverityToLogLevelNameIndex(logging::LogSeverity severity) {
+  if (severity <= logging::LOG_INFO)
+    return 0;
+  if (severity == logging::LOG_WARNING)
+    return 1;
+  return 2;
+}
+
+size_t LogMarkToLogLevelNameIndex(char mark) {
+  switch (mark) {
+    case 'I':
+    case 'V':
+      return 0;
+    case 'W':
+      return 1;
+    default:
+      return 2;
+  }
+}
+
 // Gets metadata of all files and directories in |root_path|
 // recursively. Stores the result as a list of dictionaries like:
 //
@@ -189,27 +218,73 @@ std::string FormatEntry(const base::FilePath& path,
   return out;
 }
 
-std::string SeverityToString(logging::LogSeverity severity) {
-  switch (severity) {
-    case logging::LOG_INFO:
-      return "info";
-    case logging::LOG_WARNING:
-      return "warning";
-    case logging::LOG_ERROR:
-      return "error";
-    default:  // Treat all other higher severities as ERROR.
-      return "error";
-  }
-}
-
-// Appends {'key': key, 'value': value} dictionary to the |list|.
+// Appends {'key': key, 'value': value, 'class': clazz} dictionary to the
+// |list|.
 void AppendKeyValue(base::ListValue* list,
-                    const std::string& key,
-                    const std::string& value) {
+                    std::string key,
+                    std::string value,
+                    std::string clazz = std::string()) {
   auto dict = std::make_unique<base::DictionaryValue>();
-  dict->SetString("key", key);
-  dict->SetString("value", value);
-  list->Append(std::move(dict));
+  dict->SetPath({kKey}, base::Value(std::move(key)));
+  dict->SetPath({kValue}, base::Value(std::move(value)));
+  if (!clazz.empty())
+    dict->SetPath({kClass}, base::Value(std::move(clazz)));
+  list->GetList().push_back(std::move(*dict));
+}
+
+ino_t GetInodeValue(const base::FilePath& path) {
+  struct stat file_stats;
+  if (stat(path.value().c_str(), &file_stats) != 0)
+    return 0;
+  return file_stats.st_ino;
+}
+
+std::pair<ino_t, base::ListValue> GetServiceLogContents(
+    const base::FilePath& log_path,
+    ino_t inode,
+    int from_line_number) {
+  base::ListValue result;
+
+  std::ifstream log(log_path.value());
+  if (log.good()) {
+    ino_t new_inode = GetInodeValue(log_path);
+    if (new_inode != inode) {
+      // Apparently log was recreated. Re-read the log.
+      from_line_number = 0;
+      inode = new_inode;
+    }
+
+    base::Time time;
+    constexpr char kTimestampPattern[] = R"(????-??-??T??:??:??.???Z? )";
+    const size_t pattern_length = strlen(kTimestampPattern);
+
+    std::string line;
+    int line_number = 0;
+    while (log.good()) {
+      std::getline(log, line);
+      if (line.empty() || ++line_number <= from_line_number) {
+        continue;
+      }
+
+      base::StringPiece log_line = line;
+      size_t severity_index = 0;
+      if (base::MatchPattern(log_line.substr(0, pattern_length),
+                             kTimestampPattern) &&
+          google_apis::util::GetTimeFromString(
+              log_line.substr(0, pattern_length - 2), &time)) {
+        severity_index = LogMarkToLogLevelNameIndex(line[pattern_length - 2]);
+        line = line.substr(pattern_length);
+      }
+      const char* const severity = kLogLevelName[severity_index];
+
+      AppendKeyValue(&result,
+                     google_apis::util::FormatTimeAsStringLocaltime(time),
+                     base::StrCat({"[", severity, "] ", line}),
+                     base::StrCat({"log-", severity}));
+    }
+  }
+
+  return {inode, std::move(result)};
 }
 
 // Class to handle messages from chrome://drive-internals.
@@ -255,6 +330,7 @@ class DriveInternalsWebUIHandler : public content::WebUIMessageHandler {
   void UpdateCacheContentsSection(
       drive::DebugInfoCollector* debug_info_collector);
   void UpdateEventLogSection();
+  void UpdateServiceLogSection();
   void UpdatePathConfigurationsSection();
 
   // Called when GetGCacheContents() is complete.
@@ -306,9 +382,21 @@ class DriveInternalsWebUIHandler : public content::WebUIMessageHandler {
   // Called after file system reset for ResetDriveFileSystem is done.
   void ResetFinished(bool success);
 
+  // Called when service logs are read.
+  void OnServiceLogRead(std::pair<ino_t, base::ListValue>);
+
   // The last event sent to the JavaScript side.
   int last_sent_event_id_;
 
+  // The last line of service log sent to the JS side.
+  int last_sent_line_number_;
+
+  // The inode of the log file.
+  ino_t service_log_file_inode_;
+
+  // Service log file is being parsed.
+  bool service_log_file_is_processing_ = false;
+
   base::WeakPtrFactory<DriveInternalsWebUIHandler> weak_ptr_factory_;
   DISALLOW_COPY_AND_ASSIGN(DriveInternalsWebUIHandler);
 };
@@ -461,6 +549,9 @@ void DriveInternalsWebUIHandler::OnPageLoaded(const base::ListValue* args) {
   // and resent whole the logs to the page.
   last_sent_event_id_ = -1;
   UpdateEventLogSection();
+  last_sent_line_number_ = 0;
+  service_log_file_inode_ = 0;
+  UpdateServiceLogSection();
 }
 
 void DriveInternalsWebUIHandler::UpdateDriveRelatedPreferencesSection() {
@@ -763,20 +854,54 @@ void DriveInternalsWebUIHandler::UpdateEventLogSection() {
     if (log[i].id <= last_sent_event_id_)
       continue;
 
-    std::string severity = SeverityToString(log[i].severity);
-
-    auto dict = std::make_unique<base::DictionaryValue>();
-    dict->SetString("key",
-        google_apis::util::FormatTimeAsStringLocaltime(log[i].when));
-    dict->SetString("value", "[" + severity + "] " + log[i].what);
-    dict->SetString("class", "log-" + severity);
-    list.Append(std::move(dict));
+    const char* const severity =
+        kLogLevelName[SeverityToLogLevelNameIndex(log[i].severity)];
+    AppendKeyValue(&list,
+                   google_apis::util::FormatTimeAsStringLocaltime(log[i].when),
+                   base::StrCat({"[", severity, "] ", log[i].what}),
+                   base::StrCat({"log-", severity}));
     last_sent_event_id_ = log[i].id;
   }
   if (!list.empty())
     web_ui()->CallJavascriptFunctionUnsafe("updateEventLog", list);
 }
 
+void DriveInternalsWebUIHandler::UpdateServiceLogSection() {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
+  if (service_log_file_is_processing_)
+    return;
+  service_log_file_is_processing_ = true;
+
+  drive::DriveIntegrationService* integration_service = GetIntegrationService();
+  if (!integration_service)
+    return;
+  base::FilePath log_path = integration_service->GetDriveFsLogPath();
+  if (log_path.empty())
+    return;
+
+  base::PostTaskWithTraitsAndReplyWithResult(
+      FROM_HERE, {base::MayBlock(), base::TaskPriority::USER_VISIBLE},
+      base::BindOnce(&GetServiceLogContents, log_path, service_log_file_inode_,
+                     last_sent_line_number_),
+      base::BindOnce(&DriveInternalsWebUIHandler::OnServiceLogRead,
+                     weak_ptr_factory_.GetWeakPtr()));
+}
+
+void DriveInternalsWebUIHandler::OnServiceLogRead(
+    std::pair<ino_t, base::ListValue> response) {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  if (service_log_file_inode_ != response.first) {
+    service_log_file_inode_ = response.first;
+    last_sent_line_number_ = 0;
+  }
+  if (!response.second.empty()) {
+    web_ui()->CallJavascriptFunctionUnsafe("updateServiceLog", response.second);
+    last_sent_line_number_ += response.second.GetList().size();
+  }
+  service_log_file_is_processing_ = false;
+}
+
 void DriveInternalsWebUIHandler::UpdatePathConfigurationsSection() {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
@@ -901,6 +1026,7 @@ void DriveInternalsWebUIHandler::OnPeriodicUpdate(const base::ListValue* args) {
     return;
 
   UpdateEventLogSection();
+  UpdateServiceLogSection();
 
   drive::JobListInterface* job_list = integration_service->job_list();
   if (job_list) {

chromeos/components/drivefs/drivefs_host.cc

@@ -79,10 +79,8 @@ class DriveFsHost::MountState : public mojom::DriveFsDelegate,
         pending_token_(base::UnguessableToken::Create()),
         binding_(this) {
     source_path_ = base::StrCat({kMountScheme, pending_token_.ToString()});
-    std::string datadir_option = base::StrCat(
-        {"datadir=", host_->profile_path_.Append(kDataPath)
-                         .Append(host_->delegate_->GetObfuscatedAccountId())
-                         .value()});
+    std::string datadir_option =
+        base::StrCat({"datadir=", host_->GetDataPath().value()});
     auto bootstrap =
         mojo::MakeProxy(mojo_connection_delegate_->InitializeMojoConnection());
     mojom::DriveFsDelegatePtr delegate;
@@ -365,6 +363,11 @@ const base::FilePath& DriveFsHost::GetMountPath() const {
   return mount_state_->mount_path();
 }
 
+base::FilePath DriveFsHost::GetDataPath() const {
+  return profile_path_.Append(kDataPath).Append(
+      delegate_->GetObfuscatedAccountId());
+}
+
 mojom::DriveFs* DriveFsHost::GetDriveFsInterface() const {
   if (!mount_state_ || !mount_state_->mounted()) {
     return nullptr;

chromeos/components/drivefs/drivefs_host.h

@@ -100,6 +100,9 @@ class COMPONENT_EXPORT(DRIVEFS) DriveFsHost
   // |IsMounted()| returns true.
   const base::FilePath& GetMountPath() const;
 
+  // Returns the path where DriveFS keeps its data and caches.
+  base::FilePath GetDataPath() const;
+
   mojom::DriveFs* GetDriveFsInterface() const;
 
  private:

chromeos/components/drivefs/drivefs_host_unittest.cc

@@ -372,6 +372,9 @@ class DriveFsHostTest : public ::testing::Test, public mojom::DriveFsBootstrap {
 TEST_F(DriveFsHostTest, Basic) {
   EXPECT_FALSE(host_->IsMounted());
 
+  EXPECT_EQ(base::FilePath("/path/to/profile/GCache/v2/salt-g-ID"),
+            host_->GetDataPath());
+
   ASSERT_NO_FATAL_FAILURE(DoMount());
 
   EXPECT_EQ(base::FilePath("/media/drivefsroot/salt-g-ID"),