Return error output when git commands fail

app/models/git_repository.rb

@@ -183,13 +183,15 @@ def instance_cache(key)
   # success: stdout as string
   # error: nil
   def capture_stdout(*command, dir: repo_cache_dir)
-    success, output = Samson::CommandExecutor.execute(
+    result = Samson::CommandExecutor.execute(
       *command,
       whitelist_env: ['HOME', 'PATH'],
       timeout: 30.minutes,
-      err: '/dev/null',
       dir: dir
     )
-    output.strip if success
+    unless result[:status]
+      ::Rails.logger.error("Failed to run command #{command}: #{result[:error]}")
+    end
+    result[:output].strip if result[:status]
   end
 end

app/models/release_service.rb

@@ -32,6 +32,9 @@ def ensure_tag_in_git_repository(tag)
       @project.repository.update_mirror
       @project.repository.commit_from_ref(tag)
     end
+  rescue RuntimeError
+    ::Rails.logger.error("Failed ensuring git repository #{@project.repository.executor.output.string}")
+    raise
   end
 
   def start_deploys(release)

lib/samson/command_executor.rb

@@ -1,16 +1,19 @@
 # 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
     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: {}, err: [:child, :out], dir: nil)
+      def execute(*command, timeout:, whitelist_env: [], env: {}, dir: nil)
         raise ArgumentError, "Positive timeout required" if timeout <= 0
         env = ENV.to_h.slice(*whitelist_env).merge(env)
         pio = nil
-        popen_options = {unsetenv_others: true, err: err}
+        stderr = Tempfile.new('stderr')
+        popen_options = {unsetenv_others: true, err: stderr}
         popen_options[:chdir] = dir if dir
 
         ActiveSupport::Notifications.instrument("execute.command_executor.samson", script: command.shelljoin) do
@@ -19,14 +22,26 @@ def execute(*command, timeout:, whitelist_env: [], env: {}, err: [:child, :out],
               pio = IO.popen(env, command.map(&:to_s), popen_options)
               output = pio.read
               pio.close
-              [$?.success?, output]
+              {
+                output: output,
+                error: File.read(stderr),
+                status: $?.success?
+              }
             rescue Errno::ENOENT
-              [false, "No such file or directory - #{command.first}"]
+              {
+                error: "No such file or directory - #{command.first}",
+                status: false,
+                output: ""
+              }
             end
           end
         end
       rescue Timeout::Error
-        [false, $!.message]
+        {
+          error: $!.message,
+          status: false,
+          output: ""
+        }
       ensure
         if pio && !pio.closed?
           kill_process pio.pid

plugins/gcloud/app/controllers/gcloud_controller.rb

@@ -27,10 +27,10 @@ def update_build(build)
     command = [
       "gcloud", "container", "builds", "describe", build.gcr_id, "--format", "json", *SamsonGcloud.cli_options
     ]
-    success, output = Samson::CommandExecutor.execute(*command, timeout: 30, whitelist_env: ["PATH"])
-    return "Failed to execute gcloud command: #{output}" unless success
+    result = Samson::CommandExecutor.execute(*command, timeout: 30, whitelist_env: ["PATH"])
+    return "Failed to execute gcloud command: #{result[:output]}" unless result[:status]
 
-    response = JSON.parse(output)
+    response = JSON.parse(result[:output])
     build.external_status = STATUSMAP.fetch(response.fetch("status"))
 
     if build.external_status == "succeeded"

plugins/gcloud/app/controllers/gke_clusters_controller.rb

@@ -34,16 +34,16 @@ def create
       "gcloud", "container", "clusters", "get-credentials", "--zone", zone, cluster,
       *SamsonGcloud.cli_options(project: project)
     ]
-    success, content = Samson::CommandExecutor.execute(
+    result = Samson::CommandExecutor.execute(
       *command,
       whitelist_env: ["PATH"],
       timeout: 10,
       env: {"KUBECONFIG" => path, "CLOUDSDK_CONTAINER_USE_CLIENT_CERTIFICATE" => "True"}
     )
 
-    unless success
+    unless result[:status]
       flash.now[:alert] = "Failed to execute (make sure container.cluster.getCredentials permissions are granted): " \
-        "#{command.join(" ")} #{content}"
+        "#{command.join(" ")} #{result[:output]}"
       return render :new
     end
 

plugins/gcloud/lib/samson_gcloud/image_builder.rb

@@ -88,12 +88,12 @@ def prevent_upload_of_ignored_files(dir, build)
       # NOTE: not using executor since it does not return output
       def image_exists_in_gcloud?(repo_digest)
         image, digest = repo_digest.split('@')
-        output = Samson::CommandExecutor.execute(
+        result = Samson::CommandExecutor.execute(
           "gcloud", "container", "images", "list-tags", image,
           "--format", "get(digest)", "--filter", "digest=#{digest}", *SamsonGcloud.cli_options,
           timeout: 10
-        ).last
-        output.strip == digest
+        )
+        result[:output].strip == digest
       end
     end
   end

plugins/gcloud/lib/samson_gcloud/image_tagger.rb

@@ -33,14 +33,14 @@ def tag_image(tag, base, digest, job_output)
         command = [
           "gcloud", "container", "images", "add-tag", digest, "#{base}:#{tag}", "--quiet", *SamsonGcloud.cli_options
         ]
-        success, output = Samson::CommandExecutor.execute(*command, timeout: 10, whitelist_env: ["PATH"])
+        result = Samson::CommandExecutor.execute(*command, timeout: 10, whitelist_env: ["PATH"])
         job_output.write <<~TEXT
           #{Samson::OutputUtils.timestamp} Tagging GCR image:
           #{command.join(" ")}
-          #{output.strip}
+          #{result[:output].strip}
         TEXT
-        job_output.puts "FAILED" unless success
-        success
+        job_output.puts "FAILED" unless result[:status]
+        result[:status]
       end
 
       def cache_last_tagged(key, value)

plugins/gcloud/lib/samson_gcloud/tag_resolver.rb

@@ -10,15 +10,14 @@ def resolve_docker_image_tag(image)
         return unless SamsonGcloud.gcr? image
         return if image.match? Build::DIGEST_REGEX
 
-        success, json = Samson::CommandExecutor.execute(
+        result = 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#{json}" unless success
-        digest = JSON.parse(json).dig_fetch("image_summary", "digest")
+        raise "GCLOUD ERROR: unable to resolve #{image}\n#{result[:error]}" unless result[:status]
+        digest = JSON.parse(result[:output]).dig_fetch("image_summary", "digest")
 
         base = image.split(":", 2).first
         "#{base}@#{digest}"

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(status: true, output: 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(status: true, output: 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(status: false, output: 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(status: true, output: 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(status: true, output: 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(status: true, output: result.to_json)
 
         do_sync
 

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(status: true, output: "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(status: false, output: "foo")
         do_create
         assert_response :success
         flash[:alert].must_include(

plugins/gcloud/test/samson_gcloud/image_builder_test.rb

@@ -43,7 +43,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(status: true, output: "sha256:abc\n")
       old = 'gcr.io/something-old@sha256:abc'
       build_image(cache_from: old)
       File.read("some-dir/cloudbuild.yml").must_equal <<~YML
@@ -60,7 +60,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(status: true, output: "\n")
       build_image(cache_from: 'gcr.io/something-old')
       File.read("some-dir/cloudbuild.yml").must_equal <<~YML
         steps:

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(status: true, output: "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(status: false, output: '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(status: true, output: "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(status: false, output: "NOPE")
       tag
       output_serialized.must_include "NOPE"
     end

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(status: true, output: {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(status: true, output: {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(status: false, output: "")
       assert_raises RuntimeError do
         SamsonGcloud::TagResolver.resolve_docker_image_tag(image)
       end