diff --git a/app/models/git_repository.rb b/app/models/git_repository.rb index 8ed59584b0..d18bf8df94 100644 --- a/app/models/git_repository.rb +++ b/app/models/git_repository.rb @@ -1,4 +1,7 @@ # frozen_string_literal: true + +require 'tempfile' + # Responsible for all git knowledge of a repo # Caches a local mirror (not a full checkout) and creates a workspace when deploying class GitRepository @@ -184,14 +187,17 @@ def instance_cache(key) # success: stdout as string # error: nil def capture_stdout(*command, dir: repo_cache_dir) - ::Rails.logger.info("Running command #{command}") - success, output, error = Samson::CommandExecutor.execute( - *command, - whitelist_env: ['HOME', 'PATH'], - timeout: 30.minutes, - dir: dir - ) - ::Rails.logger.error("Failed to run command #{command}: #{error}") unless success - output.strip if success + Tempfile.create('git-stderr') do |error_file| + Rails.logger.info("Running command #{command}") + success, output = Samson::CommandExecutor.execute( + *command, + whitelist_env: ['HOME', 'PATH'], + timeout: 30.minutes, + err: error_file.path, + dir: dir + ) + Rails.logger.error("Failed to run command #{command}: #{error_file.read}") unless success + output.strip if success + end end end diff --git a/lib/samson/command_executor.rb b/lib/samson/command_executor.rb index 8872a5f6a9..7a2146898e 100644 --- a/lib/samson/command_executor.rb +++ b/lib/samson/command_executor.rb @@ -1,7 +1,4 @@ # frozen_string_literal: true - -require 'tempfile' - module Samson # safe command execution that makes sure to use timeouts for everything and cleans up dead sub processes module CommandExecutor @@ -9,12 +6,11 @@ class << self # timeout could be done more reliably with timeout(1) from gnu coreutils ... but that would add another dependency # popen vs timeout http://stackoverflow.com/questions/17237743/timeout-within-a-popen-works-but-popen-inside-a-timeout-doesnt # TODO: stream output so we have a partial output when command times out - def execute(*command, timeout:, whitelist_env: [], env: {}, dir: nil) + def execute(*command, timeout:, whitelist_env: [], env: {}, err: [:child, :out], dir: nil) raise ArgumentError, "Positive timeout required" if timeout <= 0 env = ENV.to_h.slice(*whitelist_env).merge(env) pio = nil - stderr = Tempfile.new('stderr') - popen_options = {unsetenv_others: true, err: stderr} + popen_options = {unsetenv_others: true, err: err} popen_options[:chdir] = dir if dir ActiveSupport::Notifications.instrument("execute.command_executor.samson", script: command.shelljoin) do @@ -23,14 +19,14 @@ def execute(*command, timeout:, whitelist_env: [], env: {}, dir: nil) pio = IO.popen(env, command.map(&:to_s), popen_options) output = pio.read pio.close - [$?.success?, output, File.read(stderr)] + [$?.success?, output] rescue Errno::ENOENT - [false, "", "No such file or directory - #{command.first}"] + [false, "No such file or directory - #{command.first}"] end end end rescue Timeout::Error - [false, "", $!.message] + [false, $!.message] ensure if pio && !pio.closed? kill_process pio.pid diff --git a/plugins/gcloud/app/controllers/gcloud_controller.rb b/plugins/gcloud/app/controllers/gcloud_controller.rb index 44a25138c8..bf3ad97e15 100644 --- a/plugins/gcloud/app/controllers/gcloud_controller.rb +++ b/plugins/gcloud/app/controllers/gcloud_controller.rb @@ -27,8 +27,8 @@ def update_build(build) command = [ "gcloud", "container", "builds", "describe", build.gcr_id, "--format", "json", *SamsonGcloud.cli_options ] - success, output, error = Samson::CommandExecutor.execute(*command, timeout: 30, whitelist_env: ["PATH"]) - return "Failed to execute gcloud command: #{output} #{error}" unless success + success, output = Samson::CommandExecutor.execute(*command, timeout: 30, whitelist_env: ["PATH"]) + return "Failed to execute gcloud command: #{output}" unless success response = JSON.parse(output) build.external_status = STATUSMAP.fetch(response.fetch("status")) diff --git a/plugins/gcloud/app/controllers/gke_clusters_controller.rb b/plugins/gcloud/app/controllers/gke_clusters_controller.rb index 7b8f077c4a..5e0d5cea06 100644 --- a/plugins/gcloud/app/controllers/gke_clusters_controller.rb +++ b/plugins/gcloud/app/controllers/gke_clusters_controller.rb @@ -34,7 +34,7 @@ def create "gcloud", "container", "clusters", "get-credentials", "--zone", zone, cluster, *SamsonGcloud.cli_options(project: project) ] - success, content, error = Samson::CommandExecutor.execute( + success, content = Samson::CommandExecutor.execute( *command, whitelist_env: ["PATH"], timeout: 10, @@ -43,7 +43,7 @@ def create unless success flash.now[:alert] = "Failed to execute (make sure container.cluster.getCredentials permissions are granted): " \ - "#{command.join(" ")} #{content} #{error}" + "#{command.join(" ")} #{content}" return render :new end diff --git a/plugins/gcloud/lib/samson_gcloud/image_builder.rb b/plugins/gcloud/lib/samson_gcloud/image_builder.rb index f54087cab1..f5bea6ef2b 100644 --- a/plugins/gcloud/lib/samson_gcloud/image_builder.rb +++ b/plugins/gcloud/lib/samson_gcloud/image_builder.rb @@ -92,7 +92,7 @@ def image_exists_in_gcloud?(repo_digest) "gcloud", "container", "images", "list-tags", image, "--format", "get(digest)", "--filter", "digest=#{digest}", *SamsonGcloud.cli_options, timeout: 10 - ).second + ).last output.strip == digest end end diff --git a/plugins/gcloud/lib/samson_gcloud/tag_resolver.rb b/plugins/gcloud/lib/samson_gcloud/tag_resolver.rb index 53677e15c2..8c3c74ba81 100644 --- a/plugins/gcloud/lib/samson_gcloud/tag_resolver.rb +++ b/plugins/gcloud/lib/samson_gcloud/tag_resolver.rb @@ -10,14 +10,14 @@ def resolve_docker_image_tag(image) return unless SamsonGcloud.gcr? image return if image.match? Build::DIGEST_REGEX - success, json, error = Samson::CommandExecutor.execute( + success, json = Samson::CommandExecutor.execute( "gcloud", "container", "images", "describe", image, "--format", "json", *SamsonGcloud.cli_options, err: '/dev/null', timeout: 10, whitelist_env: ["PATH"] ) - raise "GCLOUD ERROR: unable to resolve #{image}\n#{error}" unless success + raise "GCLOUD ERROR: unable to resolve #{image}\n#{json}" unless success digest = JSON.parse(json).dig_fetch("image_summary", "digest") base = image.split(":", 2).first diff --git a/plugins/gcloud/test/controllers/gcloud_controller_test.rb b/plugins/gcloud/test/controllers/gcloud_controller_test.rb index b6f8591905..d9c3bd5772 100644 --- a/plugins/gcloud/test/controllers/gcloud_controller_test.rb +++ b/plugins/gcloud/test/controllers/gcloud_controller_test.rb @@ -30,7 +30,7 @@ def do_sync end it "can sync" do - Samson::CommandExecutor.expects(:execute).returns([true, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([true, result.to_json]) do_sync assert flash[:notice] build.reload @@ -40,13 +40,13 @@ def do_sync it "can sync images with a tag" do result[:results][:images][1][:name] += ":foo" - Samson::CommandExecutor.expects(:execute).returns([true, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([true, result.to_json]) do_sync build.reload.docker_repo_digest.must_equal repo_digest end it "fails when gcloud cli fails" do - Samson::CommandExecutor.expects(:execute).returns([false, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([false, result.to_json]) do_sync assert flash[:alert] end @@ -55,7 +55,7 @@ def do_sync let(:image_name) { "gcr.io/foo*baz+bing/#{build.image_name}" } it "fails when digest does not pass validations" do - Samson::CommandExecutor.expects(:execute).returns([true, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([true, result.to_json]) do_sync @@ -66,7 +66,7 @@ def do_sync it "fails when image is not found" do result[:results][:images].last[:name] = "gcr.io/other" - Samson::CommandExecutor.expects(:execute).returns([true, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([true, result.to_json]) do_sync @@ -77,7 +77,7 @@ def do_sync it "can store failures" do result[:status] = "QUEUED" result.delete(:results) - Samson::CommandExecutor.expects(:execute).returns([true, result.to_json, ""]) + Samson::CommandExecutor.expects(:execute).returns([true, result.to_json]) do_sync diff --git a/plugins/gcloud/test/controllers/gke_clusters_controller_test.rb b/plugins/gcloud/test/controllers/gke_clusters_controller_test.rb index 72b3a96016..14d0f78a30 100644 --- a/plugins/gcloud/test/controllers/gke_clusters_controller_test.rb +++ b/plugins/gcloud/test/controllers/gke_clusters_controller_test.rb @@ -38,7 +38,7 @@ def do_create(gcp_project: 'pp', cluster_name: 'cc', zone: 'zz') timeout: 10, env: {'KUBECONFIG' => expected_file, "CLOUDSDK_CONTAINER_USE_CLIENT_CERTIFICATE" => "True"}, whitelist_env: ['PATH'] - ).returns([true, "foo", ""]) + ).returns([true, "foo"]) do_create assert_redirected_to( "/kubernetes/clusters/new?kubernetes_cluster%5Bconfig_filepath%5D=#{CGI.escape(expected_file)}" @@ -48,7 +48,7 @@ def do_create(gcp_project: 'pp', cluster_name: 'cc', zone: 'zz') end it "shows errors when command fails" do - Samson::CommandExecutor.expects(:execute).returns([false, "foo", ""]) + Samson::CommandExecutor.expects(:execute).returns([false, "foo"]) do_create assert_response :success flash[:alert].must_include( diff --git a/plugins/gcloud/test/samson_gcloud/image_builder_test.rb b/plugins/gcloud/test/samson_gcloud/image_builder_test.rb index 487ef8eb20..9d783fcf86 100644 --- a/plugins/gcloud/test/samson_gcloud/image_builder_test.rb +++ b/plugins/gcloud/test/samson_gcloud/image_builder_test.rb @@ -46,7 +46,7 @@ def build_image(tag_as_latest: false, cache_from: nil) end it "can use cache" do - Samson::CommandExecutor.expects(:execute).returns([true, "sha256:abc\n", ""]) + Samson::CommandExecutor.expects(:execute).returns([true, "sha256:abc\n"]) old = 'gcr.io/something-old@sha256:abc' build_image(cache_from: old) File.read("some-dir/cloudbuild.yml").must_equal <<~YML @@ -63,7 +63,7 @@ def build_image(tag_as_latest: false, cache_from: nil) end it "does not use cache when image is not available" do - Samson::CommandExecutor.expects(:execute).returns([true, "\n", ""]) + Samson::CommandExecutor.expects(:execute).returns([true, "\n"]) build_image(cache_from: 'gcr.io/something-old') File.read("some-dir/cloudbuild.yml").must_equal <<~YML steps: diff --git a/plugins/gcloud/test/samson_gcloud/image_tagger_test.rb b/plugins/gcloud/test/samson_gcloud/image_tagger_test.rb index 14e5797db7..ff95df6204 100644 --- a/plugins/gcloud/test/samson_gcloud/image_tagger_test.rb +++ b/plugins/gcloud/test/samson_gcloud/image_tagger_test.rb @@ -16,7 +16,7 @@ def assert_tagged_with(tag, opts: []) Samson::CommandExecutor.expects(:execute).with( 'gcloud', 'container', 'images', 'add-tag', 'gcr.io/sdfsfsdf@some-sha', "gcr.io/sdfsfsdf:#{tag}", '--quiet', *opts, *auth_options, anything - ).returns([true, "OUT", ""]) + ).returns([true, "OUT"]) end with_env DOCKER_FEATURE: 'true', GCLOUD_PROJECT: '123', GCLOUD_ACCOUNT: 'acc' @@ -53,7 +53,7 @@ def assert_tagged_with(tag, opts: []) end it "tries again when tagging failed" do - Samson::CommandExecutor.expects(:execute).returns([false, 'x', ""]).times(2) + Samson::CommandExecutor.expects(:execute).returns([false, 'x']).times(2) 2.times { tag } end @@ -72,7 +72,7 @@ def assert_tagged_with(tag, opts: []) it "tags other regions" do build.update_column(:docker_repo_digest, 'asia.gcr.io/sdfsfsdf@some-sha') - Samson::CommandExecutor.expects(:execute).returns([true, "OUT", ""]) + Samson::CommandExecutor.expects(:execute).returns([true, "OUT"]) tag end @@ -89,7 +89,7 @@ def assert_tagged_with(tag, opts: []) end it "shows tagging errors" do - Samson::CommandExecutor.expects(:execute).returns([false, "NOPE", ""]) + Samson::CommandExecutor.expects(:execute).returns([false, "NOPE"]) tag output_serialized.must_include "NOPE" end diff --git a/plugins/gcloud/test/samson_gcloud/tag_resolver_test.rb b/plugins/gcloud/test/samson_gcloud/tag_resolver_test.rb index 3102ecb0c8..fc24c5ecd4 100644 --- a/plugins/gcloud/test/samson_gcloud/tag_resolver_test.rb +++ b/plugins/gcloud/test/samson_gcloud/tag_resolver_test.rb @@ -12,13 +12,13 @@ it "resolves latest" do Samson::CommandExecutor.expects(:execute). - returns([true, {image_summary: {digest: digest}}.to_json, ""]) + returns([true, {image_summary: {digest: digest}}.to_json]) SamsonGcloud::TagResolver.resolve_docker_image_tag(image).must_equal "#{image}@#{digest}" end it "resolves custom tag" do Samson::CommandExecutor.expects(:execute). - returns([true, {image_summary: {digest: digest}}.to_json, ""]) + returns([true, {image_summary: {digest: digest}}.to_json]) SamsonGcloud::TagResolver.resolve_docker_image_tag("#{image}:foo").must_equal "#{image}@#{digest}" end @@ -32,7 +32,7 @@ it "raises on gcloud error" do Samson::CommandExecutor.expects(:execute). - returns([false, "", ""]) + returns([false, ""]) assert_raises RuntimeError do SamsonGcloud::TagResolver.resolve_docker_image_tag(image) end diff --git a/test/lib/samson/command_executor_test.rb b/test/lib/samson/command_executor_test.rb index 4c52c984d8..c06f1e2bf2 100644 --- a/test/lib/samson/command_executor_test.rb +++ b/test/lib/samson/command_executor_test.rb @@ -6,11 +6,15 @@ describe Samson::CommandExecutor do describe "#execute" do it "runs" do - Samson::CommandExecutor.execute("echo", "hello", timeout: 1).must_equal [true, "hello\n", ""] + Samson::CommandExecutor.execute("echo", "hello", timeout: 1).must_equal [true, "hello\n"] end it "captures stderr" do - Samson::CommandExecutor.execute("sh", "-c", "echo hello 1>&2", timeout: 1).must_equal [true, "", "hello\n"] + Samson::CommandExecutor.execute("sh", "-c", "echo hello 1>&2", timeout: 1).must_equal [true, "hello\n"] + end + + it "can redirect stderr" do + Samson::CommandExecutor.execute("sh", "-c", "echo hello 1>&2", err: '/dev/null', timeout: 1).must_equal [true, ""] end it "runs in specified directory" do @@ -20,12 +24,11 @@ end it "fails nicely on missing exectable" do - Samson::CommandExecutor.execute("foo", "bar", timeout: 1). - must_equal [false, "", "No such file or directory - foo"] + Samson::CommandExecutor.execute("foo", "bar", timeout: 1).must_equal [false, "No such file or directory - foo"] end it "does not fail on nil commands" do - Samson::CommandExecutor.execute("echo", 1, nil, timeout: 1).must_equal [true, "1 \n", ""] + Samson::CommandExecutor.execute("echo", 1, nil, timeout: 1).must_equal [true, "1 \n"] end it "shows full backtrace when failing" do @@ -40,7 +43,7 @@ command = ["sleep", "15"] Samson::CommandExecutor.expects(:sleep) # waiting after kill ... no need to make this test slow time = Benchmark.realtime do - Samson::CommandExecutor.execute(*command, timeout: 0.1).must_equal [false, "", "execution expired"] + Samson::CommandExecutor.execute(*command, timeout: 0.1).must_equal [false, "execution expired"] end time.must_be :<, 0.2 `ps -ef`.wont_include(command.join(" ")) @@ -48,7 +51,7 @@ it "does not fail when pid was already gone" do Process.expects(:kill).raises(Errno::ESRCH) # simulate that pid was gone and kill failed - Samson::CommandExecutor.execute("sleep", "0.2", timeout: 0.1).must_equal [false, "", "execution expired"] + Samson::CommandExecutor.execute("sleep", "0.2", timeout: 0.1).must_equal [false, "execution expired"] sleep 0.2 # do not leave process thread hanging end @@ -56,7 +59,7 @@ Samson::CommandExecutor.expects(:sleep) # waiting after kill ... we ignore it in this test Process.expects(:kill).twice # simulate that process could not be killed with :KILL time = Benchmark.realtime do - Samson::CommandExecutor.execute("sleep", "0.5", timeout: 0.1).must_equal [false, "", "execution expired"] + Samson::CommandExecutor.execute("sleep", "0.5", timeout: 0.1).must_equal [false, "execution expired"] end time.must_be :>, 0.5 end @@ -68,24 +71,23 @@ end it "does not allow injection" do - Samson::CommandExecutor.execute("echo", "hel << lo | ;", timeout: 1).must_equal [true, "hel << lo | ;\n", ""] + Samson::CommandExecutor.execute("echo", "hel << lo | ;", timeout: 1).must_equal [true, "hel << lo | ;\n"] end it "does not allow env access" do with_env FOO: 'bar' do - Samson::CommandExecutor.execute("printenv", "FOO", timeout: 1).must_equal [false, "", ""] + Samson::CommandExecutor.execute("printenv", "FOO", timeout: 1).must_equal [false, ""] end end it "can set env" do - Samson::CommandExecutor.execute("printenv", "FOO", timeout: 1, env: {"FOO" => "baz"}). - must_equal [true, "baz\n", ""] + Samson::CommandExecutor.execute("printenv", "FOO", timeout: 1, env: {"FOO" => "baz"}).must_equal [true, "baz\n"] end it "allows whitelisted env access" do with_env FOO: 'bar' do Samson::CommandExecutor.execute("printenv", "FOO", timeout: 1, whitelist_env: ["FOO"]). - must_equal [true, "bar\n", ""] + must_equal [true, "bar\n"] end end end diff --git a/test/models/git_repository_test.rb b/test/models/git_repository_test.rb index f48d829e03..533b7ce4a0 100644 --- a/test/models/git_repository_test.rb +++ b/test/models/git_repository_test.rb @@ -101,6 +101,12 @@ def call repository.commit_from_ref('NOT A VALID REF').must_be_nil end + it 'logs an error if ref does not exist' do + create_repo_with_tags + Rails.logger.expects(:error).with { |message| message.must_match(/^Failed to run command/) } + repository.commit_from_ref('NOT A VALID REF') + end + it 'returns the commit of a branch' do create_repo_with_an_additional_branch('my_branch') repository.commit_from_ref('my_branch').must_match /^[0-9a-f]{40}$/ @@ -310,12 +316,12 @@ def call end it "caches" do - Samson::CommandExecutor.expects(:execute).times(2).returns([true, "x", ""]) + Samson::CommandExecutor.expects(:execute).times(2).returns([true, "x"]) 4.times { repository.file_content('foo', sha).must_equal "x" } end it "caches sha too" do - Samson::CommandExecutor.expects(:execute).times(3).returns([true, "x", ""]) + Samson::CommandExecutor.expects(:execute).times(3).returns([true, "x"]) 4.times { |i| repository.file_content("foo-#{i.odd?}", sha).must_equal "x" } end @@ -344,7 +350,7 @@ def call it "does not cache when requesting for an update" do repository.unstub(:ensure_mirror_current) repository.expects(:ensure_mirror_current) - Samson::CommandExecutor.expects(:execute).times(2).returns([true, "x", ""]) + Samson::CommandExecutor.expects(:execute).times(2).returns([true, "x"]) repository.file_content('foo', 'HEAD', pull: false).must_equal "x" 4.times { repository.file_content('foo', 'HEAD', pull: true).must_equal "x" } end