Skip to content

Commit

Permalink
Add error context when helper subprocesses fail
Browse files Browse the repository at this point in the history
Switch from `IO.popen` to `Open3.popen3` to get separate stdout and
stderr, adding stderr to Sentry error context.

Adding error context to debug these Sentries with no useful information:
https://sentry.io/dependabot/backend/issues/831291825/events/41548068139/
  • Loading branch information
feelepxyz committed Jan 11, 2019
1 parent 5ccff64 commit b7db071
Show file tree
Hide file tree
Showing 5 changed files with 70 additions and 27 deletions.
3 changes: 3 additions & 0 deletions helpers/test/run.rb
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,9 @@
when "error"
$stdout.write(JSON.dump(error: "Something went wrong"))
exit 1
when "useful_error"
$stderr.write("Some useful error")
exit 1
when "hard_error"
puts "Oh no!"
exit 0
Expand Down
2 changes: 1 addition & 1 deletion hex/lib/dependabot/hex/file_parser.rb
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,7 @@ def dependency_details
command: "mix run #{elixir_helper_path}",
function: "parse",
args: [Dir.pwd],
popen_opts: { err: %i(child out) }
stderr_to_stdout: true
)
end
rescue Dependabot::SharedHelpers::HelperSubprocessFailed => error
Expand Down
2 changes: 1 addition & 1 deletion hex/lib/dependabot/hex/update_checker/version_resolver.rb
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ def run_elixir_update_checker
args: [Dir.pwd,
dependency.name,
organization_credentials],
popen_opts: { err: %i(child out) }
stderr_to_stdout: true
)
end

Expand Down
71 changes: 47 additions & 24 deletions lib/dependabot/shared_helpers.rb
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
require "excon"
require "English"
require "digest"
require "open3"

module Dependabot
module SharedHelpers
Expand Down Expand Up @@ -62,34 +63,51 @@ def self.in_a_forked_process
end

class HelperSubprocessFailed < StandardError
def initialize(message, command)
def initialize(message:, error_context:)
super(message)
@command = command
@error_context = error_context
@command = error_context[:command]
end

def raven_context
{ fingerprint: [@command] }
{ fingerprint: [@command], extra: @error_context }
end
end

def self.run_helper_subprocess(command:, function:, args:, env: nil,
popen_opts: {})
raw_response = nil
popen_args = [env, command, "w+"].compact
IO.popen(*popen_args, popen_opts) do |process|
process.write(JSON.dump(function: function, args: args))
process.close_write
raw_response = process.read
end
stderr_to_stdout: false)
start = Time.now
stdin_data = JSON.dump(function: function, args: args)
env_cmd = [env, command].compact
stdout, stderr, process = Open3.capture3(*env_cmd, stdin_data: stdin_data)
time_taken = Time.now - start

# Some package managers output useful stuff to stderr instead of stdout so
# we want to parse this, most package manager will output garbage here so
# would mess up json response from stdout
stdout = "#{stderr}\n#{stdout}" if stderr_to_stdout

error_context = {
command: command,
function: function,
args: args,
time_taken: time_taken,
stderr_output: stderr ? stderr[0..50_000] : "", # Truncate to ~100kb
process_exit_value: process.to_s
}

response = JSON.parse(raw_response)
return response["result"] if $CHILD_STATUS.success?
response = JSON.parse(stdout)
return response["result"] if process.success?

raise HelperSubprocessFailed.new(response["error"], command)
raise HelperSubprocessFailed.new(
message: response["error"],
error_context: error_context
)
rescue JSON::ParserError
raise HelperSubprocessFailed.new(raw_response, command) if raw_response

raise HelperSubprocessFailed.new("No output from command", command)
raise HelperSubprocessFailed.new(
message: stdout || "No output from command",
error_context: error_context
)
end

def self.excon_middleware
Expand Down Expand Up @@ -183,18 +201,23 @@ def self.reset_global_git_config(backup_path)
end

def self.run_shell_command(command)
raw_response = nil
IO.popen(command, err: %i(child out)) do |process|
raw_response = process.read
end
start = Time.now
stdout, process = Open3.capture2e(command)
time_taken = start - Time.now

# Raise an error with the output from the shell session if the
# command returns a non-zero status
return if $CHILD_STATUS.success?
return if process.success?

error_context = {
command: command,
time_taken: time_taken,
process_exit_value: process.to_s
}

raise SharedHelpers::HelperSubprocessFailed.new(
raw_response,
command
message: stdout,
error_context: error_context
)
end
end
Expand Down
19 changes: 18 additions & 1 deletion spec/dependabot/shared_helpers_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@
let(:function) { "example" }
let(:args) { ["foo"] }
let(:env) { nil }
let(:stderr_to_stdout) { false }

subject(:run_subprocess) do
project_root = File.join(File.dirname(__FILE__), "../..")
Expand All @@ -64,7 +65,8 @@
command: command,
function: function,
args: args,
env: env
env: env,
stderr_to_stdout: stderr_to_stdout
)
end

Expand All @@ -80,6 +82,21 @@
expect(run_subprocess).to eq("function" => function, "args" => args)
end
end

context "when sending stderr to stdout" do
let(:stderr_to_stdout) { true }
let(:function) { "useful_error" }

it "raises a HelperSubprocessFailed error with stderr output" do
expect { run_subprocess }.
to raise_error(
Dependabot::SharedHelpers::HelperSubprocessFailed
) do |error|
expect(error.message).
to include("Some useful error")
end
end
end
end

context "when the subprocess fails gracefully" do
Expand Down

0 comments on commit b7db071

Please sign in to comment.