Add notebook logging example (#477)

Follow up to changes of #476. Related to #332.

Author: gabrielfeo

docs/Logging.md

@@ -14,15 +14,17 @@ This library uses [SLF4J][1] but does not bundle an SLF4J implementation.
 
 Logs appear in the Kotlin Jupyter kernel logs:
 
-- In IntelliJ, view logs in the Kotlin Notebook logs tool window
 - In Jupyter and JupyterLab, logs appear in the shell that owns the Jupyter process
+- In IntelliJ, view logs in the Kotlin Notebook logs tool window
 
 ![IntelliJ Kotlin Notebook logs tool window](media/IntelliJKernelLogs.png)
 
 ⚠️ Older versions of the Kotlin Jupyter kernel had issues with logging. Kernel version `0.15.0-598` and higher are known to work. In IntelliJ, configure to use a later version than bundled. In pip and conda, update the kernel package.
 
 ![IntelliJ Kotlin Jupyter kernel version configuration](media/IntelliJKernelSettings.png)
 
+See the example notebook [Logging.ipynb](../examples/example-notebooks/Logging.ipynb).
+
 ## Scripts
 
 1. Add an SLF4J implementation (e.g., `slf4j-simple`, `logback-classic`, etc.)

examples/example-notebooks/Logging.ipynb

@@ -0,0 +1,79 @@
+{
+ "cells": [
+  {
+   "metadata": {},
+   "cell_type": "code",
+   "outputs": [],
+   "execution_count": null,
+   "source": [
+    "%useLatestDescriptors\n",
+    "%use develocity-api-kotlin(version=2024.3.0)\n",
+    "%use coroutines(v=1.7.1)\n",
+    "\n",
+    "val api = DevelocityApi.newInstance(config = Config(cacheConfig = Config.CacheConfig(cacheEnabled = false)))"
+   ]
+  },
+  {
+   "metadata": {},
+   "cell_type": "code",
+   "outputs": [],
+   "execution_count": null,
+   "source": [
+    "%logLevel debug\n",
+    "\n",
+    "runBlocking {\n",
+    "    api.buildsApi.getBuildsFlow(\n",
+    "        fromInstant = 0,\n",
+    "        query = \"\"\"buildStartTime>-7d buildTool:gradle\"\"\",\n",
+    "    ).last()\n",
+    "}"
+   ]
+  },
+  {
+   "metadata": {},
+   "cell_type": "markdown",
+   "source": [
+    "Expect logs such as these in kernel logs. See [docs/Logging.md][1] for more details.\n",
+    "\n",
+    "##### Cache hits\n",
+    "\n",
+    "```\n",
+    "3764 [Execution of code '%logLevel debug...'] DEBUG c.gabrielfeo.develocity.api.Cache - HTTP cache dir: /Users/gfeo/.develocity-api-kotlin-cache (max 1000000000B)\n",
+    "4053 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.gabrielfeo.develocity.api.Cache - Cache hit: https://ge.solutions-team.gradle.com/api/builds?fromInstant=0&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false\n",
+    "4072 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.gabrielfeo.develocity.api.Cache - Cache hit: https://ge.solutions-team.gradle.com/api/builds?fromBuild=qcku2w347d5dy&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false\n",
+    "4072 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.gabrielfeo.develocity.api.OkHttpClient - Cache hit: https://ge.solutions-team.gradle.com/api/builds?fromBuild=qcku2w347d5dy&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false\n",
+    "```\n",
+    "\n",
+    "##### Cache misses\n",
+    "\n",
+    "```\n",
+    "3447 [Execution of code '%logLevel debug...'] DEBUG c.gabrielfeo.develocity.api.Cache - HTTP cache is disabled\n",
+    "3853 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.g.develocity.api.OkHttpClient - --> GET https://ge.solutions-team.gradle.com/api/builds?fromInstant=0&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false h2\n",
+    "4208 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.g.develocity.api.OkHttpClient - <-- 200 https://ge.solutions-team.gradle.com/api/builds?fromInstant=0&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false (355ms, unknown-length body)\n",
+    "4230 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.g.develocity.api.OkHttpClient - --> GET https://ge.solutions-team.gradle.com/api/builds?fromBuild=qcku2w347d5dy&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false h2\n",
+    "4424 [OkHttp https://ge.solutions-team.gradle.com/...] DEBUG c.g.develocity.api.OkHttpClient - <-- 200 https://ge.solutions-team.gradle.com/api/builds?fromBuild=qcku2w347d5dy&maxBuilds=1000&query=buildStartTime%3E-7d%20buildTool%3Agradle&allModels=false (193ms, unknown-length body)\n",
+    "```\n",
+    "\n",
+    "[1]: https://github.com/gabrielfeo/develocity-api-kotlin/blob/main/docs/Logging.md"
+   ]
+  }
+ ],
+ "metadata": {
+  "kernelspec": {
+   "display_name": "Kotlin",
+   "language": "kotlin",
+   "name": "kotlin"
+  },
+  "language_info": {
+   "codemirror_mode": "text/x-kotlin",
+   "file_extension": ".kt",
+   "mimetype": "text/x-kotlin",
+   "name": "kotlin",
+   "nbconvert_exporter": "",
+   "pygments_lexer": "kotlin",
+   "version": "2.2.20-Beta2"
+  }
+ },
+ "nbformat": 4,
+ "nbformat_minor": 0
+}

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/Shell.kt

@@ -9,25 +9,29 @@ import java.nio.file.Path
 fun runInShell(workDir: Path, vararg command: String) =
     runInShell(workDir, command.joinToString(" "))
 
-fun runInShell(workDir: Path, command: String): String {
+fun runInShell(workDir: Path, command: String): OutputStreams {
     val process = ProcessBuilder("bash", "-c", command).apply {
         directory(workDir.toFile())
         // Ensure the test's build toolchain is used (not whatever JAVA_HOME is set to)
         environment()["JAVA_HOME"] = System.getProperty("java.home")
     }.start()
-    val stdout = runBlocking {
-        launch(start = UNDISPATCHED) {
-            process.errorStream.bufferedReader().lineSequence()
-                .onEach(System.err::println)
-                .joinToString("\n")
-        }
-        async(start = UNDISPATCHED) {
-            process.inputStream.bufferedReader().lineSequence()
-                .onEach(System.out::println)
-                .joinToString("\n")
-        }.await()
+    val streams = runBlocking {
+        OutputStreams(
+            stderr = async(start = UNDISPATCHED) {
+                process.errorStream.bufferedReader().lineSequence()
+                    .onEach(System.err::println)
+                    .joinToString("\n")
+            }.await(),
+            stdout = async(start = UNDISPATCHED) {
+                process.inputStream.bufferedReader().lineSequence()
+                    .onEach(System.out::println)
+                    .joinToString("\n")
+            }.await(),
+        )
     }
     val exitCode = process.waitFor()
     check(exitCode == 0) { "Exit code '$exitCode' for command: $command" }
-    return stdout
+    return streams
 }
+
+class OutputStreams(val stdout: String, val stderr: String)

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/gradle/ExampleGradleTaskTest.kt

@@ -34,7 +34,7 @@ class ExampleGradleTaskTest {
     @Test
     @Order(1)
     fun smokeTest() {
-        val dependencies = runBuild(":buildSrc:dependencies --configuration runtimeClasspath")
+        val dependencies = runBuild(":buildSrc:dependencies --configuration runtimeClasspath").stdout
         val libraryMatches = dependencies.lines().filter { "develocity-api-kotlin" in it }
         assertTrue(libraryMatches.isNotEmpty())
         assertTrue(libraryMatches.all { "-> SNAPSHOT" in it && "FAILED" !in it }) {
@@ -45,7 +45,7 @@ class ExampleGradleTaskTest {
     @Test
     fun testBuildPerformanceMetricsTaskWithDefaults() {
         val user = System.getProperty("user.name")
-        val output = runBuild("userBuildPerformanceMetrics")
+        val output = runBuild("userBuildPerformanceMetrics").stdout
         assertPerformanceMetricsOutput(output, user = user, period = "-14d")
     }
 
@@ -70,7 +70,7 @@ class ExampleGradleTaskTest {
 
     @Test
     fun testBuildPerformanceMetricsTaskWithOptions() {
-        val output = runBuild("userBuildPerformanceMetrics --user runner --period=-1d")
+        val output = runBuild("userBuildPerformanceMetrics --user runner --period=-1d").stdout
         assertPerformanceMetricsOutput(output, user = "runner", period = "-1d")
     }
 }

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/gradle/ExampleProjectTest.kt

@@ -33,7 +33,7 @@ class ExampleProjectTest {
     @Test
     @Order(1)
     fun smokeTest() {
-        val dependencies = runBuild("dependencies --configuration runtimeClasspath")
+        val dependencies = runBuild("dependencies --configuration runtimeClasspath").stdout
         val libraryMatches = dependencies.lines().filter { "develocity-api-kotlin" in it }
         assertTrue(libraryMatches.isNotEmpty())
         assertTrue(libraryMatches.all { "-> SNAPSHOT" in it && "FAILED" !in it }) {
@@ -43,7 +43,7 @@ class ExampleProjectTest {
 
     @Test
     fun testExampleProject() {
-        val output = runBuild("run")
+        val output = runBuild("run").stdout
         val tableRegex = Regex("""(?ms)^[-]+\nMost frequent builds:\n\s*\n(.+\|\s*\d+\s*\n?)+""")
         assertTrue(tableRegex.containsMatchIn(output)) {
             "Expected match for pattern '$tableRegex' in output '$output'"

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/notebook/Jupyter.kt

@@ -1,5 +1,6 @@
 package com.gabrielfeo.develocity.api.example.notebook
 
+import com.gabrielfeo.develocity.api.example.OutputStreams
 import com.gabrielfeo.develocity.api.example.copyFromResources
 import com.gabrielfeo.develocity.api.example.runInShell
 import java.nio.file.Path
@@ -12,17 +13,22 @@ class Jupyter(
     val venv: Path,
 ) {
 
-    fun executeNotebook(path: Path): Path {
+    class Execution(
+        val outputStreams: OutputStreams,
+        val outputNotebook: Path,
+    )
+
+    fun executeNotebook(path: Path): Execution {
         val outputPath = path.parent / "${path.nameWithoutExtension}-executed.ipynb"
-        runInShell(
+        val outputStreams = runInShell(
             workDir,
             "source '${venv / "bin/activate"}' &&",
             "jupyter nbconvert '$path'",
             "--to ipynb",
             "--execute",
             "--output='$outputPath'",
         )
-        return outputPath
+        return Execution(outputStreams, outputPath)
     }
 
     fun replaceMagics(

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/notebook/NotebooksTest.kt

@@ -40,7 +40,7 @@ class NotebooksTest {
         val sourceNotebook = tempDir / "examples/example-notebooks/MostFrequentBuilds.ipynb"
         val snapshotNotebook = forceUseOfMavenLocalSnapshotArtifact(sourceNotebook)
         val executedNotebook = assertDoesNotThrow { jupyter.executeNotebook(snapshotNotebook) }
-        with(JsonAdapter.fromJson(executedNotebook).asNotebookJson()) {
+        with(JsonAdapter.fromJson(executedNotebook.outputNotebook).asNotebookJson()) {
             assertTrue(textOutputLines.any { Regex("""Collected \d+ builds from the API""").containsMatchIn(it) }) {
                 "Expected line match not found in text outputs:\n${JsonAdapter.toPrettyJson(properties)}"
             }
@@ -53,6 +53,15 @@ class NotebooksTest {
         }
     }
 
+    @Test
+    fun testLoggingNotebook() {
+        val sourceNotebook = tempDir / "examples/example-notebooks/Logging.ipynb"
+        val snapshotNotebook = forceUseOfMavenLocalSnapshotArtifact(sourceNotebook)
+        val executedNotebook = assertDoesNotThrow { jupyter.executeNotebook(snapshotNotebook) }
+        val kernelLogs = executedNotebook.outputStreams.stderr
+        assertTrue(kernelLogs.contains("gabrielfeo.develocity.api.Cache - HTTP cache", ignoreCase = true))
+    }
+
     private fun forceUseOfMavenLocalSnapshotArtifact(sourceNotebook: Path): Path {
         val mavenLocal = Path(System.getProperty("user.home"), ".m2/repository").toUri()
         val libraryDescriptor = (tempDir / "develocity-api-kotlin.json").apply {

library/src/examplesTest/kotlin/com/gabrielfeo/develocity/api/example/script/ScriptsTest.kt

@@ -23,7 +23,7 @@ class ScriptsTest {
     fun testMostFrequentBuildsScript() {
         val script = tempDir / "examples/example-scripts/example-script.main.kts"
         val replacedScript = forceUseOfMavenLocalSnapshotArtifact(script)
-        val output = runInShell(tempDir, "kotlin '$replacedScript'").trim()
+        val output = runInShell(tempDir, "kotlin '$replacedScript'").stdout.trim()
         val tableRegex = Regex("""(?ms)^[-]+\nMost frequent builds:\n\s*\n(.+\|\s*\d+\s*\n?)+""")
         assertTrue(tableRegex.containsMatchIn(output)) {
             "Expected match for pattern '$tableRegex' in output '$output'"