Introduce LoggedUIThreadExtensionFunction to help migrate to UIThreadExtensionFunction.

Some fileManagerPrivate APIs use a subclass of
ChromeAsyncExtensionFunction to time and log long-running API calls. To
help migrate off ChromeAsyncExtensionFunction, create another subclass
that inherits from UIThreadExtensionFunction directly.

BUG=934541

Change-Id: I1e715ca6a063ac186f73d45ce1eaa1fbf9825263
Reviewed-on: https://chromium-review.googlesource.com/c/1481131
Commit-Queue: Anand Mistry <amistry@chromium.org>
Reviewed-by: Sam McNally <sammc@chromium.org>
Cr-Commit-Position: refs/heads/master@{#634447}

chrome/browser/chromeos/extensions/file_manager/private_api_base.cc

@@ -8,6 +8,7 @@
 
 #include "base/strings/string_number_conversions.h"
 #include "chrome/browser/chromeos/extensions/file_manager/private_api_util.h"
+#include "chrome/browser/extensions/chrome_extension_function_details.h"
 #include "components/drive/event_logger.h"
 
 namespace extensions {
@@ -43,4 +44,32 @@ void LoggedAsyncExtensionFunction::OnResponded() {
   ChromeAsyncExtensionFunction::OnResponded();
 }
 
+LoggedUIThreadExtensionFunction::LoggedUIThreadExtensionFunction()
+    : log_on_completion_(false) {
+  start_time_ = base::Time::Now();
+}
+
+LoggedUIThreadExtensionFunction::~LoggedUIThreadExtensionFunction() = default;
+
+void LoggedUIThreadExtensionFunction::OnResponded() {
+  const ChromeExtensionFunctionDetails chrome_details(this);
+  drive::EventLogger* logger =
+      file_manager::util::GetLogger(chrome_details.GetProfile());
+  if (logger) {
+    int64_t elapsed = (base::Time::Now() - start_time_).InMilliseconds();
+    DCHECK(response_type());
+    bool success = *response_type() == SUCCEEDED;
+    if (log_on_completion_) {
+      logger->Log(logging::LOG_INFO, "%s[%d] %s. (elapsed time: %sms)", name(),
+                  request_id(), success ? "succeeded" : "failed",
+                  base::NumberToString(elapsed).c_str());
+    } else if (elapsed >= kSlowOperationThresholdMs) {
+      logger->Log(logging::LOG_WARNING,
+                  "PEFORMANCE WARNING: %s[%d] was slow. (elapsed time: %sms)",
+                  name(), request_id(), base::NumberToString(elapsed).c_str());
+    }
+  }
+  UIThreadExtensionFunction::OnResponded();
+}
+
 }  // namespace extensions

chrome/browser/chromeos/extensions/file_manager/private_api_base.h

@@ -9,6 +9,7 @@
 
 #include "base/time/time.h"
 #include "chrome/browser/extensions/chrome_extension_function.h"
+#include "extensions/browser/extension_function.h"
 
 namespace extensions {
 
@@ -20,6 +21,8 @@ namespace extensions {
 // set_log_on_completion(true) to enable it, if they want. However, even if
 // the logging is turned off, a warning is emitted when a function call is
 // very slow. See the implementation of OnResponded() for details.
+// TODO(crbug.com/934541): Remove this once all extension functions have been
+// migrated to LoggedUIThreadExtensionFunction.
 class LoggedAsyncExtensionFunction : public ChromeAsyncExtensionFunction {
  public:
   LoggedAsyncExtensionFunction();
@@ -40,6 +43,28 @@ class LoggedAsyncExtensionFunction : public ChromeAsyncExtensionFunction {
   bool log_on_completion_;
 };
 
+// This is the same class as above, but inheriting directly from
+// UIThreadExtensionFunction instead.
+class LoggedUIThreadExtensionFunction : public UIThreadExtensionFunction {
+ public:
+  LoggedUIThreadExtensionFunction();
+
+ protected:
+  ~LoggedUIThreadExtensionFunction() override;
+
+  // UIThreadExtensionFunction overrides.
+  void OnResponded() override;
+
+  // Sets the logging on completion flag. By default, logging is turned off.
+  void set_log_on_completion(bool log_on_completion) {
+    log_on_completion_ = log_on_completion;
+  }
+
+ private:
+  base::Time start_time_;
+  bool log_on_completion_;
+};
+
 }  // namespace extensions
 
 #endif  // CHROME_BROWSER_CHROMEOS_EXTENSIONS_FILE_MANAGER_PRIVATE_API_BASE_H_

chrome/browser/chromeos/extensions/file_manager/private_api_tasks.cc

@@ -67,7 +67,12 @@ std::set<std::string> GetUniqueMimeTypes(
 
 }  // namespace
 
-bool FileManagerPrivateInternalExecuteTaskFunction::RunAsync() {
+FileManagerPrivateInternalExecuteTaskFunction::
+    FileManagerPrivateInternalExecuteTaskFunction()
+    : chrome_details_(this) {}
+
+ExtensionFunction::ResponseAction
+FileManagerPrivateInternalExecuteTaskFunction::Run() {
   using extensions::api::file_manager_private_internal::ExecuteTask::Params;
   using extensions::api::file_manager_private_internal::ExecuteTask::Results::
       Create;
@@ -76,73 +81,76 @@ bool FileManagerPrivateInternalExecuteTaskFunction::RunAsync() {
 
   file_manager::file_tasks::TaskDescriptor task;
   if (!file_manager::file_tasks::ParseTaskID(params->task_id, &task)) {
-    SetError(kInvalidTask + params->task_id);
-    SetResultList(
-        Create(extensions::api::file_manager_private::TASK_RESULT_FAILED));
-    return false;
+    // TODO(crbug.com/514135): Stop relying on the result being set on error.
+    return RespondNow(ErrorWithArguments(
+        Create(extensions::api::file_manager_private::TASK_RESULT_FAILED),
+        kInvalidTask + params->task_id));
   }
 
   if (params->urls.empty()) {
-    SetResultList(
-        Create(extensions::api::file_manager_private::TASK_RESULT_EMPTY));
-    SendResponse(true);
-    return true;
+    return RespondNow(ArgumentList(
+        Create(extensions::api::file_manager_private::TASK_RESULT_EMPTY)));
   }
 
   const scoped_refptr<storage::FileSystemContext> file_system_context =
       file_manager::util::GetFileSystemContextForRenderFrameHost(
-          GetProfile(), render_frame_host());
+          chrome_details_.GetProfile(), render_frame_host());
 
   std::vector<FileSystemURL> urls;
   for (size_t i = 0; i < params->urls.size(); i++) {
     const FileSystemURL url =
         file_system_context->CrackURL(GURL(params->urls[i]));
     if (!chromeos::FileSystemBackend::CanHandleURL(url)) {
-      SetError(kInvalidFileUrl);
-      SetResultList(
-          Create(extensions::api::file_manager_private::TASK_RESULT_FAILED));
-      return false;
+      return RespondNow(ErrorWithArguments(
+          Create(extensions::api::file_manager_private::TASK_RESULT_FAILED),
+          kInvalidFileUrl));
     }
     urls.push_back(url);
   }
 
   const bool result = file_manager::file_tasks::ExecuteFileTask(
-      GetProfile(), source_url(), task, urls,
+      chrome_details_.GetProfile(), source_url(), task, urls,
       base::BindOnce(
           &FileManagerPrivateInternalExecuteTaskFunction::OnTaskExecuted,
           this));
   if (!result) {
-    SetResultList(
-        Create(extensions::api::file_manager_private::TASK_RESULT_FAILED));
+    return RespondNow(ErrorWithArguments(
+        Create(extensions::api::file_manager_private::TASK_RESULT_FAILED),
+        "ExecuteFileTask failed"));
   }
-  return result;
+  return RespondLater();
 }
 
 void FileManagerPrivateInternalExecuteTaskFunction::OnTaskExecuted(
     extensions::api::file_manager_private::TaskResult result) {
-  SetResultList(extensions::api::file_manager_private_internal::ExecuteTask::
-                    Results::Create(result));
-  SendResponse(result !=
-               extensions::api::file_manager_private::TASK_RESULT_FAILED);
+  auto result_list = extensions::api::file_manager_private_internal::
+      ExecuteTask::Results::Create(result);
+  if (result == extensions::api::file_manager_private::TASK_RESULT_FAILED) {
+    Respond(ErrorWithArguments(std::move(result_list), "Task result failed"));
+  } else {
+    Respond(ArgumentList(std::move(result_list)));
+  }
 }
 
 FileManagerPrivateInternalGetFileTasksFunction::
-    FileManagerPrivateInternalGetFileTasksFunction() = default;
+    FileManagerPrivateInternalGetFileTasksFunction()
+    : chrome_details_(this) {}
 
 FileManagerPrivateInternalGetFileTasksFunction::
     ~FileManagerPrivateInternalGetFileTasksFunction() = default;
 
-bool FileManagerPrivateInternalGetFileTasksFunction::RunAsync() {
+ExtensionFunction::ResponseAction
+FileManagerPrivateInternalGetFileTasksFunction::Run() {
   using extensions::api::file_manager_private_internal::GetFileTasks::Params;
   const std::unique_ptr<Params> params(Params::Create(*args_));
   EXTENSION_FUNCTION_VALIDATE(params);
 
   if (params->urls.empty())
-    return false;
+    return RespondNow(Error("No URLs provided"));
 
   const scoped_refptr<storage::FileSystemContext> file_system_context =
       file_manager::util::GetFileSystemContextForRenderFrameHost(
-          GetProfile(), render_frame_host());
+          chrome_details_.GetProfile(), render_frame_host());
 
   // Collect all the URLs, convert them to GURLs, and crack all the urls into
   // file paths.
@@ -156,21 +164,22 @@ bool FileManagerPrivateInternalGetFileTasksFunction::RunAsync() {
   }
 
   mime_type_collector_ =
-      std::make_unique<app_file_handler_util::MimeTypeCollector>(GetProfile());
+      std::make_unique<app_file_handler_util::MimeTypeCollector>(
+          chrome_details_.GetProfile());
   mime_type_collector_->CollectForLocalPaths(
       local_paths_,
       base::Bind(
           &FileManagerPrivateInternalGetFileTasksFunction::OnMimeTypesCollected,
           this));
 
-  return true;
+  return RespondLater();
 }
 
 void FileManagerPrivateInternalGetFileTasksFunction::OnMimeTypesCollected(
     std::unique_ptr<std::vector<std::string>> mime_types) {
   is_directory_collector_ =
       std::make_unique<app_file_handler_util::IsDirectoryCollector>(
-          GetProfile());
+          chrome_details_.GetProfile());
   is_directory_collector_->CollectForEntriesPaths(
       local_paths_, base::Bind(&FileManagerPrivateInternalGetFileTasksFunction::
                                    OnAreDirectoriesAndMimeTypesCollected,
@@ -189,7 +198,7 @@ void FileManagerPrivateInternalGetFileTasksFunction::
   }
 
   file_manager::file_tasks::FindAllTypesOfTasks(
-      GetProfile(), entries, urls_,
+      chrome_details_.GetProfile(), entries, urls_,
       base::BindOnce(
           &FileManagerPrivateInternalGetFileTasksFunction::OnFileTasksListed,
           this));
@@ -214,9 +223,8 @@ void FileManagerPrivateInternalGetFileTasksFunction::OnFileTasksListed(
     results.push_back(std::move(converted));
   }
 
-  SetResultList(extensions::api::file_manager_private_internal::GetFileTasks::
-                    Results::Create(results));
-  SendResponse(true);
+  Respond(ArgumentList(extensions::api::file_manager_private_internal::
+                           GetFileTasks::Results::Create(results)));
 }
 
 ExtensionFunction::ResponseAction

chrome/browser/chromeos/extensions/file_manager/private_api_tasks.h

@@ -28,25 +28,29 @@ class MimeTypeCollector;
 
 // Implements the chrome.fileManagerPrivateInternal.executeTask method.
 class FileManagerPrivateInternalExecuteTaskFunction
-    : public LoggedAsyncExtensionFunction {
+    : public LoggedUIThreadExtensionFunction {
  public:
+  FileManagerPrivateInternalExecuteTaskFunction();
+
   DECLARE_EXTENSION_FUNCTION("fileManagerPrivateInternal.executeTask",
                              FILEMANAGERPRIVATEINTERNAL_EXECUTETASK)
 
  protected:
   ~FileManagerPrivateInternalExecuteTaskFunction() override = default;
 
-  // ChromeAsyncExtensionFunction overrides.
-  bool RunAsync() override;
+  // UIThreadExtensionFunction overrides.
+  ResponseAction Run() override;
 
  private:
   void OnTaskExecuted(
       extensions::api::file_manager_private::TaskResult success);
+
+  const ChromeExtensionFunctionDetails chrome_details_;
 };
 
 // Implements the chrome.fileManagerPrivateInternal.getFileTasks method.
 class FileManagerPrivateInternalGetFileTasksFunction
-    : public LoggedAsyncExtensionFunction {
+    : public LoggedUIThreadExtensionFunction {
  public:
   FileManagerPrivateInternalGetFileTasksFunction();
 
@@ -56,8 +60,8 @@ class FileManagerPrivateInternalGetFileTasksFunction
  protected:
   ~FileManagerPrivateInternalGetFileTasksFunction() override;
 
-  // ChromeAsyncExtensionFunction overrides.
-  bool RunAsync() override;
+  // UIThreadExtensionFunction overrides.
+  ResponseAction Run() override;
 
  private:
   void OnMimeTypesCollected(
@@ -77,6 +81,7 @@ class FileManagerPrivateInternalGetFileTasksFunction
       mime_type_collector_;
   std::vector<GURL> urls_;
   std::vector<base::FilePath> local_paths_;
+  const ChromeExtensionFunctionDetails chrome_details_;
 };
 
 // Implements the chrome.fileManagerPrivateInternal.setDefaultTask method.