Fix job logs and the truncated flag, release 1.0.1

README.md

@@ -40,6 +40,7 @@ else's review — is behind a checkbox that is off by default. See
 
 ## Documentation
 
+- [Handleiding](documentation/handleiding.md) — Dutch, for administrators and process designers: setting it up in the admin UI, no technical background needed
 - [Getting started](documentation/getting-started.md) — running the sandbox and its fixtures, and developing on it
 - [Plugin documentation](documentation/plugin.md) — the actions, their properties and what they return
 - [Release notes](documentation/release-notes.md) — version history

backend/plugin/plugin.properties

@@ -1,3 +1,3 @@
 pluginGroupId=com.ritense.valtimoplugins
 pluginArtifactId=github
-pluginVersion=1.0.0
+pluginVersion=1.0.1

backend/plugin/src/main/kotlin/com/ritense/valtimoplugins/github/client/GitHubClient.kt

@@ -151,10 +151,19 @@ class GitHubClient(
             }
 
             pages++
+            next = nextLink(response.headers)
             if (limit != null && items.size() >= limit) {
-                return PagedResult(trim(items, limit), truncated = true, totalCount = totalCount)
+                return PagedResult(
+                    items = trim(items, limit),
+                    // Only truncated when something was actually left behind: either this
+                    // page held more than was asked for, or GitHub offered another one. A
+                    // list that happens to be exactly [limit] long was not cut short, and
+                    // saying it was sends a process down the "there is more to do" branch
+                    // on every run.
+                    truncated = items.size() > limit || next != null,
+                    totalCount = totalCount,
+                )
             }
-            next = nextLink(response.headers)
         }
 
         return PagedResult(
@@ -164,6 +173,43 @@ class GitHubClient(
         )
     }
 
+    /**
+     * Reads an endpoint that answers with plain text, following the redirect to storage that
+     * GitHub serves an Actions job log through.
+     *
+     * The redirect is followed by hand rather than by the http client, because the target is
+     * a pre-signed URL on a host that is not GitHub — Azure blob storage — and a client
+     * configured to follow redirects would carry the `Authorization` header there with it.
+     * The signature is what authorises that second call; the token would only be a GitHub
+     * credential handed to a third party that never needed it.
+     *
+     * Null when GitHub answered with neither a body nor somewhere to fetch one from, which
+     * is what an expired log looks like. Callers are expected to say so rather than pass an
+     * empty log off as a log that was read.
+     */
+    fun getText(
+        connection: GitHubConnectionProperties,
+        path: String,
+    ): String? {
+        val response = exchange(connection, HttpMethod.GET, uri(connection, path), null)
+        val location = response.headers.location
+        if (response.status in REDIRECTED && location != null) {
+            return restClientBuilder
+                .clone()
+                .build()
+                .get()
+                .uri(location)
+                .headers { it.set(HttpHeaders.USER_AGENT, USER_AGENT) }
+                .retrieve()
+                .body(String::class.java)
+                ?.takeIf { it.isNotEmpty() }
+        }
+        // The raw bytes rather than the parsed body: a log is text, and a log whose first
+        // line happens to parse as JSON — a bare timestamp does — would come back through
+        // the tree as that one value with the rest of the log dropped.
+        return String(response.raw, Charsets.UTF_8).takeIf { it.isNotEmpty() }
+    }
+
     /**
      * Runs a GraphQL document.
      *
@@ -233,10 +279,10 @@ class GitHubClient(
                             status = response.statusCode.value(),
                         )
                     }
-                    Response(parsed, response.headers)
+                    Response(response.statusCode.value(), parsed, raw, response.headers)
                 }, false)
 
-        return entity ?: Response(NullNode.instance, HttpHeaders.EMPTY)
+        return entity ?: Response(0, NullNode.instance, ByteArray(0), HttpHeaders.EMPTY)
     }
 
     /**
@@ -308,8 +354,14 @@ class GitHubClient(
             objectMapper.createArrayNode().apply { (0 until limit).forEach { add(items.get(it)) } }
         }
 
-    private data class Response(
+    /**
+     * Not a data class: [raw] holds the bytes [body] was parsed from, and an array makes
+     * generated equality mean something other than it reads as.
+     */
+    private class Response(
+        val status: Int,
         val body: JsonNode,
+        val raw: ByteArray,
         val headers: HttpHeaders,
     )
 
@@ -338,5 +390,8 @@ class GitHubClient(
         private const val API_VERSION = "2022-11-28"
         private const val USER_AGENT = "valtimo-github-plugin"
         private const val MAX_ERROR_LENGTH = 1000
+
+        /** The statuses [getText] treats as "the body is somewhere else". */
+        private val REDIRECTED = setOf(301, 302, 303, 307, 308)
     }
 }

backend/plugin/src/main/kotlin/com/ritense/valtimoplugins/github/service/GitHubOperations.kt

@@ -778,28 +778,29 @@ class GitHubOperations(
      * The log of one job, tail-first.
      *
      * GitHub answers this endpoint with a redirect to blob storage and plain text rather
-     * than JSON, so the body arrives as a string. [maxLines] keeps the tail — a failing job
-     * says why it failed at the end, and the beginning is several thousand lines of setup
-     * that would fill a process variable with nothing.
+     * than JSON, which is why it goes through [GitHubClient.getText] rather than the JSON
+     * calls every other action uses. [maxLines] keeps the tail — a failing job says why it
+     * failed at the end, and the beginning is several thousand lines of setup that would
+     * fill a process variable with nothing.
+     *
+     * A log GitHub would not hand over — an expired run, a job still starting — reports
+     * `available` false with the reason, rather than an empty log that a process would read
+     * as a job that said nothing.
      */
     fun getJobLogs(
         connection: GitHubConnectionProperties,
         repository: RepositoryRef,
         jobId: Long,
         maxLines: Int,
     ): ObjectNode {
-        val response =
-            runCatching { client.get(connection, "/repos/$repository/actions/jobs/$jobId/logs") }
+        val text =
+            runCatching { client.getText(connection, "/repos/$repository/actions/jobs/$jobId/logs") }
                 .getOrElse { failure ->
                     logger.warn(failure) { "Could not read logs of job $jobId in $repository" }
-                    return obj {
-                        put("jobId", jobId)
-                        put("available", false)
-                        put("reason", failure.message)
-                    }
+                    return unavailable(jobId, failure.message)
                 }
+                ?: return unavailable(jobId, "GitHub returned no log for job $jobId")
 
-        val text = if (response.isTextual) response.asText() else response.toString()
         val lines = text.lines()
         val tail = if (lines.size > maxLines) lines.takeLast(maxLines) else lines
 
@@ -1110,6 +1111,16 @@ class GitHubOperations(
 
     // ─── helpers ────────────────────────────────────────────────────────────
 
+    private fun unavailable(
+        jobId: Long,
+        reason: String?,
+    ): ObjectNode =
+        obj {
+            put("jobId", jobId)
+            put("available", false)
+            put("reason", reason)
+        }
+
     private fun defaultBranch(
         connection: GitHubConnectionProperties,
         repository: RepositoryRef,

backend/plugin/src/test/kotlin/com/ritense/valtimoplugins/github/client/GitHubClientTest.kt

@@ -95,6 +95,73 @@ class GitHubClientTest : BaseTest() {
         assertThat(result.truncated).isTrue()
     }
 
+    /**
+     * A list that happens to be exactly as long as the limit was not cut short. Reporting it
+     * as truncated sends a process down the "there is more to do" branch on every run.
+     */
+    @Test
+    fun `should not call a list truncated when it ended exactly on the limit`() {
+        enqueue("""[{"number":1},{"number":2}]""")
+
+        val result = client.getPaged(connection(), "/repos/o/r/issues", limit = 2)
+
+        assertThat(result.items).hasSize(2)
+        assertThat(result.truncated).isFalse()
+    }
+
+    @Test
+    fun `should call a list that ended on the limit truncated when github offered another page`() {
+        enqueuePage("""[{"number":1},{"number":2}]""", next = "/repos/o/r/issues?page=2")
+
+        val result = client.getPaged(connection(), "/repos/o/r/issues", limit = 2)
+
+        assertThat(result.items).hasSize(2)
+        assertThat(result.truncated).isTrue()
+    }
+
+    /**
+     * An Actions job log is not JSON: GitHub answers 302 to a pre-signed blob URL. Following
+     * it is the only way to get the log at all — without it the body is empty and a caller
+     * cannot tell that from a job that logged nothing.
+     */
+    @Test
+    fun `should follow the redirect github serves a job log through`() {
+        val blob = MockWebServer()
+        blob.start()
+        blob.enqueue(MockResponse().setHeader("Content-Type", "text/plain").setBody("setup\nBUILD FAILED"))
+        server.enqueue(MockResponse().setResponseCode(302).setHeader("Location", blob.url("/log.txt").toString()))
+
+        val text = client.getText(connection(), "/repos/o/r/actions/jobs/1/logs")
+
+        assertThat(text).isEqualTo("setup\nBUILD FAILED")
+        blob.shutdown()
+    }
+
+    /**
+     * The signature on the blob URL is what authorises the second call. Carrying the GitHub
+     * token to a host that is not GitHub would hand a credential to a third party that never
+     * needed it.
+     */
+    @Test
+    fun `should not carry the github token to the storage host it is redirected to`() {
+        val blob = MockWebServer()
+        blob.start()
+        blob.enqueue(MockResponse().setHeader("Content-Type", "text/plain").setBody("log"))
+        server.enqueue(MockResponse().setResponseCode(302).setHeader("Location", blob.url("/log.txt").toString()))
+
+        client.getText(connection(), "/repos/o/r/actions/jobs/1/logs")
+
+        assertThat(blob.takeRequest().getHeader("Authorization")).isNull()
+        blob.shutdown()
+    }
+
+    @Test
+    fun `should report no log rather than an empty one when github offers nothing to fetch`() {
+        server.enqueue(MockResponse().setResponseCode(204))
+
+        assertThat(client.getText(connection(), "/repos/o/r/actions/jobs/1/logs")).isNull()
+    }
+
     @Test
     fun `should unwrap a search response and keep what github said the total was`() {
         enqueue("""{"total_count":1337,"incomplete_results":false,"items":[{"number":7}]}""")

backend/plugin/src/test/kotlin/com/ritense/valtimoplugins/github/service/GitHubOperationsTest.kt

@@ -392,6 +392,47 @@ class GitHubOperationsTest : BaseTest() {
         ).isFalse()
     }
 
+    // ─── job logs ───────────────────────────────────────────────────────────
+
+    @Test
+    fun `should keep the tail of a job log, which is where a failing job says why`() {
+        whenever(client.getText(any(), eq("/repos/$repository/actions/jobs/7/logs")))
+            .thenReturn("setup\ncompile\ntest\nBUILD FAILED")
+
+        val result = operations.getJobLogs(connection, repository, 7, maxLines = 2)
+
+        assertThat(result.path("available").asBoolean()).isTrue()
+        assertThat(result.path("log").asText()).isEqualTo("test\nBUILD FAILED")
+        assertThat(result.path("truncated").asBoolean()).isTrue()
+        assertThat(result.path("totalLines").asInt()).isEqualTo(4)
+    }
+
+    /**
+     * An expired run has no log to hand over. Saying `available` false is the difference
+     * between a process reporting that it could not read the log and one reporting that the
+     * job failed silently.
+     */
+    @Test
+    fun `should say a log was not available rather than hand back an empty one`() {
+        whenever(client.getText(any(), eq("/repos/$repository/actions/jobs/7/logs"))).thenReturn(null)
+
+        val result = operations.getJobLogs(connection, repository, 7, maxLines = 200)
+
+        assertThat(result.path("available").asBoolean()).isFalse()
+        assertThat(result.has("log")).isFalse()
+    }
+
+    @Test
+    fun `should say why a log could not be read when github refused it`() {
+        whenever(client.getText(any(), eq("/repos/$repository/actions/jobs/7/logs")))
+            .thenThrow(GitHubException("Not Found", status = 404))
+
+        val result = operations.getJobLogs(connection, repository, 7, maxLines = 200)
+
+        assertThat(result.path("available").asBoolean()).isFalse()
+        assertThat(result.path("reason").asText()).contains("Not Found")
+    }
+
     // ─── branches ───────────────────────────────────────────────────────────
 
     @Test