DEV: Add instrumentation for uploads (#14397)

This commit allows for measuring the time taken for
individual uploads via the new uppy interfaces, only
if the enable_upload_debug_mode site setting is enabled.

Also in this PR, for upload errors with a specific message
locally, we return the real message to show in the modal
instead of the upload.failed message so the developer
does not have to dig around in logs.

app/assets/javascripts/discourse/app/mixins/composer-upload-uppy.js

@@ -131,6 +131,10 @@ export default Mixin.create(ExtendableUploader, {
       },
     });
 
+    if (this.siteSettings.enable_upload_debug_mode) {
+      this._instrumentUploadTimings();
+    }
+
     // hidden setting like enable_experimental_image_uploader
     if (this.siteSettings.enable_direct_s3_uploads) {
       this._useS3MultipartUploads();

app/assets/javascripts/discourse/app/mixins/extendable-uploader.js

@@ -1,4 +1,5 @@
 import Mixin from "@ember/object/mixin";
+import UploadDebugging from "discourse/mixins/upload-debugging";
 
 /**
  * Use this mixin with any component that needs to upload files or images
@@ -39,7 +40,7 @@ import Mixin from "@ember/object/mixin";
  *
  * See ComposerUploadUppy for an example of a component using this mixin.
  */
-export default Mixin.create({
+export default Mixin.create(UploadDebugging, {
   _useUploadPlugin(pluginClass, opts = {}) {
     if (!this._uppyInstance) {
       return;
@@ -172,11 +173,4 @@ export default Mixin.create({
       }
     }
   },
-
-  _consoleDebug(msg) {
-    if (this.siteSettings.enable_upload_debug_mode) {
-      // eslint-disable-next-line no-console
-      console.log(msg);
-    }
-  },
 });

app/assets/javascripts/discourse/app/mixins/upload-debugging.js

@@ -0,0 +1,86 @@
+import Mixin from "@ember/object/mixin";
+
+export default Mixin.create({
+  _consoleDebug(msg) {
+    if (this.siteSettings.enable_upload_debug_mode) {
+      // eslint-disable-next-line no-console
+      console.log(msg);
+    }
+  },
+
+  _consolePerformanceTiming(timing) {
+    const minutes = Math.floor(timing.duration / 60000);
+    const seconds = ((timing.duration % 60000) / 1000).toFixed(0);
+    const duration = minutes + ":" + (seconds < 10 ? "0" : "") + seconds;
+    this._consoleDebug(
+      `${timing.name}:\n duration: ${duration} (${timing.duration}ms)`
+    );
+  },
+
+  _instrumentUploadTimings() {
+    this._uppyInstance.on("upload", (data) => {
+      data.fileIDs.forEach((fileId) =>
+        performance.mark(`upload-${fileId}-start`)
+      );
+    });
+
+    this._uppyInstance.on("create-multipart", (fileId) => {
+      performance.mark(`upload-${fileId}-create-multipart`);
+    });
+
+    this._uppyInstance.on("create-multipart-success", (fileId) => {
+      performance.mark(`upload-${fileId}-create-multipart-success`);
+    });
+
+    this._uppyInstance.on("complete-multipart", (fileId) => {
+      performance.mark(`upload-${fileId}-complete-multipart`);
+
+      this._consolePerformanceTiming(
+        performance.measure(
+          `upload-${fileId}-multipart-all-parts-complete`,
+          `upload-${fileId}-create-multipart-success`,
+          `upload-${fileId}-complete-multipart`
+        )
+      );
+    });
+
+    this._uppyInstance.on("complete-multipart-success", (fileId) => {
+      performance.mark(`upload-${fileId}-complete-multipart-success`);
+
+      this._consolePerformanceTiming(
+        performance.measure(
+          `upload-${fileId}-multipart-total-network-exclusive-complete-multipart`,
+          `upload-${fileId}-create-multipart`,
+          `upload-${fileId}-complete-multipart`
+        )
+      );
+
+      this._consolePerformanceTiming(
+        performance.measure(
+          `upload-${fileId}-multipart-total-network-inclusive-complete-multipart`,
+          `upload-${fileId}-create-multipart`,
+          `upload-${fileId}-complete-multipart-success`
+        )
+      );
+
+      this._consolePerformanceTiming(
+        performance.measure(
+          `upload-${fileId}-multipart-complete-convert-to-upload`,
+          `upload-${fileId}-complete-multipart`,
+          `upload-${fileId}-complete-multipart-success`
+        )
+      );
+    });
+
+    this._uppyInstance.on("upload-success", (file) => {
+      performance.mark(`upload-${file.id}-end`);
+      this._consolePerformanceTiming(
+        performance.measure(
+          `upload-${file.id}-multipart-total-inclusive-preprocessing`,
+          `upload-${file.id}-start`,
+          `upload-${file.id}-end`
+        )
+      );
+    });
+  },
+});

app/controllers/uploads_controller.rb

@@ -264,21 +264,30 @@ class UploadsController < ApplicationController
           render_json_error(upload.errors.to_hash.values.flatten, status: 422)
         end
       rescue ExternalUploadManager::SizeMismatchError => err
-        debug_upload_error(err, "upload.size_mismatch_failure", additional_detail: err.message)
+        render_json_error(
-        render_json_error(I18n.t("upload.failed"), status: 422)
+          debug_upload_error(err, "upload.size_mismatch_failure", additional_detail: err.message),
+          status: 422
+        )
       rescue ExternalUploadManager::ChecksumMismatchError => err
-        debug_upload_error(err, "upload.checksum_mismatch_failure")
+        render_json_error(
-        render_json_error(I18n.t("upload.failed"), status: 422)
+          debug_upload_error(err, "upload.checksum_mismatch_failure", additional_detail: err.message),
+          status: 422
+        )
       rescue ExternalUploadManager::CannotPromoteError => err
-        debug_upload_error(err, "upload.cannot_promote_failure")
+        render_json_error(
-        render_json_error(I18n.t("upload.failed"), status: 422)
+          debug_upload_error(err, "upload.cannot_promote_failure", additional_detail: err.message),
+          status: 422
+        )
       rescue ExternalUploadManager::DownloadFailedError, Aws::S3::Errors::NotFound => err
-        debug_upload_error(err, "upload.download_failure")
+        render_json_error(
-        render_json_error(I18n.t("upload.failed"), status: 422)
+          debug_upload_error(err, "upload.download_failure", additional_detail: err.message),
+          status: 422
+        )
       rescue => err
         Discourse.warn_exception(
           err, message: "Complete external upload failed unexpectedly for user #{current_user.id}"
         )
+
         render_json_error(I18n.t("upload.failed"), status: 422)
       end
     end
@@ -308,8 +317,10 @@ class UploadsController < ApplicationController
         file_name, content_type, metadata: metadata
       )
     rescue Aws::S3::Errors::ServiceError => err
-      debug_upload_error(err, "upload.create_mutlipart_failure")
+      return render_json_error(
-      return render_json_error(I18n.t("upload.failed"), status: 422)
+        debug_upload_error(err, "upload.create_mutlipart_failure", additional_detail: err.message),
+        status: 422
+      )
     end
 
     upload_stub = ExternalUploadStub.create!(
@@ -403,8 +414,10 @@ class UploadsController < ApplicationController
         key: external_upload_stub.key
       )
     rescue Aws::S3::Errors::ServiceError => err
-      debug_upload_error(err, "upload.abort_mutlipart_failure", additional_detail: "external upload stub id: #{external_upload_stub.id}")
+      return render_json_error(
-      return render_json_error(I18n.t("upload.failed"), status: 422)
+        debug_upload_error(err, "upload.abort_mutlipart_failure", additional_detail: "external upload stub id: #{external_upload_stub.id}"),
+        status: 422
+      )
     end
 
     external_upload_stub.destroy!
@@ -452,8 +465,10 @@ class UploadsController < ApplicationController
         parts: parts
       )
     rescue Aws::S3::Errors::ServiceError => err
-      debug_upload_error(err, "upload.complete_mutlipart_failure", additional_detail: "external upload stub id: #{external_upload_stub.id}")
+      return render_json_error(
-      return render_json_error(I18n.t("upload.failed"), status: 422)
+        debug_upload_error(err, "upload.complete_mutlipart_failure", additional_detail: "external upload stub id: #{external_upload_stub.id}"),
+        status: 422
+      )
     end
 
     complete_external_upload_via_manager(external_upload_stub)
@@ -567,7 +582,9 @@ class UploadsController < ApplicationController
 
   def debug_upload_error(err, translation_key, translation_params = {})
     return if !SiteSetting.enable_upload_debug_mode
-    Discourse.warn_exception(err, message: I18n.t(translation_key, translation_params))
+    message = I18n.t(translation_key, translation_params)
+    Discourse.warn_exception(err, message: message)
+    Rails.env.development? ? message : I18n.t("upload.failed")
   end
 
   # don't want people posting arbitrary S3 metadata so we just take the