Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Track unknown errors #7534

Merged
merged 22 commits into from
Sep 21, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
8afba2d
Increase unknown_error metric with package manger tag
Nishnha Jul 7, 2023
a554758
Print failing subprocess commands
Nishnha Jul 7, 2023
833b6b9
Increment unknown_error metric on subprocess failed
Nishnha Jul 7, 2023
ef33ebc
Octokit 500 is a server_error not unknown_error
Nishnha Jul 7, 2023
c951225
Pass details to record_unknown_error
Nishnha Jul 7, 2023
e8fd556
Fix failing tests and lint
Nishnha Aug 4, 2023
38b68af
Include error type
Nishnha Aug 23, 2023
f9889b7
Check added in Dependabot-api
honeyankit Sep 11, 2023
b5a46c9
added more error information to error_details
honeyankit Sep 14, 2023
1f8eb0c
Change default error_type from unknown to unknown_error
honeyankit Sep 14, 2023
d062ad2
Fix test for update_files_command
honeyankit Sep 14, 2023
7f898eb
added job id, dependencies and dependency_groups in the error_details
honeyankit Sep 14, 2023
aac7bab
fixed test cases errors in error_handler
honeyankit Sep 14, 2023
2dc1f96
fixed updater spec conflicts
honeyankit Sep 14, 2023
91bb35b
kept error_details consistant
honeyankit Sep 14, 2023
e6a6dff
fixed lint issues and refactor code in update_files_command
honeyankit Sep 14, 2023
7f7a142
fixed integration test
honeyankit Sep 15, 2023
597a8e7
refactor call to record_update_job_unknown_error in file fetcher
honeyankit Sep 15, 2023
f3a79ee
new test for unknown error in file fetcher
honeyankit Sep 15, 2023
3cd8c38
Fixed failing test by shared helper
honeyankit Sep 15, 2023
db7ff1f
fixed more errors in SharedHelpers
honeyankit Sep 15, 2023
91a24fe
fixed test in setup_file_parser_spec.rb
honeyankit Sep 15, 2023
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 5 additions & 3 deletions common/lib/dependabot/shared_helpers.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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)
Expand Down Expand Up @@ -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]})",
honeyankit marked this conversation as resolved.
Show resolved Hide resolved
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")
Expand Down
2 changes: 1 addition & 1 deletion common/spec/dependabot/shared_helpers_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
18 changes: 18 additions & 0 deletions updater/lib/dependabot/api_client.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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 } }
Expand Down
15 changes: 14 additions & 1 deletion updater/lib/dependabot/base_command.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
31 changes: 25 additions & 6 deletions updater/lib/dependabot/file_fetcher_command.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand All @@ -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
Expand Down
5 changes: 5 additions & 0 deletions updater/lib/dependabot/service.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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|
{
Expand Down
35 changes: 28 additions & 7 deletions updater/lib/dependabot/update_files_command.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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])
Expand All @@ -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
48 changes: 36 additions & 12 deletions updater/lib/dependabot/updater/error_handler.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -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}"
Expand All @@ -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"),
Expand All @@ -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}"
Expand Down Expand Up @@ -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
Expand Down
18 changes: 18 additions & 0 deletions updater/spec/dependabot/api_client_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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" }
Expand Down
25 changes: 25 additions & 0 deletions updater/spec/dependabot/file_fetcher_command_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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 }

Expand Down
Loading
Loading