From dbb517df4b222496a003912c93a1022fb521e6c6 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Mon, 16 Dec 2024 15:56:13 -0800 Subject: [PATCH 01/10] add command helpers with timeout behind feature flag `enable_shared_helpers_command_timeout` --- common/lib/dependabot/command_helpers.rb | 196 ++++++++++ common/lib/dependabot/shared_helpers.rb | 58 ++- .../spec/dependabot/command_helpers_spec.rb | 87 +++++ common/spec/dependabot/shared_helpers_spec.rb | 357 +++++++++++++----- common/spec/fixtures/commands/error.sh | 3 + common/spec/fixtures/commands/error_hang.sh | 3 + common/spec/fixtures/commands/output_hang.sh | 3 + common/spec/fixtures/commands/success.sh | 3 + common/spec/spec_helper.rb | 8 + 9 files changed, 613 insertions(+), 105 deletions(-) create mode 100644 common/lib/dependabot/command_helpers.rb create mode 100644 common/spec/dependabot/command_helpers_spec.rb create mode 100755 common/spec/fixtures/commands/error.sh create mode 100755 common/spec/fixtures/commands/error_hang.sh create mode 100755 common/spec/fixtures/commands/output_hang.sh create mode 100755 common/spec/fixtures/commands/success.sh diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb new file mode 100644 index 0000000000..954a20b0c8 --- /dev/null +++ b/common/lib/dependabot/command_helpers.rb @@ -0,0 +1,196 @@ +# typed: strict +# frozen_string_literal: true + +require "open3" +require "timeout" +require "sorbet-runtime" +require "shellwords" + +module Dependabot + module CommandHelpers + extend T::Sig + + class ProcessStatus + extend T::Sig + + sig { params(process_status: Process::Status, custom_exitstatus: T.nilable(Integer)).void } + def initialize(process_status, custom_exitstatus = nil) + @process_status = process_status + @custom_exitstatus = custom_exitstatus + end + + # Return the exit status, either from the process status or the custom one + sig { returns(Integer) } + def exitstatus + @custom_exitstatus || @process_status.exitstatus || 0 + end + + # Determine if the process was successful + sig { returns(T::Boolean) } + def success? + @custom_exitstatus.nil? ? @process_status.success? || false : @custom_exitstatus.zero? + end + + # Return the PID of the process (if available) + sig { returns(T.nilable(Integer)) } + def pid + @process_status.pid + end + + sig { returns(T.nilable(Integer)) } + def termsig + @process_status.termsig + end + + # String representation of the status + sig { returns(String) } + def to_s + if @custom_exitstatus + "pid #{pid || 'unknown'}: exit #{@custom_exitstatus} (custom status)" + else + @process_status.to_s + end + end + end + + DEFAULT_TIMEOUTS = T.let({ + no_time_out: -1, # No timeout + local: 30, # Local commands + network: 120, # Network-dependent commands + long_running: 300 # Long-running tasks (e.g., builds) + }.freeze, T::Hash[T.untyped, T.untyped]) + + # rubocop:disable Metrics/AbcSize + # rubocop:disable Metrics/MethodLength + # rubocop:disable Metrics/PerceivedComplexity + sig do + params( + env_cmd: T::Array[T.any(T::Hash[String, String], String)], + stdin_data: T.nilable(String), + stderr_to_stdout: T::Boolean, + command_type: Symbol, + timeout: Integer + ).returns([T.nilable(String), T.nilable(String), T.nilable(ProcessStatus), Float]) + end + def self.capture3_with_timeout( + env_cmd, + stdin_data: nil, + stderr_to_stdout: false, + command_type: :network, + timeout: -1 + ) + # Assign default timeout based on command type if timeout < 0 + timeout = DEFAULT_TIMEOUTS[command_type] if timeout.negative? + + stdout = T.let("", String) + stderr = T.let("", String) + status = T.let(nil, T.nilable(ProcessStatus)) + pid = T.let(nil, T.untyped) + start_time = Time.now + + begin + T.unsafe(Open3).popen3(*env_cmd) do |stdin, stdout_io, stderr_io, wait_thr| + pid = wait_thr.pid + stdin&.write(stdin_data) if stdin_data + stdin&.close + + stdout_io.sync = true + stderr_io.sync = true + + # Array to monitor both stdout and stderr + ios = [stdout_io, stderr_io] + + last_output_time = Time.now # Track the last time output was received + + until ios.empty? + # Calculate remaining timeout dynamically + remaining_timeout = timeout - (Time.now - last_output_time) + + # Raise an error if timeout is exceeded + if remaining_timeout <= 0 + terminate_process(pid) + status = ProcessStatus.new(wait_thr.value, 124) + raise Timeout::Error, "Timed out due to inactivity after #{timeout} seconds" + end + + # Use IO.select with a dynamically calculated short timeout + ready_ios = IO.select(ios, nil, nil, [0.1, remaining_timeout].min) + + # Process ready IO streams + ready_ios&.first&.each do |io| + data = io.read_nonblock(1024) + last_output_time = Time.now + if io == stdout_io + stdout += data + else + stderr += data unless stderr_to_stdout + stdout += data if stderr_to_stdout + end + rescue EOFError + ios.delete(io) + rescue IO::WaitReadable + next + end + end + + status = ProcessStatus.new(wait_thr.value) + end + rescue Timeout::Error => e + stderr += e.message unless stderr_to_stdout + stdout += e.message if stderr_to_stdout + rescue Errno::ENOENT => e + stderr += e.message unless stderr_to_stdout + stdout += e.message if stderr_to_stdout + end + + elapsed_time = Time.now - start_time + [stdout, stderr, status, elapsed_time] + end + # rubocop:enable Metrics/AbcSize + # rubocop:enable Metrics/MethodLength + # rubocop:enable Metrics/PerceivedComplexity + sig { params(pid: T.nilable(Integer)).void } + def self.terminate_process(pid) + return unless pid + + begin + if process_alive?(pid) + Process.kill("TERM", pid) # Attempt graceful termination + sleep(0.5) # Allow process to terminate + end + if process_alive?(pid) + Process.kill("KILL", pid) # Forcefully kill if still running + end + rescue Errno::EPERM + Dependabot.logger.error("Insufficient permissions to terminate process: #{pid}") + ensure + begin + Process.waitpid(pid) + rescue Errno::ESRCH, Errno::ECHILD + # Process has already exited + end + end + end + + sig { params(pid: T.nilable(Integer)).returns(T::Boolean) } + def self.process_alive?(pid) + return false if pid.nil? # No PID, consider process not alive + + begin + Process.kill(0, pid) # Check if the process exists + true # Process is still alive + rescue Errno::ESRCH + false # Process does not exist (terminated successfully) + rescue Errno::EPERM + Dependabot.logger.error("Insufficient permissions to check process: #{pid}") + false # Assume process not alive due to lack of permissions + end + end + + sig { params(command: String).returns(String) } + def self.escape_command(command) + command_parts = command.split.map(&:strip).reject(&:empty?) + Shellwords.join(command_parts) + end + end +end diff --git a/common/lib/dependabot/shared_helpers.rb b/common/lib/dependabot/shared_helpers.rb index 4ef7a3c201..ddfea8ca9e 100644 --- a/common/lib/dependabot/shared_helpers.rb +++ b/common/lib/dependabot/shared_helpers.rb @@ -7,7 +7,6 @@ require "fileutils" require "json" require "open3" -require "shellwords" require "sorbet-runtime" require "tmpdir" @@ -17,9 +16,10 @@ require "dependabot/errors" require "dependabot/workspace" require "dependabot" +require "dependabot/command_helpers" module Dependabot - module SharedHelpers + module SharedHelpers # rubocop:disable Metrics/ModuleLength extend T::Sig GIT_CONFIG_GLOBAL_PATH = T.let(File.expand_path(".gitconfig", Utils::BUMP_TMP_DIR_PATH), String) @@ -121,8 +121,7 @@ def sentry_context # Escapes all special characters, e.g. = & | <> sig { params(command: String).returns(String) } def self.escape_command(command) - command_parts = command.split.map(&:strip).reject(&:empty?) - Shellwords.join(command_parts) + CommandHelpers.escape_command(command) end # rubocop:disable Metrics/MethodLength @@ -135,14 +134,18 @@ def self.escape_command(command) env: T.nilable(T::Hash[String, String]), stderr_to_stdout: T::Boolean, allow_unsafe_shell_command: T::Boolean, - error_class: T.class_of(HelperSubprocessFailed) + error_class: T.class_of(HelperSubprocessFailed), + command_type: Symbol, + timeout: Integer ) .returns(T.nilable(T.any(String, T::Hash[String, T.untyped], T::Array[T::Hash[String, T.untyped]]))) end def self.run_helper_subprocess(command:, function:, args:, env: nil, stderr_to_stdout: false, allow_unsafe_shell_command: false, - error_class: HelperSubprocessFailed) + error_class: HelperSubprocessFailed, + command_type: :network, + timeout: -1) start = Time.now stdin_data = JSON.dump(function: function, args: args) cmd = allow_unsafe_shell_command ? command : escape_command(command) @@ -157,7 +160,16 @@ def self.run_helper_subprocess(command:, function:, args:, env: nil, end env_cmd = [env, cmd].compact - stdout, stderr, process = T.unsafe(Open3).capture3(*env_cmd, stdin_data: stdin_data) + if Experiments.enabled?(:enable_shared_helpers_command_timeout) + stdout, stderr, process = CommandHelpers.capture3_with_timeout( + env_cmd, + stdin_data: stdin_data, + command_type: command_type, + timeout: timeout + ) + else + stdout, stderr, process = T.unsafe(Open3).capture3(*env_cmd, stdin_data: stdin_data) + end time_taken = Time.now - start if ENV["DEBUG_HELPERS"] == "true" @@ -177,16 +189,16 @@ def self.run_helper_subprocess(command:, function:, args:, env: nil, function: function, args: args, time_taken: time_taken, - stderr_output: stderr ? stderr[0..50_000] : "", # Truncate to ~100kb + stderr_output: stderr[0..50_000], # Truncate to ~100kb process_exit_value: process.to_s, - process_termsig: process.termsig + process_termsig: process&.termsig } check_out_of_memory_error(stderr, error_context, error_class) begin response = JSON.parse(stdout) - return response["result"] if process.success? + return response["result"] if process&.success? raise error_class.new( message: response["error"], @@ -415,6 +427,7 @@ def self.find_safe_directories safe_directories end + # rubocop:disable Metrics/PerceivedComplexity sig do params( command: String, @@ -422,7 +435,9 @@ def self.find_safe_directories cwd: T.nilable(String), env: T.nilable(T::Hash[String, String]), fingerprint: T.nilable(String), - stderr_to_stdout: T::Boolean + stderr_to_stdout: T::Boolean, + command_type: Symbol, + timeout: Integer ).returns(String) end def self.run_shell_command(command, @@ -430,7 +445,9 @@ def self.run_shell_command(command, cwd: nil, env: {}, fingerprint: nil, - stderr_to_stdout: true) + stderr_to_stdout: true, + command_type: :network, + timeout: -1) start = Time.now cmd = allow_unsafe_shell_command ? command : escape_command(command) @@ -439,7 +456,17 @@ def self.run_shell_command(command, opts = {} opts[:chdir] = cwd if cwd - if stderr_to_stdout + env_cmd = [env || {}, cmd, opts].compact + if Experiments.enabled?(:enable_shared_helpers_command_timeout) + + stdout, stderr, process, _elapsed_time = CommandHelpers.capture3_with_timeout( + env_cmd, + stderr_to_stdout: stderr_to_stdout, + command_type: command_type, + timeout: timeout + ) + + elsif stderr_to_stdout stdout, process = Open3.capture2e(env || {}, cmd, opts) else stdout, stderr, process = Open3.capture3(env || {}, cmd, opts) @@ -449,7 +476,7 @@ def self.run_shell_command(command, # Raise an error with the output from the shell session if the # command returns a non-zero status - return stdout if process.success? + return stdout || "" if process&.success? error_context = { command: cmd, @@ -461,10 +488,11 @@ def self.run_shell_command(command, check_out_of_disk_memory_error(stderr, error_context) raise SharedHelpers::HelperSubprocessFailed.new( - message: stderr_to_stdout ? stdout : "#{stderr}\n#{stdout}", + message: stderr_to_stdout ? (stdout || "") : "#{stderr}\n#{stdout}", error_context: error_context ) end + # rubocop:enable Metrics/PerceivedComplexity sig { params(stderr: T.nilable(String), error_context: T::Hash[Symbol, String]).void } def self.check_out_of_disk_memory_error(stderr, error_context) diff --git a/common/spec/dependabot/command_helpers_spec.rb b/common/spec/dependabot/command_helpers_spec.rb new file mode 100644 index 0000000000..9f51a8b8f9 --- /dev/null +++ b/common/spec/dependabot/command_helpers_spec.rb @@ -0,0 +1,87 @@ +# typed: false +# frozen_string_literal: true + +require "spec_helper" +require "dependabot/command_helpers" + +RSpec.describe Dependabot::CommandHelpers do + describe ".capture3_with_timeout" do + let(:success_cmd) { command_fixture("success.sh") } + let(:error_cmd) { command_fixture("error.sh") } + let(:output_hang_cmd) { command_fixture("output_hang.sh") } + let(:error_hang_cmd) { command_fixture("error_hang.sh") } + let(:invalid_cmd) { "non_existent_command" } + let(:timeout) { 2 } # Timeout for hanging commands + + context "when the command runs successfully" do + it "captures stdout and exits successfully" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [success_cmd], + timeout: timeout + ) + + expect(stdout).to eq("This is a successful command.\n") + expect(stderr).to eq("") + expect(status.exitstatus).to eq(0) + expect(elapsed_time).to be > 0 + end + end + + context "when the command runs with an error" do + it "captures stderr and returns an error status" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [error_cmd], + timeout: timeout + ) + + expect(stdout).to eq("") + expect(stderr).to eq("This is an error message.\n") + expect(status.exitstatus).to eq(1) + expect(elapsed_time).to be > 0 + end + end + + context "when the command runs with output but hangs" do + it "times out and appends a timeout message to stderr" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [output_hang_cmd], + timeout: timeout + ) + + expect(stdout).to eq("This is a hanging command.\n") + expect(stderr).to include("Timed out due to inactivity after #{timeout} seconds") + expect(status.exitstatus).to eq(124) # Timeout-specific status code + expect(elapsed_time).to be_within(1).of(timeout) + end + end + + context "when the command runs with an error but hangs" do + it "times out and appends a timeout message to stderr" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [error_hang_cmd], + timeout: timeout + ) + + expect(stdout).to eq("") + expect(stderr).to include("This is a hanging error command.") + expect(stderr).to include("Timed out due to inactivity after #{timeout} seconds") + expect(status.exitstatus).to eq(124) + expect(elapsed_time).to be_within(1).of(timeout) + end + end + + context "when the command is invalid" do + it "raises an error and captures stderr" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [invalid_cmd], + timeout: timeout + ) + + expect(stdout).to eq("") + expect(stderr).to include("No such file or directory - non_existent_command") if stderr + expect(status).to be_nil + expect(elapsed_time).to be > 0 + end + end + end +end diff --git a/common/spec/dependabot/shared_helpers_spec.rb b/common/spec/dependabot/shared_helpers_spec.rb index c45fc3fba6..132b8db88d 100644 --- a/common/spec/dependabot/shared_helpers_spec.rb +++ b/common/spec/dependabot/shared_helpers_spec.rb @@ -16,6 +16,18 @@ class EcoSystemHelperSubprocessFailed < Dependabot::SharedHelpers::HelperSubproc let(:spec_root) { File.join(File.dirname(__FILE__), "..") } let(:tmp) { Dependabot::Utils::BUMP_TMP_DIR_PATH } + let(:enable_shared_helpers_command_timeout) { false } + + before do + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout) + .and_return(enable_shared_helpers_command_timeout) + end + + after do + Dependabot::Experiments.reset! + end + describe ".in_a_temporary_directory" do def existing_tmp_folders Dir.glob(File.join(tmp, "*")) @@ -149,84 +161,173 @@ def existing_tmp_folders let(:stderr_to_stdout) { false } let(:error_class) { Dependabot::SharedHelpers::HelperSubprocessFailed } - context "when the subprocess is successful" do - it "returns the result" do - expect(run_subprocess).to eq("function" => function, "args" => args) + context "when enable_shared_helpers_command_timeout is disabled" do + let(:enable_shared_helpers_command_timeout) { false } + + context "when the subprocess is successful" do + it "returns the result" do + expect(run_subprocess).to eq("function" => function, "args" => args) + end + + context "with an env" do + let(:env) { { "MIX_EXS" => "something" } } + + it "runs the function passed, as expected" do + 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 "with an env" do - let(:env) { { "MIX_EXS" => "something" } } + context "when the subprocess fails gracefully" do + let(:function) { "error" } - it "runs the function passed, as expected" do - expect(run_subprocess).to eq("function" => function, "args" => args) + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) end end - context "when sending stderr to stdout" do - let(:stderr_to_stdout) { true } - let(:function) { "useful_error" } + context "when the subprocess fails gracefully with sensitive data" do + let(:function) { "sensitive_error" } - it "raises a HelperSubprocessFailed error with stderr output" do + it "raises a HelperSubprocessFailed error" do expect { run_subprocess } - .to raise_error( - Dependabot::SharedHelpers::HelperSubprocessFailed - ) do |error| - expect(error.message) - .to include("Some useful error") + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| + expect(error.message).to include("Something went wrong: https://www.example.com") end end end - end - context "when the subprocess fails gracefully" do - let(:function) { "error" } + context "when the subprocess fails ungracefully" do + let(:function) { "hard_error" } + + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + end + end + + context "when the subprocess is killed" do + let(:function) { "killed" } + + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to(raise_error do |error| + expect(error) + .to be_a(Dependabot::SharedHelpers::HelperSubprocessFailed) + expect(error.error_context[:process_termsig]).to eq(9) + end) + end + end + + context "when a custom error class is passed" do + let(:error_class) { EcoSystemHelperSubprocessFailed } + let(:function) { "hard_error" } - it "raises a HelperSubprocessFailed error" do - expect { run_subprocess } - .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + it "raises the custom error class" do + expect { run_subprocess } + .to raise_error(EcoSystemHelperSubprocessFailed) + end end end - context "when the subprocess fails gracefully with sensitive data" do - let(:function) { "sensitive_error" } + context "when enable_shared_helpers_command_timeout is enabled" do + let(:enable_shared_helpers_command_timeout) { true } + + context "when the subprocess is successful" do + it "returns the result" do + expect(run_subprocess).to eq("function" => function, "args" => args) + end + + context "with an env" do + let(:env) { { "MIX_EXS" => "something" } } + + it "runs the function passed, as expected" do + expect(run_subprocess).to eq("function" => function, "args" => args) + end + end - it "raises a HelperSubprocessFailed error" do - expect { run_subprocess } - .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| - expect(error.message).to include("Something went wrong: https://www.example.com") + 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 - end - context "when the subprocess fails ungracefully" do - let(:function) { "hard_error" } + context "when the subprocess fails gracefully" do + let(:function) { "error" } - it "raises a HelperSubprocessFailed error" do - expect { run_subprocess } - .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + end end - end - context "when the subprocess is killed" do - let(:function) { "killed" } + context "when the subprocess fails gracefully with sensitive data" do + let(:function) { "sensitive_error" } - it "raises a HelperSubprocessFailed error" do - expect { run_subprocess } - .to(raise_error do |error| - expect(error) - .to be_a(Dependabot::SharedHelpers::HelperSubprocessFailed) - expect(error.error_context[:process_termsig]).to eq(9) - end) + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| + expect(error.message).to include("Something went wrong: https://www.example.com") + end + end end - end - context "when a custom error class is passed" do - let(:error_class) { EcoSystemHelperSubprocessFailed } - let(:function) { "hard_error" } + context "when the subprocess fails ungracefully" do + let(:function) { "hard_error" } - it "raises the custom error class" do - expect { run_subprocess } - .to raise_error(EcoSystemHelperSubprocessFailed) + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + end + end + + context "when the subprocess is killed" do + let(:function) { "killed" } + + it "raises a HelperSubprocessFailed error" do + expect { run_subprocess } + .to(raise_error do |error| + expect(error) + .to be_a(Dependabot::SharedHelpers::HelperSubprocessFailed) + expect(error.error_context[:process_termsig]).to eq(9) + end) + end + end + + context "when a custom error class is passed" do + let(:error_class) { EcoSystemHelperSubprocessFailed } + let(:function) { "hard_error" } + + it "raises the custom error class" do + expect { run_subprocess } + .to raise_error(EcoSystemHelperSubprocessFailed) + end end end end @@ -239,71 +340,147 @@ def existing_tmp_folders let(:command) { File.join(spec_root, "helpers/test/run_bash") + " output" } let(:env) { nil } - context "when the subprocess is successful" do - it "returns the result" do - expect(run_shell_command).to eq("output\n") - end - end + context "when enable_shared_helpers_command_timeout is disabled" do + let(:enable_shared_helpers_command_timeout) { false } - context "with bash command as argument" do - let(:command) do - File.join(spec_root, "helpers/test/run_bash") + " $(ps)" + context "when the subprocess is successful" do + it "returns the result" do + expect(run_shell_command).to eq("output\n") + end end - it "returns the argument" do - expect(run_shell_command).to eq("$(ps)\n") + context "with bash command as argument" do + let(:command) do + File.join(spec_root, "helpers/test/run_bash") + " $(ps)" + end + + it "returns the argument" do + expect(run_shell_command).to eq("$(ps)\n") + end + + context "when allowing unsafe shell command" do + subject(:run_shell_command) do + described_class + .run_shell_command(command, allow_unsafe_shell_command: true) + end + + it "returns the command output" do + output = run_shell_command + expect(output).not_to eq("$(ps)\n") + expect(output).to include("PID") + end + end end - context "when allowing unsafe shell command" do - subject(:run_shell_command) do - described_class - .run_shell_command(command, allow_unsafe_shell_command: true) + context "with an environment variable" do + let(:env) { { "TEST_ENV" => "prefix:" } } + + it "is available to the command" do + expect(run_shell_command).to eq("prefix:output\n") end + end - it "returns the command output" do - output = run_shell_command - expect(output).not_to eq("$(ps)\n") - expect(output).to include("PID") + context "when the subprocess exits" do + let(:command) { File.join(spec_root, "helpers/test/error_bash") } + + it "raises a HelperSubprocessFailed error" do + expect { run_shell_command } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) end end - end - context "with an environment variable" do - let(:env) { { "TEST_ENV" => "prefix:" } } + context "when the subprocess exits with out of disk error" do + let(:command) { File.join(spec_root, "helpers/test/error_bash disk") } - it "is available to the command" do - expect(run_shell_command).to eq("prefix:output\n") + it "raises a HelperSubprocessFailed out of disk error" do + expect { run_shell_command } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| + expect(error.message).to include("No space left on device") + end + end + + context "when the subprocess exits with out of memory error" do + let(:command) { File.join(spec_root, "helpers/test/error_bash memory") } + + it "raises a HelperSubprocessFailed out of memory error" do + expect { run_shell_command } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| + expect(error.message).to include("MemoryError") + end + end + end end end - context "when the subprocess exits" do - let(:command) { File.join(spec_root, "helpers/test/error_bash") } + context "when enable_shared_helpers_command_timeout is enabled" do + let(:enable_shared_helpers_command_timeout) { true } - it "raises a HelperSubprocessFailed error" do - expect { run_shell_command } - .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + context "when the subprocess is successful" do + it "returns the result" do + expect(run_shell_command).to eq("output\n") + end end - end - context "when the subprocess exits with out of disk error" do - let(:command) { File.join(spec_root, "helpers/test/error_bash disk") } + context "with bash command as argument" do + let(:command) do + File.join(spec_root, "helpers/test/run_bash") + " $(ps)" + end + + it "returns the argument" do + expect(run_shell_command).to eq("$(ps)\n") + end - it "raises a HelperSubprocessFailed out of disk error" do - expect { run_shell_command } - .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| - expect(error.message).to include("No space left on device") + context "when allowing unsafe shell command" do + subject(:run_shell_command) do + described_class + .run_shell_command(command, allow_unsafe_shell_command: true) end + + it "returns the command output" do + output = run_shell_command + expect(output).not_to eq("$(ps)\n") + expect(output).to include("PID") + end + end end - context "when the subprocess exits with out of memory error" do - let(:command) { File.join(spec_root, "helpers/test/error_bash memory") } + context "with an environment variable" do + let(:env) { { "TEST_ENV" => "prefix:" } } - it "raises a HelperSubprocessFailed out of memory error" do + it "is available to the command" do + expect(run_shell_command).to eq("prefix:output\n") + end + end + + context "when the subprocess exits" do + let(:command) { File.join(spec_root, "helpers/test/error_bash") } + + it "raises a HelperSubprocessFailed error" do + expect { run_shell_command } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) + end + end + + context "when the subprocess exits with out of disk error" do + let(:command) { File.join(spec_root, "helpers/test/error_bash disk") } + + it "raises a HelperSubprocessFailed out of disk error" do expect { run_shell_command } .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| - expect(error.message).to include("MemoryError") + expect(error.message).to include("No space left on device") end end + + context "when the subprocess exits with out of memory error" do + let(:command) { File.join(spec_root, "helpers/test/error_bash memory") } + + it "raises a HelperSubprocessFailed out of memory error" do + expect { run_shell_command } + .to raise_error(Dependabot::SharedHelpers::HelperSubprocessFailed) do |error| + expect(error.message).to include("MemoryError") + end + end + end end end end diff --git a/common/spec/fixtures/commands/error.sh b/common/spec/fixtures/commands/error.sh new file mode 100755 index 0000000000..0985371495 --- /dev/null +++ b/common/spec/fixtures/commands/error.sh @@ -0,0 +1,3 @@ +#!/bin/bash +echo "This is an error message." >&2 +exit 1 diff --git a/common/spec/fixtures/commands/error_hang.sh b/common/spec/fixtures/commands/error_hang.sh new file mode 100755 index 0000000000..6b92c10749 --- /dev/null +++ b/common/spec/fixtures/commands/error_hang.sh @@ -0,0 +1,3 @@ +#!/bin/bash +echo "This is a hanging error command." >&2 +sleep 30 diff --git a/common/spec/fixtures/commands/output_hang.sh b/common/spec/fixtures/commands/output_hang.sh new file mode 100755 index 0000000000..e73b57a804 --- /dev/null +++ b/common/spec/fixtures/commands/output_hang.sh @@ -0,0 +1,3 @@ +#!/bin/bash +echo "This is a hanging command." +sleep 30 diff --git a/common/spec/fixtures/commands/success.sh b/common/spec/fixtures/commands/success.sh new file mode 100755 index 0000000000..45241e8517 --- /dev/null +++ b/common/spec/fixtures/commands/success.sh @@ -0,0 +1,3 @@ +#!/bin/bash +echo "This is a successful command." +exit 0 diff --git a/common/spec/spec_helper.rb b/common/spec/spec_helper.rb index 0a2084bf0f..f376821476 100644 --- a/common/spec/spec_helper.rb +++ b/common/spec/spec_helper.rb @@ -194,3 +194,11 @@ def github_credentials }] end end + +# Load a command from the fixtures/commands directory +def command_fixture(name) + path = File.join("spec", "fixtures", "commands", name) + raise "Command fixture '#{name}' does not exist" unless File.exist?(path) + + File.expand_path(path) +end From 87e2b0245ff4246771f5ebb957d177d6bbd07ff5 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Mon, 16 Dec 2024 16:06:39 -0800 Subject: [PATCH 02/10] fix lint issue and feature flag spec issues --- common/lib/dependabot/command_helpers.rb | 3 +++ npm_and_yarn/spec/dependabot/npm_and_yarn/file_parser_spec.rb | 2 ++ .../npm_and_yarn/file_updater/npm_lockfile_updater_spec.rb | 2 ++ .../npm_and_yarn/file_updater/yarn_lockfile_updater_spec.rb | 2 ++ .../spec/dependabot/npm_and_yarn/file_updater_spec.rb | 2 ++ .../npm_and_yarn/update_checker/version_resolver_spec.rb | 2 ++ updater/spec/dependabot/dependency_snapshot_spec.rb | 3 +++ .../operations/refresh_security_update_pull_request_spec.rb | 4 ++++ .../operations/refresh_version_update_pull_request_spec.rb | 4 ++++ 9 files changed, 24 insertions(+) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index 954a20b0c8..8ceb96ed46 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -63,6 +63,7 @@ def to_s # rubocop:disable Metrics/AbcSize # rubocop:disable Metrics/MethodLength # rubocop:disable Metrics/PerceivedComplexity + # rubocop:disable Metrics/CyclomaticComplexity sig do params( env_cmd: T::Array[T.any(T::Hash[String, String], String)], @@ -149,6 +150,8 @@ def self.capture3_with_timeout( # rubocop:enable Metrics/AbcSize # rubocop:enable Metrics/MethodLength # rubocop:enable Metrics/PerceivedComplexity + # rubocop:enable Metrics/CyclomaticComplexity + sig { params(pid: T.nilable(Integer)).void } def self.terminate_process(pid) return unless pid diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_parser_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_parser_spec.rb index 96aab6748c..cfdd667837 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_parser_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_parser_spec.rb @@ -42,6 +42,8 @@ .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/npm_lockfile_updater_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/npm_lockfile_updater_spec.rb index c0f8f842d1..c5fe8dbaee 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/npm_lockfile_updater_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/npm_lockfile_updater_spec.rb @@ -72,6 +72,8 @@ .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/yarn_lockfile_updater_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/yarn_lockfile_updater_spec.rb index aa4c55324e..af955adf0b 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/yarn_lockfile_updater_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/yarn_lockfile_updater_spec.rb @@ -65,6 +65,8 @@ FileUtils.mkdir_p(tmp_path) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater_spec.rb index ab362f490f..3514c191af 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater_spec.rb @@ -68,6 +68,8 @@ .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/version_resolver_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/version_resolver_spec.rb index 0387075973..05a001c0a4 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/version_resolver_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/version_resolver_spec.rb @@ -83,6 +83,8 @@ .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/updater/spec/dependabot/dependency_snapshot_spec.rb b/updater/spec/dependabot/dependency_snapshot_spec.rb index fc63e23a94..e309f117c8 100644 --- a/updater/spec/dependabot/dependency_snapshot_spec.rb +++ b/updater/spec/dependabot/dependency_snapshot_spec.rb @@ -108,6 +108,9 @@ allow(Dependabot::Experiments).to receive(:enabled?) .with(:add_deprecation_warn_to_pr_message) .and_return(true) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout) + .and_return(true) end after do diff --git a/updater/spec/dependabot/updater/operations/refresh_security_update_pull_request_spec.rb b/updater/spec/dependabot/updater/operations/refresh_security_update_pull_request_spec.rb index e69e456adf..e093a1f590 100644 --- a/updater/spec/dependabot/updater/operations/refresh_security_update_pull_request_spec.rb +++ b/updater/spec/dependabot/updater/operations/refresh_security_update_pull_request_spec.rb @@ -158,6 +158,10 @@ .and_return(stub_dependency_change) allow(mock_service).to receive(:close_pull_request) + + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout) + .and_return(true) end after do diff --git a/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb b/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb index dbeeed37b0..6080c2c63a 100644 --- a/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb +++ b/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb @@ -146,6 +146,10 @@ .to receive(:create_from) .and_return(stub_dependency_change) allow(dependency_snapshot).to receive(:ecosystem).and_return(ecosystem) + + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout) + .and_return(true) end after do From 7d157e010a85cab119689b81a932dbc42a8cc858 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Mon, 16 Dec 2024 16:44:33 -0800 Subject: [PATCH 03/10] fix output UTF-8 issue. fix spec issues --- common/lib/dependabot/command_helpers.rb | 3 +++ .../file_updater/pnpm_lockfile_updater_spec.rb | 2 ++ .../update_checker/subdependency_version_resolver_spec.rb | 2 ++ .../spec/dependabot/npm_and_yarn/update_checker_spec.rb | 2 ++ .../operations/refresh_version_update_pull_request_spec.rb | 7 +++---- 5 files changed, 12 insertions(+), 4 deletions(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index 8ceb96ed46..f4c61672ba 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -120,6 +120,9 @@ def self.capture3_with_timeout( # Process ready IO streams ready_ios&.first&.each do |io| data = io.read_nonblock(1024) + + data.force_encoding("UTF-8").scrub! # Normalize to UTF-8 and replace invalid characters + last_output_time = Time.now if io == stdout_io stdout += data diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/pnpm_lockfile_updater_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/pnpm_lockfile_updater_spec.rb index 4f86ad0ec8..811d04a513 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/pnpm_lockfile_updater_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/file_updater/pnpm_lockfile_updater_spec.rb @@ -70,6 +70,8 @@ FileUtils.mkdir_p(tmp_path) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/subdependency_version_resolver_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/subdependency_version_resolver_spec.rb index 51f3bd5de3..10247cb171 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/subdependency_version_resolver_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker/subdependency_version_resolver_spec.rb @@ -41,6 +41,8 @@ .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) allow(Dependabot::Experiments).to receive(:enabled?) .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker_spec.rb b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker_spec.rb index 93208bf669..1af401cf5a 100644 --- a/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker_spec.rb +++ b/npm_and_yarn/spec/dependabot/npm_and_yarn/update_checker_spec.rb @@ -71,6 +71,8 @@ .with(:enable_corepack_for_npm_and_yarn).and_return(enable_corepack_for_npm_and_yarn) allow(Dependabot::Experiments).to receive(:enabled?) .with(:npm_fallback_version_above_v6).and_return(npm_fallback_version_above_v6_enabled) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout).and_return(true) end after do diff --git a/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb b/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb index 6080c2c63a..b8fb3ce989 100644 --- a/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb +++ b/updater/spec/dependabot/updater/operations/refresh_version_update_pull_request_spec.rb @@ -140,16 +140,15 @@ before do allow(Dependabot::Experiments).to receive(:enabled?).with(:lead_security_dependency).and_return(false) + allow(Dependabot::Experiments).to receive(:enabled?) + .with(:enable_shared_helpers_command_timeout) + .and_return(true) allow(Dependabot::UpdateCheckers).to receive(:for_package_manager).and_return(stub_update_checker_class) allow(Dependabot::DependencyChangeBuilder) .to receive(:create_from) .and_return(stub_dependency_change) allow(dependency_snapshot).to receive(:ecosystem).and_return(ecosystem) - - allow(Dependabot::Experiments).to receive(:enabled?) - .with(:enable_shared_helpers_command_timeout) - .and_return(true) end after do From 78c2014a0e516968a41d367cecd32180698d6417 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 09:17:15 -0800 Subject: [PATCH 04/10] update spaces. --- common/lib/dependabot/shared_helpers.rb | 2 -- 1 file changed, 2 deletions(-) diff --git a/common/lib/dependabot/shared_helpers.rb b/common/lib/dependabot/shared_helpers.rb index ddfea8ca9e..023658d019 100644 --- a/common/lib/dependabot/shared_helpers.rb +++ b/common/lib/dependabot/shared_helpers.rb @@ -458,14 +458,12 @@ def self.run_shell_command(command, env_cmd = [env || {}, cmd, opts].compact if Experiments.enabled?(:enable_shared_helpers_command_timeout) - stdout, stderr, process, _elapsed_time = CommandHelpers.capture3_with_timeout( env_cmd, stderr_to_stdout: stderr_to_stdout, command_type: command_type, timeout: timeout ) - elsif stderr_to_stdout stdout, process = Open3.capture2e(env || {}, cmd, opts) else From 81a3e19454f3af8cb15f9d9dcf36f168ef03adf1 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 10:48:04 -0800 Subject: [PATCH 05/10] reading in UTF-8 encoding. --- common/lib/dependabot/command_helpers.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index f4c61672ba..5bdaff24f8 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -119,9 +119,9 @@ def self.capture3_with_timeout( # Process ready IO streams ready_ios&.first&.each do |io| - data = io.read_nonblock(1024) + io.set_encoding("UTF-8", "UTF-8") - data.force_encoding("UTF-8").scrub! # Normalize to UTF-8 and replace invalid characters + data = io.read_nonblock(1024) last_output_time = Time.now if io == stdout_io From b6aef5ff5a64af82ebedde40d6a9df2bf15778c8 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 11:36:53 -0800 Subject: [PATCH 06/10] update logging and ensure no_timeout works as well --- common/lib/dependabot/command_helpers.rb | 38 +++++++++++++++++------- 1 file changed, 28 insertions(+), 10 deletions(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index 5bdaff24f8..7283e74fc6 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -53,12 +53,15 @@ def to_s end end + # Default timeout for commands + DEFAULT_TIMEOUT = 120 + DEFAULT_TIMEOUTS = T.let({ no_time_out: -1, # No timeout local: 30, # Local commands - network: 120, # Network-dependent commands + network: DEFAULT_TIMEOUT, # Network-dependent commands long_running: 300 # Long-running tasks (e.g., builds) - }.freeze, T::Hash[T.untyped, T.untyped]) + }.freeze, T::Hash[Symbol, Integer]) # rubocop:disable Metrics/AbcSize # rubocop:disable Metrics/MethodLength @@ -82,6 +85,7 @@ def self.capture3_with_timeout( ) # Assign default timeout based on command type if timeout < 0 timeout = DEFAULT_TIMEOUTS[command_type] if timeout.negative? + timeout = DEFAULT_TIMEOUT if command_type != :no_time_out && (!timeout || timeout.negative?) stdout = T.let("", String) stderr = T.let("", String) @@ -92,6 +96,9 @@ def self.capture3_with_timeout( begin T.unsafe(Open3).popen3(*env_cmd) do |stdin, stdout_io, stderr_io, wait_thr| pid = wait_thr.pid + Dependabot.logger.info("Started process PID: #{pid} with command: #{env_cmd.join(' ')}") + + # Write to stdin if input data is provided stdin&.write(stdin_data) if stdin_data stdin&.close @@ -105,10 +112,11 @@ def self.capture3_with_timeout( until ios.empty? # Calculate remaining timeout dynamically - remaining_timeout = timeout - (Time.now - last_output_time) + remaining_timeout = T.must(timeout) - (Time.now - last_output_time) if command_type != :no_time_out # Raise an error if timeout is exceeded - if remaining_timeout <= 0 + if command_type != :no_time_out && T.must(remaining_timeout) <= 0 + Dependabot.logger.warn("Process PID: #{pid} timed out after #{timeout}s. Terminating...") terminate_process(pid) status = ProcessStatus.new(wait_thr.value, 124) raise Timeout::Error, "Timed out due to inactivity after #{timeout} seconds" @@ -119,11 +127,12 @@ def self.capture3_with_timeout( # Process ready IO streams ready_ios&.first&.each do |io| + # Ensure UTF-8 encoding for input data io.set_encoding("UTF-8", "UTF-8") - data = io.read_nonblock(1024) - last_output_time = Time.now + # Reset the timeout if data is received + last_output_time = Time.now if data if io == stdout_io stdout += data else @@ -131,23 +140,29 @@ def self.capture3_with_timeout( stdout += data if stderr_to_stdout end rescue EOFError + # Remove the stream when EOF is reached ios.delete(io) rescue IO::WaitReadable + # Continue when IO is not ready yet next end end status = ProcessStatus.new(wait_thr.value) + Dependabot.logger.info("Process PID: #{pid} completed with status: #{status}") end rescue Timeout::Error => e + Dependabot.logger.error("Process PID: #{pid} failed due to timeout: #{e.message}") stderr += e.message unless stderr_to_stdout stdout += e.message if stderr_to_stdout rescue Errno::ENOENT => e + Dependabot.logger.error("Command failed: #{e.message}") stderr += e.message unless stderr_to_stdout stdout += e.message if stderr_to_stdout end elapsed_time = Time.now - start_time + Dependabot.logger.info("Total execution time: #{elapsed_time.round(2)} seconds") [stdout, stderr, status, elapsed_time] end # rubocop:enable Metrics/AbcSize @@ -155,6 +170,7 @@ def self.capture3_with_timeout( # rubocop:enable Metrics/PerceivedComplexity # rubocop:enable Metrics/CyclomaticComplexity + # Terminate a process by PID sig { params(pid: T.nilable(Integer)).void } def self.terminate_process(pid) return unless pid @@ -178,21 +194,23 @@ def self.terminate_process(pid) end end + # Check if the process is still alive sig { params(pid: T.nilable(Integer)).returns(T::Boolean) } def self.process_alive?(pid) - return false if pid.nil? # No PID, consider process not alive + return false if pid.nil? begin Process.kill(0, pid) # Check if the process exists - true # Process is still alive + true rescue Errno::ESRCH - false # Process does not exist (terminated successfully) + false rescue Errno::EPERM Dependabot.logger.error("Insufficient permissions to check process: #{pid}") - false # Assume process not alive due to lack of permissions + false end end + # Escape shell commands to ensure safe execution sig { params(command: String).returns(String) } def self.escape_command(command) command_parts = command.split.map(&:strip).reject(&:empty?) From 50df5314064863c785243988a54816fb81e82c7c Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 15:25:12 -0800 Subject: [PATCH 07/10] add/update specs reduce timeout parameter complexity --- common/lib/dependabot/command_helpers.rb | 53 ++++++++++--------- common/lib/dependabot/shared_helpers.rb | 10 +--- .../spec/dependabot/command_helpers_spec.rb | 19 ++++++- common/spec/fixtures/commands/error_hang.sh | 9 +++- common/spec/fixtures/commands/no_timeout.sh | 4 ++ 5 files changed, 59 insertions(+), 36 deletions(-) create mode 100755 common/spec/fixtures/commands/no_timeout.sh diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index 7283e74fc6..44cc8e4115 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -10,6 +10,14 @@ module Dependabot module CommandHelpers extend T::Sig + module TIMEOUTS + NO_TIME_OUT = -1 + LOCAL = 30 + NETWORK = 120 + LONG_RUNNING = 300 + DEFAULT = NETWORK + end + class ProcessStatus extend T::Sig @@ -53,15 +61,12 @@ def to_s end end - # Default timeout for commands - DEFAULT_TIMEOUT = 120 - DEFAULT_TIMEOUTS = T.let({ no_time_out: -1, # No timeout local: 30, # Local commands - network: DEFAULT_TIMEOUT, # Network-dependent commands + network: 120, # Network-dependent commands long_running: 300 # Long-running tasks (e.g., builds) - }.freeze, T::Hash[Symbol, Integer]) + }.freeze, T::Hash[T.untyped, T.untyped]) # rubocop:disable Metrics/AbcSize # rubocop:disable Metrics/MethodLength @@ -72,7 +77,6 @@ def to_s env_cmd: T::Array[T.any(T::Hash[String, String], String)], stdin_data: T.nilable(String), stderr_to_stdout: T::Boolean, - command_type: Symbol, timeout: Integer ).returns([T.nilable(String), T.nilable(String), T.nilable(ProcessStatus), Float]) end @@ -80,12 +84,8 @@ def self.capture3_with_timeout( env_cmd, stdin_data: nil, stderr_to_stdout: false, - command_type: :network, - timeout: -1 + timeout: TIMEOUTS::DEFAULT ) - # Assign default timeout based on command type if timeout < 0 - timeout = DEFAULT_TIMEOUTS[command_type] if timeout.negative? - timeout = DEFAULT_TIMEOUT if command_type != :no_time_out && (!timeout || timeout.negative?) stdout = T.let("", String) stderr = T.let("", String) @@ -94,7 +94,7 @@ def self.capture3_with_timeout( start_time = Time.now begin - T.unsafe(Open3).popen3(*env_cmd) do |stdin, stdout_io, stderr_io, wait_thr| + T.unsafe(Open3).popen3(*env_cmd) do |stdin, stdout_io, stderr_io, wait_thr| # rubocop:disable Metrics/BlockLength pid = wait_thr.pid Dependabot.logger.info("Started process PID: #{pid} with command: #{env_cmd.join(' ')}") @@ -111,19 +111,21 @@ def self.capture3_with_timeout( last_output_time = Time.now # Track the last time output was received until ios.empty? - # Calculate remaining timeout dynamically - remaining_timeout = T.must(timeout) - (Time.now - last_output_time) if command_type != :no_time_out - - # Raise an error if timeout is exceeded - if command_type != :no_time_out && T.must(remaining_timeout) <= 0 - Dependabot.logger.warn("Process PID: #{pid} timed out after #{timeout}s. Terminating...") - terminate_process(pid) - status = ProcessStatus.new(wait_thr.value, 124) - raise Timeout::Error, "Timed out due to inactivity after #{timeout} seconds" + if timeout.positive? + # Calculate remaining timeout dynamically + remaining_timeout = timeout - (Time.now - last_output_time) + + # Raise an error if timeout is exceeded + if remaining_timeout <= 0 + Dependabot.logger.warn("Process PID: #{pid} timed out after #{timeout}s. Terminating...") + terminate_process(pid) + status = ProcessStatus.new(wait_thr.value, 124) + raise Timeout::Error, "Timed out due to inactivity after #{timeout} seconds" + end end # Use IO.select with a dynamically calculated short timeout - ready_ios = IO.select(ios, nil, nil, [0.1, remaining_timeout].min) + ready_ios = IO.select(ios, nil, nil, 0) # Process ready IO streams ready_ios&.first&.each do |io| @@ -153,8 +155,11 @@ def self.capture3_with_timeout( end rescue Timeout::Error => e Dependabot.logger.error("Process PID: #{pid} failed due to timeout: #{e.message}") - stderr += e.message unless stderr_to_stdout - stdout += e.message if stderr_to_stdout + terminate_process(pid) + + # Append timeout message only to stderr without interfering with stdout + stderr += "\n#{e.message}" unless stderr_to_stdout + stdout += "\n#{e.message}" if stderr_to_stdout rescue Errno::ENOENT => e Dependabot.logger.error("Command failed: #{e.message}") stderr += e.message unless stderr_to_stdout diff --git a/common/lib/dependabot/shared_helpers.rb b/common/lib/dependabot/shared_helpers.rb index 023658d019..650c913ae8 100644 --- a/common/lib/dependabot/shared_helpers.rb +++ b/common/lib/dependabot/shared_helpers.rb @@ -135,7 +135,6 @@ def self.escape_command(command) stderr_to_stdout: T::Boolean, allow_unsafe_shell_command: T::Boolean, error_class: T.class_of(HelperSubprocessFailed), - command_type: Symbol, timeout: Integer ) .returns(T.nilable(T.any(String, T::Hash[String, T.untyped], T::Array[T::Hash[String, T.untyped]]))) @@ -144,8 +143,7 @@ def self.run_helper_subprocess(command:, function:, args:, env: nil, stderr_to_stdout: false, allow_unsafe_shell_command: false, error_class: HelperSubprocessFailed, - command_type: :network, - timeout: -1) + timeout: CommandHelpers::TIMEOUTS::DEFAULT) start = Time.now stdin_data = JSON.dump(function: function, args: args) cmd = allow_unsafe_shell_command ? command : escape_command(command) @@ -164,7 +162,6 @@ def self.run_helper_subprocess(command:, function:, args:, env: nil, stdout, stderr, process = CommandHelpers.capture3_with_timeout( env_cmd, stdin_data: stdin_data, - command_type: command_type, timeout: timeout ) else @@ -436,7 +433,6 @@ def self.find_safe_directories env: T.nilable(T::Hash[String, String]), fingerprint: T.nilable(String), stderr_to_stdout: T::Boolean, - command_type: Symbol, timeout: Integer ).returns(String) end @@ -446,8 +442,7 @@ def self.run_shell_command(command, env: {}, fingerprint: nil, stderr_to_stdout: true, - command_type: :network, - timeout: -1) + timeout: CommandHelpers::TIMEOUTS::DEFAULT) start = Time.now cmd = allow_unsafe_shell_command ? command : escape_command(command) @@ -461,7 +456,6 @@ def self.run_shell_command(command, stdout, stderr, process, _elapsed_time = CommandHelpers.capture3_with_timeout( env_cmd, stderr_to_stdout: stderr_to_stdout, - command_type: command_type, timeout: timeout ) elsif stderr_to_stdout diff --git a/common/spec/dependabot/command_helpers_spec.rb b/common/spec/dependabot/command_helpers_spec.rb index 9f51a8b8f9..8130838abf 100644 --- a/common/spec/dependabot/command_helpers_spec.rb +++ b/common/spec/dependabot/command_helpers_spec.rb @@ -11,6 +11,7 @@ let(:output_hang_cmd) { command_fixture("output_hang.sh") } let(:error_hang_cmd) { command_fixture("error_hang.sh") } let(:invalid_cmd) { "non_existent_command" } + let(:no_timeout_cmd) { command_fixture("no_timeout.sh") } let(:timeout) { 2 } # Timeout for hanging commands context "when the command runs successfully" do @@ -62,8 +63,8 @@ timeout: timeout ) - expect(stdout).to eq("") - expect(stderr).to include("This is a hanging error command.") + expect(stdout).to eq("This is a output for command error command.\n") + expect(stderr).to include("This is an error message.") expect(stderr).to include("Timed out due to inactivity after #{timeout} seconds") expect(status.exitstatus).to eq(124) expect(elapsed_time).to be_within(1).of(timeout) @@ -83,5 +84,19 @@ expect(elapsed_time).to be > 0 end end + + context "when timeout is zero or negative" do + it "waiting commands to be done" do + stdout, stderr, status, elapsed_time = described_class.capture3_with_timeout( + [no_timeout_cmd], + timeout: -1 + ) + + expect(stdout).to eq("This is a command result.\n") + expect(stderr).to eql("") + expect(status.exitstatus).to eq(0) + expect(elapsed_time).to be_within(0.5).of(3) + end + end end end diff --git a/common/spec/fixtures/commands/error_hang.sh b/common/spec/fixtures/commands/error_hang.sh index 6b92c10749..ff59cb756a 100755 --- a/common/spec/fixtures/commands/error_hang.sh +++ b/common/spec/fixtures/commands/error_hang.sh @@ -1,3 +1,8 @@ #!/bin/bash -echo "This is a hanging error command." >&2 -sleep 30 +echo "This is a output for command error command." + +# Simulate an error output to stderr +echo "This is an error message." >&2 + +# Simulate a hang +sleep 30 \ No newline at end of file diff --git a/common/spec/fixtures/commands/no_timeout.sh b/common/spec/fixtures/commands/no_timeout.sh new file mode 100755 index 0000000000..8e52912090 --- /dev/null +++ b/common/spec/fixtures/commands/no_timeout.sh @@ -0,0 +1,4 @@ +#!/bin/bash +echo "This is a command result." +sleep 3 +exit 0 From 1fce03ada0d956576dc79cf8c2891a7afc195429 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 15:27:30 -0800 Subject: [PATCH 08/10] remove unused timeouts --- common/lib/dependabot/command_helpers.rb | 7 ------- 1 file changed, 7 deletions(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index 44cc8e4115..d6d23e67d1 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -61,13 +61,6 @@ def to_s end end - DEFAULT_TIMEOUTS = T.let({ - no_time_out: -1, # No timeout - local: 30, # Local commands - network: 120, # Network-dependent commands - long_running: 300 # Long-running tasks (e.g., builds) - }.freeze, T::Hash[T.untyped, T.untyped]) - # rubocop:disable Metrics/AbcSize # rubocop:disable Metrics/MethodLength # rubocop:disable Metrics/PerceivedComplexity From 2c4dc102f055b6eacc3b43276ce73515cadec953 Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 15:54:17 -0800 Subject: [PATCH 09/10] fix streamed data UTF-8 issues --- common/lib/dependabot/command_helpers.rb | 22 ++++++++++++++-------- 1 file changed, 14 insertions(+), 8 deletions(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index d6d23e67d1..ecb5d71cdc 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -122,10 +122,16 @@ def self.capture3_with_timeout( # Process ready IO streams ready_ios&.first&.each do |io| - # Ensure UTF-8 encoding for input data - io.set_encoding("UTF-8", "UTF-8") + # 1. Read data from the stream + io.set_encoding("BINARY") data = io.read_nonblock(1024) + # 2. Force encoding to UTF-8 (for proper conversion) + data.force_encoding("UTF-8") + + # 3. Convert to UTF-8 safely, handling invalid/undefined bytes + data = data.encode("UTF-8", invalid: :replace, undef: :replace, replace: "?") + # Reset the timeout if data is received last_output_time = Time.now if data if io == stdout_io @@ -134,12 +140,12 @@ def self.capture3_with_timeout( stderr += data unless stderr_to_stdout stdout += data if stderr_to_stdout end - rescue EOFError - # Remove the stream when EOF is reached - ios.delete(io) - rescue IO::WaitReadable - # Continue when IO is not ready yet - next + rescue EOFError + # Remove the stream when EOF is reached + ios.delete(io) + rescue IO::WaitReadable + # Continue when IO is not ready yet + next end end From d5083a92c62fdf25c1a93c904b8292e7ae34b16d Mon Sep 17 00:00:00 2001 From: Kamil Bukum Date: Tue, 17 Dec 2024 16:52:04 -0800 Subject: [PATCH 10/10] check the if the data is not empty then reset the timeout --- common/lib/dependabot/command_helpers.rb | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/common/lib/dependabot/command_helpers.rb b/common/lib/dependabot/command_helpers.rb index ecb5d71cdc..f10aeff67b 100644 --- a/common/lib/dependabot/command_helpers.rb +++ b/common/lib/dependabot/command_helpers.rb @@ -133,7 +133,9 @@ def self.capture3_with_timeout( data = data.encode("UTF-8", invalid: :replace, undef: :replace, replace: "?") # Reset the timeout if data is received - last_output_time = Time.now if data + last_output_time = Time.now unless data.empty? + + # 4. Append data to the appropriate stream if io == stdout_io stdout += data else