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

Improve error when native helper gives empty output #6521

Closed

Conversation

deivid-rodriguez
Copy link
Contributor

@deivid-rodriguez deivid-rodriguez commented Jan 25, 2023

If native helper output is empty, an empty string is unparseable JSON and we end up getting an error about that, but no information about the underlying culprit.

In this case, show the native error output, which is likely to contain something useful.

Before

Dependabot::Bundler::UpdateChecker::VersionResolver#latest_resolvable_version_details with a gemspec and a Gemfile with an upper bound that is lower than the current req 
Failure/Error: raise Dependabot::DependencyFileNotEvaluatable, msg

Dependabot::DependencyFileNotEvaluatable:
  Error evaluating your dependency files:
# ./lib/dependabot/bundler/update_checker/shared_bundler_helpers.rb:82:in `handle_bundler_errors'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:119:in `rescue in fetch_latest_resolvable_version_details'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:75:in `fetch_latest_resolvable_version_details'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:44:in `latest_resolvable_version_details'
# ./spec/dependabot/bundler/update_checker/version_resolver_spec.rb:52:in `block (3 levels) in <top (required)>'
# ./spec/dependabot/bundler/update_checker/version_resolver_spec.rb:414:in `block (5 levels) in <top (required)>'
# ./spec/spec_helper.rb:50:in `block (2 levels) in <top (required)>'
# /home/dependabot/common/spec/spec_helper.rb:63:in `block (2 levels) in <top (required)>'
# ./.bundle/ruby/3.1.0/gems/webmock-3.18.1/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'
# ------------------
# --- Caused by: ---
# JSON::ParserError:
#   unexpected token at ''
#   ./.bundle/ruby/3.1.0/gems/json-2.6.3/lib/json/common.rb:216:in `parse'

After

Dependabot::Bundler::UpdateChecker::VersionResolver#latest_resolvable_version_details with a gemspec and a Gemfile with an upper bound that is lower than the current req 
Failure/Error: raise Dependabot::DependencyFileNotEvaluatable, msg

Dependabot::DependencyFileNotEvaluatable:
  Error evaluating your dependency files: No output from command. Error from command: /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/definition.rb:432:in `validate_ruby!': Your Ruby version is 3.1.3, but your Gemfile specified 2.4.10 (Bundler::RubyVersionMismatch)
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/definition.rb:407:in `validate_runtime!'
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler.rb:155:in `setup'
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/setup.rb:20:in `block in <top (required)>'
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/ui/shell.rb:136:in `with_level'
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/ui/shell.rb:88:in `silence'
  	from /usr/local/lib/ruby/gems/3.1.0/gems/bundler-2.3.26/lib/bundler/setup.rb:20:in `<top (required)>'
  	from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
  	from <internal:/usr/local/lib/ruby/3.1.0/rubygems/core_ext/kernel_require.rb>:85:in `require'
  	from /opt/bundler/v2/run.rb:4:in `<main>'
# ./lib/dependabot/bundler/update_checker/shared_bundler_helpers.rb:82:in `handle_bundler_errors'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:119:in `rescue in fetch_latest_resolvable_version_details'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:75:in `fetch_latest_resolvable_version_details'
# ./lib/dependabot/bundler/update_checker/version_resolver.rb:44:in `latest_resolvable_version_details'
# ./spec/dependabot/bundler/update_checker/version_resolver_spec.rb:52:in `block (3 levels) in <top (required)>'
# ./spec/dependabot/bundler/update_checker/version_resolver_spec.rb:414:in `block (5 levels) in <top (required)>'
# ./spec/spec_helper.rb:50:in `block (2 levels) in <top (required)>'
# /home/dependabot/common/spec/spec_helper.rb:63:in `block (2 levels) in <top (required)>'
# ./.bundle/ruby/3.1.0/gems/webmock-3.18.1/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'
# ------------------
# --- Caused by: ---
# JSON::ParserError:
#   unexpected token at ''
#   ./.bundle/ruby/3.1.0/gems/json-2.6.3/lib/json/common.rb:216:in `parse'

Fix #4948

@deivid-rodriguez deivid-rodriguez requested a review from a team as a code owner January 25, 2023 18:49
@jeffwidman
Copy link
Member

So this would be super useful, I was literally debugging an error like this just last night.

However, is there a security risk here? Historically I thought we intentionally suppressed stderr output from the native helpers in prod because we don't control what they might output, and it could potentially include secrets.

@deivid-rodriguez
Copy link
Contributor Author

Fair concern.

In my opinion, if a package manager is including secrets in its error output, that'd be a bug in the package manager (at least that's how Bundler & RubyGems treat it).

If this is a concern though, we should review the whole codebase, because we're already including error output in other places. For example, whenever stderr_to_stdout is fed to this method.

@deivid-rodriguez deivid-rodriguez marked this pull request as draft January 25, 2023 19:57
If native helper output is empty, an empty string is unparseable JSON
and we end up getting an error about that, but no information about the
underlying culprit.

In this case, show the native error output, which is likely to contain
something useful.
@dwc0011
Copy link
Contributor

dwc0011 commented Jun 29, 2023

Sorry for long comment and I know this has been in work in progress for a while, but I think it is worth revisiting. I was run down a rabbit hole tonight trying to figure out what exactly what was happening and causing the JSON parser error. I had to dig into the dependabot-core source code to figure out what was happening. Not intuitive or user friendly.

If an error happens in the native subprocess helper, a more meaningful message can and should be raised with a valid error class associated with it.

The proposed solution in this PR:

raise HelperSubprocessFailed.new(
        message: stdout.empty? ? "No output from command. Error from command: #{stderr}" : stdout,
        error_class: "JSON::ParserError",
        error_context: error_context
      )

Is still problematic because the error class of JSON::ParserError in the resulting output message. The parser was not an error, it wasn't the cause of the issue, heck it had nothing to do with the issue, it was a red herring, because it was passed an empty string, which can and should be checked.

I propose if stdout is empty or has a Json parse error, then process stderr and raise with a different error class. If worried about if the message has secrets, then the message could be as simple as a base message of "Error while running #{command}".

We can mimic what is currently being done in the main branch for out of memory errors. If we attempt to detect some of the common ones, then we can append a much more meaningful message to the base message.

For instance, 'command not found', 'Versionmismatch', and any other potentially common ones. (obviously, this would require some trial and error to get a few of the common ones). Below is untested, unlinted, non-ide written example of what I am trying to explain.

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,
       process_termsig: process.termsig
     }

     check_out_of_memory_error(stderr, error_context)
     
     if stdout
       response = JSON.parse(stdout)
       return response["result"] if process.success?
       
       raise HelperSubprocessFailed.new(
         message: response["error"],
         error_class: response["error_class"],
         error_context: error_context,
         trace: response["trace"]
       )
     end
    raise_command_errors(stderr, error_context)
   rescue JSON::ParserError
     raise HelperSubprocessFailed.new(
       message: stdout || "No output from command",
       error_class: "JSON::ParserError",
       error_context: error_context
     )
   end
def self.raise_command_errors(stderr, error_context)
    base_error = "Error running #{errror_context['command']}"
    if stderr&.include?("command not found")
        error_msg = "#{base_error}: command not found"
        error_class = "Dependabot::CommandNotFound"
    
    elsif stderr&.include?("VersionMisMatch")
        error_msg = "#{base_error}: version mismatch"
        error_class = "Dependabot::Version Mismatch"
    else
        error_msg = "#{base_error}: unknown error"
        error_class = "Dependabot::UnknownError"
    end
    raise HelperSubprocessFailed.new(
       message: error_msg ,
       error_class: error_class ,
       error_context: error_context
     )
end

@deivid-rodriguez
Copy link
Contributor Author

I get the idea and it makes sense. Rather than trying to parse empty output as JSON and rescue the parse error, we can detect the situation and raise something more explicit.

Even if privacy of error messages not under our control is still a concern, we can still raise a more accurate error class than JSON::ParseError in this case like Dependabot::UnknownSubprocessError, and not even try to parse the empty output.

Feel free to raise a PR for this, I'll close this one for now since the privacy bit is unclear right now.

@deivid-rodriguez deivid-rodriguez deleted the deivid-rodriguez/improve-native-helper-errors branch June 29, 2023 06:37
@Nishnha Nishnha mentioned this pull request Jul 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Improve backtrace for spec failures caused by empty native helper output
3 participants