Fix stderror not being captured in processed exec and max retries (#26)

* Verbose echo if bugsnag isn't enabled

* Log issue count

* Spotless

* Add a debug flag

* Print the full path to logs

* undo

Not necessary

* Add no-exit for debugging in tests

* Add a stderr test

* Fix message not being optional

* Undo

* Cap attempts

* Spotless

* Opportunistic fix toStrings

* Detekt

* Upload failure reports

* What about... this?

* Spotless

* Silence slf4j

* Restore

* Test stderr on CI

* Remove

* Try macos

* Explanatory comment

Author: ZacSweers

.github/workflows/ci.yml

@@ -13,7 +13,8 @@ on:
 
 jobs:
   build:
-    runs-on: 'ubuntu-latest'
+    # Necessary for ResultProcessorTest.testExecuteCommandWithStderr
+    runs-on: 'macos-latest'
     steps:
       - name: Checkout
         uses: actions/checkout@v3
@@ -32,6 +33,14 @@ jobs:
         with:
           arguments: check
 
+      - name: (Fail-only) Upload build reports
+        if: failure()
+        uses: actions/upload-artifact@v3
+        with:
+          name: reports
+          path: |
+            **/build/reports/**
+
       - name: Upload snapshot (main only)
         env:
           ORG_GRADLE_PROJECT_mavenCentralUsername: ${{ secrets.SonatypeUsername }}

build.gradle.kts

@@ -96,6 +96,8 @@ dependencies {
   implementation(libs.bugsnag)
   implementation(libs.moshi)
   implementation(libs.kotlin.reflect)
+  // To silence this stupid log https://www.slf4j.org/codes.html#StaticLoggerBinder
+  implementation(libs.slf4jNop)
   testImplementation(libs.junit)
   testImplementation(libs.truth)
 }

gradle/libs.versions.toml

@@ -23,5 +23,6 @@ kotlin-reflect = { module = "org.jetbrains.kotlin:kotlin-reflect", version.ref =
 moshi = { module = "com.squareup.moshi:moshi", version.ref = "moshi" }
 okhttp = "com.squareup.okhttp3:okhttp:4.11.0"
 okio = "com.squareup.okio:okio:3.3.0"
+slf4jNop = "org.slf4j:slf4j-nop:2.0.7"
 junit = "junit:junit:4.13.2"
 truth = "com.google.truth:truth:1.1.5"

src/main/kotlin/slack/cli/exec/ProcessedExecCli.kt

@@ -52,10 +52,20 @@ public class ProcessedExecCli :
     option("--config", envvar = "PE_CONFIGURATION_FILE")
       .path(mustExist = true, canBeFile = true, canBeDir = false)
 
+  private val debug by option("--debug", "-d").flag()
+
+  @get:TestOnly
+  private val noExit by
+    option(
+        "--no-exit",
+        help = "Instructs this CLI to not exit the process with the status code. Test only!"
+      )
+      .flag()
   @get:TestOnly internal val parseOnly by option("--parse-only").flag(default = false)
 
   internal val args by argument().multiple()
 
+  @Suppress("CyclomaticComplexMethod")
   @OptIn(ExperimentalStdlibApi::class, ExperimentalPathApi::class)
   override fun run() {
     if (parseOnly) return
@@ -76,8 +86,12 @@ public class ProcessedExecCli :
 
     // Initial command execution
     val (exitCode, logFile) = executeCommand(cmd, tmpDir)
-    while (exitCode != 0) {
-      echo("Command failed with exit code $exitCode. Running processor script...")
+    var attempts = 0
+    while (exitCode != 0 && attempts < 1) {
+      attempts++
+      echo(
+        "Command failed with exit code $exitCode. Running processor script (attempt $attempts)..."
+      )
 
       echo("Processing CI failure")
       val resultProcessor = ResultProcessor(verbose, bugsnagKey, config, ::echo)
@@ -114,8 +128,14 @@ public class ProcessedExecCli :
 
     // If we got here, all is well
     // Delete the tmp files
-    tmpDir.deleteRecursively()
-    exitProcess(exitCode)
+    if (!debug) {
+      tmpDir.deleteRecursively()
+    }
+
+    echo("Exiting with code $exitCode")
+    if (!noExit) {
+      exitProcess(exitCode)
+    }
   }
 
   // Function to execute command and capture output. Shorthand to the testable top-level function.
@@ -148,7 +168,7 @@ internal fun executeCommand(
         // Pass the line through unmodified
         line to ""
       }
-      val process = command.process()
+      val process = command.process() forkErr { it pipe echoHandler pipe tmpFile.toFile() }
       pipeline { process pipe echoHandler pipe tmpFile.toFile() }.join()
       exitCode = process.process.pcb.exitCode
     }

src/main/kotlin/slack/cli/exec/ResultProcessor.kt

@@ -54,14 +54,15 @@ internal class ResultProcessor(
     val bugsnag: Bugsnag? by lazy { bugsnagKey?.let { key -> createBugsnag(key) } }
 
     val logLinesReversed = logFile.readLines().asReversed()
+    echo("Checking ${config.knownIssues.size} known issues")
     for (issue in config.knownIssues) {
       val retrySignal = issue.check(logLinesReversed, echo)
 
       if (retrySignal != RetrySignal.Unknown) {
         // Report to bugsnag. Shared common Throwable but with different messages.
-        bugsnag?.apply {
+        bugsnag?.let {
           verboseEcho("Reporting to bugsnag: $retrySignal")
-          notify(IssueThrowable(issue), Severity.ERROR) { report ->
+          it.notify(IssueThrowable(issue), Severity.ERROR) { report ->
             // Group by the throwable message
             report.setGroupingHash(issue.groupingHash)
             report.addToTab("Run Info", "After-Retry", isAfterRetry)
@@ -70,6 +71,7 @@ internal class ResultProcessor(
             }
           }
         }
+          ?: run { verboseEcho("Skipping bugsnag reporting: $retrySignal") }
 
         if (retrySignal is RetrySignal.Ack) {
           echo("Recognized known issue but cannot retry: ${issue.message}")

src/main/kotlin/slack/cli/exec/RetrySignal.kt

@@ -23,13 +23,25 @@ import kotlin.time.Duration
 internal sealed interface RetrySignal {
 
   /** Unknown issue. */
-  @TypeLabel("unknown") object Unknown : RetrySignal
+  @TypeLabel("unknown")
+  object Unknown : RetrySignal {
+    // TODO remove when we have data objects in Kotlin 1.9
+    override fun toString() = this::class.simpleName!!
+  }
 
   /** Indicates an issue that is recognized but cannot be retried. */
-  @TypeLabel("ack") object Ack : RetrySignal
+  @TypeLabel("ack")
+  object Ack : RetrySignal {
+    // TODO remove when we have data objects in Kotlin 1.9
+    override fun toString() = this::class.simpleName!!
+  }
 
   /** Indicates this issue should be retried immediately. */
-  @TypeLabel("immediate") object RetryImmediately : RetrySignal
+  @TypeLabel("immediate")
+  object RetryImmediately : RetrySignal {
+    // TODO remove when we have data objects in Kotlin 1.9
+    override fun toString() = this::class.simpleName!!
+  }
 
   /** Indicates this issue should be retried after a [delay]. */
   @TypeLabel("delayed")

src/test/kotlin/slack/cli/exec/ResultProcessorTest.kt

@@ -48,6 +48,38 @@ class ResultProcessorTest {
     assertThat(logs.joinToString("\n").trim()).contains(expectedOutput)
   }
 
+  @Test
+  fun testExecuteCommandWithStderr() {
+    val script =
+      """
+      #!/bin/bash
+
+      >&2 echo "Error text"
+    """
+        .trimIndent()
+    val scriptFile =
+      tmpFolder.newFile("script.sh").apply {
+        writeText(script)
+        setExecutable(true)
+      }
+    tmpFolder.newFile("test.txt")
+    val tmpDir = tmpFolder.newFolder("tmp/processed_exec")
+    val (exitCode, outputFile) =
+      executeCommand(tmpFolder.root.toPath(), scriptFile.absolutePath, tmpDir.toPath(), logs::add)
+    assertThat(exitCode).isEqualTo(0)
+
+    val expectedOutput =
+      """
+      Error text
+    """
+        .trimIndent()
+
+    assertThat(outputFile.readText().trim()).isEqualTo(expectedOutput)
+
+    // Note we use "contains" here because our script may output additional logs
+    assertThat(logs.joinToString("\n").trim()).contains(expectedOutput)
+  }
+
   @Test
   fun unknownIssue() {
     val outputFile = tmpFolder.newFile("logs.txt")