Track unknown errors (dependabot#7534)

* Refactored error handling and metrics in Dependabot to improve debugging and reporting. This includes enhancing the "unknown_error" metric with package manager tags, passing detailed error information to "record_unknown_error," and updating tests and lint issues for better code quality.

---------

Co-authored-by: Ankit Honey <honeyankit@github.com>

common/lib/dependabot/shared_helpers.rb

@@ -64,7 +64,7 @@ class HelperSubprocessFailed < Dependabot::DependabotError
 
       def initialize(message:, error_context:, error_class: nil, trace: nil)
         super(message)
-        @error_class = error_class || ""
+        @error_class = error_class || "HelperSubprocessFailed"
         @error_context = error_context
         @fingerprint = error_context[:fingerprint] || error_context[:command]
         @trace = trace
@@ -82,6 +82,7 @@ def self.escape_command(command)
     end
 
     # rubocop:disable Metrics/MethodLength
+    # rubocop:disable Metrics/AbcSize
     def self.run_helper_subprocess(command:, function:, args:, env: nil,
                                    stderr_to_stdout: false,
                                    allow_unsafe_shell_command: false)
@@ -130,19 +131,20 @@ def self.run_helper_subprocess(command:, function:, args:, env: nil,
       return response["result"] if process.success?
 
       raise HelperSubprocessFailed.new(
-        message: response["error"],
+        message: "#{response['error']} failed with command (#{error_context[:command]})",
         error_class: response["error_class"],
         error_context: error_context,
         trace: response["trace"]
       )
     rescue JSON::ParserError
       raise HelperSubprocessFailed.new(
-        message: stdout || "No output from command",
+        message: stdout.empty? ? "No output from command (#{error_context[:command]})" : stdout,
         error_class: "JSON::ParserError",
         error_context: error_context
       )
     end
     # rubocop:enable Metrics/MethodLength
+    # rubocop:enable Metrics/AbcSize
 
     def self.check_out_of_memory_error(stderr, error_context)
       return unless stderr&.include?("JavaScript heap out of memory")

common/spec/dependabot/shared_helpers_spec.rb

@@ -187,7 +187,7 @@ def existing_tmp_folders
       it "raises a HelperSubprocessFailed error" do
         expect { run_subprocess }
           .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error|
-            expect(error.message).to eq("Something went wrong: https://www.example.com")
+            expect(error.message).to include("Something went wrong: https://www.example.com")
           end
       end
     end

composer/spec/dependabot/composer/update_checker/version_resolver_spec.rb

@@ -161,7 +161,7 @@
       it "raises a Dependabot::PrivateSourceTimedOut error" do
         expect { resolver.latest_resolvable_version }
           .to raise_error(Dependabot::DependencyFileNotResolvable) do |error|
-            expect(error.message).to start_with(
+            expect(error.message).to include(
               'The "https://github.com/dependabot/composer-not-found/packages.json"' \
               " file could not be downloaded"
             )

python/spec/dependabot/python/file_parser/setup_file_parser_spec.rb

@@ -257,7 +257,7 @@
               expect(error.class)
                 .to eq(Dependabot::DependencyFileNotEvaluatable)
               expect(error.message)
-                .to eq("InstallationError(\"Invalid requirement: 'psycopg2==2.6.1raven == 5.32.0'\")")
+                .to include("InstallationError(\"Invalid requirement: 'psycopg2==2.6.1raven == 5.32.0'\")")
             end
         end
       end

updater/lib/dependabot/api_client.rb

@@ -89,6 +89,24 @@ def record_update_job_error(error_type:, error_details:)
       sleep(rand(3.0..10.0)) && retry
     end
 
+    def record_update_job_unknown_error(error_type: "unknown_error", error_details:)
+      api_url = "#{base_url}/update_jobs/#{job_id}/record_update_job_unknown_error"
+      body = {
+        data: {
+          "error-type": error_type,
+          "error-details": error_details
+        }
+      }
+      response = http_client.post(api_url, json: body)
+      raise ApiError, response.body if response.code >= 400
+    rescue HTTP::ConnectionError, OpenSSL::SSL::SSLError
+      retry_count ||= 0
+      retry_count += 1
+      raise if retry_count > 3
+
+      sleep(rand(3.0..10.0)) && retry
+    end
+
     def mark_job_as_processed(base_commit_sha)
       api_url = "#{base_url}/update_jobs/#{job_id}/mark_as_processed"
       body = { data: { "base-commit-sha": base_commit_sha } }

updater/lib/dependabot/base_command.rb

@@ -64,9 +64,22 @@ def run
     def handle_exception(err)
       Dependabot.logger.error(err.message)
       err.backtrace.each { |line| Dependabot.logger.error(line) }
+      error_details = {
+        "error-class" => err.class.to_s,
+        "error-message" => err.message,
+        "error-backtrace" => err.backtrace.join("\n"),
+        "package-manager" => job.package_manager,
+        "job-id" => job.id,
+        "job-dependencies" => job.dependencies,
+        "job-dependency_group" => job.dependency_groups
+      }.compact
 
       service.capture_exception(error: err, job: job)
-      service.record_update_job_error(error_type: "unknown_error", error_details: { message: err.message })
+      service.record_update_job_unknown_error(error_type: "updater_error", error_details: error_details)
+      service.increment_metric("updater.update_job_unknown_error", tags: {
+        package_manager: job.package_manager,
+        class_name: err.class.name
+      })
     end
 
     def job_id

updater/lib/dependabot/file_fetcher_command.rb

@@ -161,7 +161,7 @@ def handle_file_fetcher_error(error)
           # If we get a 500 from GitHub there's very little we can do about it,
           # and responsibility for fixing it is on them, not us. As a result we
           # quietly log these as errors
-          { "error-type": "unknown_error" }
+          { "error-type": "server_error" }
         when *Octokit::RATE_LIMITED_ERRORS
           # If we get a rate-limited error we let dependabot-api handle the
           # retry by re-enqueing the update job after the reset
@@ -174,9 +174,21 @@ def handle_file_fetcher_error(error)
         else
           Dependabot.logger.error(error.message)
           error.backtrace.each { |line| Dependabot.logger.error line }
+          unknown_error_details = {
+            "error-class" => error.class.to_s,
+            "error-message" => error.message,
+            "error-backtrace" => error.backtrace.join("\n"),
+            "package-manager" => job.package_manager,
+            "job-id" => job.id,
+            "job-dependencies" => job.dependencies,
+            "job-dependency_group" => job.dependency_groups
+          }.compact
 
           service.capture_exception(error: error, job: job)
-          { "error-type": "unknown_error" }
+          {
+            "error-type": "file_fetcher_error",
+            "error-detail": unknown_error_details
+          }
         end
 
       record_error(error_details) if error_details
@@ -191,10 +203,17 @@ def rate_limit_error_remaining(error)
     end
 
     def record_error(error_details)
-      service.record_update_job_error(
-        error_type: error_details.fetch(:"error-type"),
-        error_details: error_details[:"error-detail"]
-      )
+      if error_details[:"error-type"] == "file_fetcher_error"
+        service.record_update_job_unknown_error(
+          error_type: error_details.fetch(:"error-type"),
+          error_details: error_details[:"error-detail"]
+        )
+      else
+        service.record_update_job_error(
+          error_type: error_details.fetch(:"error-type"),
+          error_details: error_details[:"error-detail"]
+        )
+      end
     end
 
     # Perform a debug check of connectivity to GitHub/GHES. This also ensures

updater/lib/dependabot/service.rb

@@ -49,6 +49,11 @@ def record_update_job_error(error_type:, error_details:, dependency: nil)
       client.record_update_job_error(error_type: error_type, error_details: error_details)
     end
 
+    def record_update_job_unknown_error(error_type:, error_details:, dependency: nil)
+      @errors << [error_type.to_s, dependency]
+      client.record_update_job_unknown_error(error_type: error_type, error_details: error_details)
+    end
+
     def update_dependency_list(dependency_snapshot:)
       dependency_payload = dependency_snapshot.dependencies.map do |dep|
         {

updater/lib/dependabot/update_files_command.rb

@@ -59,6 +59,7 @@ def base_commit_sha
     end
 
     # rubocop:disable Metrics/MethodLength
+    # rubocop:disable Metrics/AbcSize
     def handle_parser_error(error)
       # This happens if the repo gets removed after a job gets kicked off.
       # The service will handle the removal without any prompt from the updater,
@@ -121,7 +122,7 @@ def handle_parser_error(error)
           # If we get a 500 from GitHub there's very little we can do about it,
           # and responsibility for fixing it is on them, not us. As a result we
           # quietly log these as errors
-          { "error-type": "unknown_error" }
+          { "error-type": "server_error" }
         else
           # Check if the error is a known "run halting" state we should handle
           if (error_type = Updater::ErrorHandler::RUN_HALTING_ERRORS[error.class])
@@ -131,19 +132,39 @@ def handle_parser_error(error)
             # tracker know about it
             Dependabot.logger.error error.message
             error.backtrace.each { |line| Dependabot.logger.error line }
+            unknown_error_details = {
+              "error-class" => error.class.to_s,
+              "error-message" => error.message,
+              "error-backtrace" => error.backtrace.join("\n"),
+              "package-manager" => job.package_manager,
+              "job-id" => job.id,
+              "job-dependencies" => job.dependencies,
+              "job-dependency_group" => job.dependency_groups
+            }.compact
 
             service.capture_exception(error: error, job: job)
 
-            # Set an unknown error type to be added to the job
-            { "error-type": "unknown_error" }
+            # Set an unknown error type as update_files_error to be added to the job
+            {
+              "error-type": "update_files_error",
+              "error-detail": unknown_error_details
+            }
           end
         end
 
-      service.record_update_job_error(
-        error_type: error_details.fetch(:"error-type"),
-        error_details: error_details[:"error-detail"]
-      )
+      if error_details.fetch(:"error-type") == "update_files_error"
+        service.record_update_job_unknown_error(
+          error_type: "update_files_error",
+          error_details: error_details[:"error-detail"]
+        )
+      else
+        service.record_update_job_error(
+          error_type: error_details.fetch(:"error-type"),
+          error_details: error_details[:"error-detail"]
+        )
+      end
     end
     # rubocop:enable Metrics/MethodLength
+    # rubocop:enable Metrics/AbcSize
   end
 end

updater/lib/dependabot/updater/error_handler.rb

@@ -44,11 +44,15 @@ def handle_dependency_error(error:, dependency:, dependency_group: nil)
         raise error if RUN_HALTING_ERRORS.keys.any? { |err| error.is_a?(err) }
 
         error_details = error_details_for(error, dependency: dependency, dependency_group: dependency_group)
-        service.record_update_job_error(
-          error_type: error_details.fetch(:"error-type"),
-          error_details: error_details[:"error-detail"],
-          dependency: dependency
-        )
+        if error_details.fetch(:"error-type") == "unknown_error"
+          log_unknown_error_with_backtrace(error, dependency)
+        else
+          service.record_update_job_error(
+            error_type: error_details.fetch(:"error-type"),
+            error_details: error_details[:"error-detail"],
+            dependency: dependency
+          )
+        end
 
         log_dependency_error(
           dependency: dependency,
@@ -62,7 +66,6 @@ def handle_dependency_error(error:, dependency:, dependency_group: nil)
       def log_dependency_error(dependency:, error:, error_type:, error_detail: nil)
         if error_type == "unknown_error"
           Dependabot.logger.error "Error processing #{dependency.name} (#{error.class.name})"
-          log_unknown_error_with_backtrace(error)
         else
           Dependabot.logger.info(
             "Handled error whilst updating #{dependency.name}: #{error_type} #{error_detail}"
@@ -78,10 +81,15 @@ def handle_job_error(error:, dependency_group: nil)
         raise error if RUN_HALTING_ERRORS.keys.any? { |err| error.is_a?(err) }
 
         error_details = error_details_for(error, dependency_group: dependency_group)
-        service.record_update_job_error(
-          error_type: error_details.fetch(:"error-type"),
-          error_details: error_details[:"error-detail"]
-        )
+        if error_details.fetch(:"error-type") == "unknown_error"
+          log_unknown_error_with_backtrace(error, dependency_group)
+        else
+          service.record_update_job_error(
+            error_type: error_details.fetch(:"error-type"),
+            error_details: error_details[:"error-detail"]
+          )
+        end
+
         log_job_error(
           error: error,
           error_type: error_details.fetch(:"error-type"),
@@ -93,7 +101,6 @@ def handle_job_error(error:, dependency_group: nil)
       def log_job_error(error:, error_type:, error_detail: nil)
         if error_type == "unknown_error"
           Dependabot.logger.error "Error processing job (#{error.class.name})"
-          log_unknown_error_with_backtrace(error)
         else
           Dependabot.logger.info(
             "Handled error whilst processing job: #{error_type} #{error_detail}"
@@ -202,9 +209,26 @@ def error_details_for(error, dependency: nil, dependency_group: nil) # rubocop:d
         end
       end
 
-      def log_unknown_error_with_backtrace(error)
+      def log_unknown_error_with_backtrace(error, dependency = nil, _dependency_group = nil)
         Dependabot.logger.error error.message
         error.backtrace.each { |line| Dependabot.logger.error line }
+
+        error_details = {
+          "error-class" => error.class.to_s,
+          "error-message" => error.message,
+          "error-backtrace" => error.backtrace.join("\n"),
+          "package-manager" => job.package_manager,
+          "job-id" => job.id,
+          "job-dependencies" => job.dependencies,
+          "job-dependency_group" => job.dependency_groups
+        }.compact
+
+        service.increment_metric("updater.update_job_unknown_error", tags: {
+          package_manager: job.package_manager,
+          class_name: error.class.name
+        })
+        service.record_update_job_unknown_error(error_type: "unknown_error", error_details: error_details,
+                                                dependency: dependency)
       end
     end
   end

updater/spec/dependabot/api_client_spec.rb

@@ -349,6 +349,24 @@
     end
   end
 
+  describe "record_update_job_unknown_error" do
+    let(:url) { "http://example.com/update_jobs/1/record_update_job_unknown_error" }
+    let(:error_type) { "server_error" }
+    let(:error_detail) { { "message" => "My message" } }
+    before { stub_request(:post, url).to_return(status: 204) }
+
+    it "hits the correct endpoint" do
+      client.record_update_job_unknown_error(
+        error_type: error_type,
+        error_details: error_detail
+      )
+
+      expect(WebMock)
+        .to have_requested(:post, url)
+        .with(headers: { "Authorization" => "token" })
+    end
+  end
+
   describe "mark_job_as_processed" do
     let(:url) { "http://example.com/update_jobs/1/mark_as_processed" }
     let(:base_commit) { "sha" }

updater/spec/dependabot/file_fetcher_command_spec.rb

@@ -98,6 +98,31 @@
       end
     end
 
+    context "when the fetcher raises a file fetcher error", vcr: true do
+      before do
+        allow_any_instance_of(Dependabot::Bundler::FileFetcher)
+          .to receive(:commit)
+          .and_raise(StandardError, "my_branch")
+      end
+
+      it "tells the backend about the error (and doesn't re-raise it)" do
+        expect(api_client).to receive(:record_update_job_unknown_error).with(
+          error_type: "file_fetcher_error",
+          error_details: {
+            "error-backtrace" => an_instance_of(String),
+            "error-message" => "my_branch",
+            "error-class" => "StandardError",
+            "package-manager" => "bundler",
+            "job-id" => "123123",
+            "job-dependency_group" => []
+          }
+        )
+        expect(api_client).to receive(:mark_job_as_processed)
+
+        expect { perform_job }.to output(/Error during file fetching; aborting/).to_stdout_from_any_process
+      end
+    end
+
     context "when the fetcher raises a rate limited error", vcr: true do
       let(:reset_at) { Time.now + 30 }