added better tracing facilities & rebuilt

Groostav · Dec 20, 2021 · 64e1de0 · 64e1de0
1 parent 4b24226
commit 64e1de0
Show file tree

Hide file tree

Showing 8 changed files with 139 additions and 171 deletions.
diff --git a/build.gradle b/build.gradle
@@ -18,7 +18,7 @@ plugins {
 
 allprojects {
     group 'groostav'
-    version '0.8'
+    version '0.9'
 
     repositories {
         mavenCentral()

diff --git a/core/src/main/kotlin/groostav/kotlinx/exec/CoroutineTracer.kt b/core/src/main/kotlin/groostav/kotlinx/exec/CoroutineTracer.kt
@@ -1,24 +1,27 @@
 package groostav.kotlinx.exec
 
+import kotlinx.coroutines.Dispatchers
+import kotlin.coroutines.CoroutineContext
 import kotlin.reflect.jvm.jvmName
 
-internal val TRACE = true
-
-internal data class CoroutineTracer private constructor(
+internal data class CoroutineTracer internal constructor(
     val debugName: String,
     val traceElements: List<Exception>
-) {
+): CoroutineContext.Element {
+
     constructor(name: String): this(name, emptyList())
 
+    companion object Key: CoroutineContext.Key<CoroutineTracer>
+
     init {
-        require( ! debugName.isNullOrBlank())
+        require(debugName.isNotBlank())
     }
 
     fun appendName(nameSuffix: String) = CoroutineTracer("$debugName/$nameSuffix", traceElements)
 
-    inline fun trace(crossinline messageSupplier: () -> String) {
+    inline fun trace(isErr: Boolean = false, crossinline messageSupplier: () -> String) {
         if(TRACE){
-            println("$debugName: ${messageSupplier()}")
+            (if(isErr) System.err else System.out).println("$debugName: ${messageSupplier()}")
         }
     }
 
@@ -95,16 +98,5 @@ internal data class CoroutineTracer private constructor(
 
     fun makeFrame(name: String) = StackTraceElement(CoroutineTracer::class.jvmName, "ASYNC_RECOVERY_FOR_${name.toUpperCase()}", null, 0)
 
-    fun makeReceiveException(ex: Exception): Exception {
-
-        TODO()
-//        val exceptions: List<Exception> = (exceptionStack + ex).toList()
-//
-//        for ((outerEx, innerEx) in exceptions.windowed(2)) {
-//            innerEx.originalCause.initCause(outerEx)
-//        }
-//
-//        return exceptions.last()
-    }
-
+    override val key: CoroutineContext.Key<CoroutineTracer> = Key
 }
diff --git a/core/src/main/kotlin/groostav/kotlinx/exec/ExecCoroutine.kt b/core/src/main/kotlin/groostav/kotlinx/exec/ExecCoroutine.kt
diff --git a/core/src/main/kotlin/groostav/kotlinx/exec/WindowsProcessControl.kt b/core/src/main/kotlin/groostav/kotlinx/exec/WindowsProcessControl.kt
@@ -14,10 +14,7 @@ import java.io.Closeable
 import java.lang.ProcessBuilder.*
 import java.nio.file.Files
 import java.nio.file.Paths
-import java.time.Duration
-import java.time.Instant
 import java.util.*
-import java.util.concurrent.TimeUnit
 import kotlin.jvm.internal.FunctionReference
 import kotlin.reflect.KClass
 import kotlin.reflect.KFunction
@@ -152,10 +149,7 @@ internal object WindowsProcessControl {
             //      spawned sub-process was some kind of cleanup, possibly initiated by a finally{} block
             //      so I think its best to leave it running.
 
-
             val pids: String = actualTree.toSequence().joinToString(",") { it.pid.toString() }
-            val name = "siginter -pid $pids"
-
             // this cant be that durable...
             val commandLine = listOf(
                 javaw.toAbsolutePath().toString(),
@@ -167,7 +161,7 @@ internal object WindowsProcessControl {
             val reaperCode = if(DEBUGGING_GRACEFUL_KILL){
                 ungracefullyKillGracefully(commandLine)
             }
-            else runBlocking(Dispatchers.IO) {
+            else runBlocking(Dispatchers.IO + tracing) {
                 val remainingTime = deadline - System.currentTimeMillis()
 
                 if(remainingTime > 0) withTimeoutOrNull(remainingTime) {
@@ -176,8 +170,9 @@ internal object WindowsProcessControl {
                         gracefulTimeoutMillis = 0, //avoid recursion
                         expectedOutputCodes = null
                     )
-                    reaper.collect { message: ProcessEvent ->
-                        tracing.trace { "$name: ${message.formattedMessage}" }
+                    val localTracing = tracing.appendName("reaper-pid=${reaper.processID}")
+                    reaper.collect {
+                        localTracing.trace { it.formattedMessage }
                     }
                     reaper.await()
                 }
@@ -194,9 +189,6 @@ internal object WindowsProcessControl {
     // but it looks like that just punts the problem from the jvm into kernel 32, which still uses the same
     // (blocking thread) strategy.
     // => dont bother, no matter the API we're still polling the bastard.
-
-    private const val DEBUGGING_GRACEFUL_KILL: Boolean = true
-    init { if(DEBUGGING_GRACEFUL_KILL) System.err.println("DEBUGGING_GRACEFUL_KILL enabled") }
 }
 
 fun ungracefullyKillGracefully(commandLine: List<String>): Int = ProcessBuilder()

diff --git a/core/src/main/kotlin/groostav/kotlinx/exec/exec.kt b/core/src/main/kotlin/groostav/kotlinx/exec/exec.kt
@@ -9,6 +9,8 @@ import kotlin.coroutines.CoroutineContext
 import kotlin.coroutines.EmptyCoroutineContext
 import kotlin.coroutines.coroutineContext
 
+internal val TRACE = System.getProperty("groostav.kotlinx.exec.trace").toBoolean()
+internal val DEBUGGING_GRACEFUL_KILL: Boolean = System.getProperty("groostav.kotlinx.exec.DebuggingGracefulKill").toBoolean()
 
 data class ProcessResult(val outputAndErrorLines: List<String>, val exitCode: Int?)
 

diff --git a/core/src/test/kotlin/groostav/kotlinx/exec/BasicTests.kt b/core/src/test/kotlin/groostav/kotlinx/exec/BasicTests.kt
@@ -10,6 +10,10 @@ import kotlin.test.assertTrue
 
 class BasicTests {
 
+    init {
+        System.setProperty("groostav.kotlinx.exec.trace", "true")
+    }
+
     @Test
     fun `when command returns allowed nonzero exit code should return normally`() = runBlocking<Unit>{
 

diff --git a/core/src/test/kotlin/groostav/kotlinx/exec/CancelAndKillTests.kt b/core/src/test/kotlin/groostav/kotlinx/exec/CancelAndKillTests.kt
@@ -13,6 +13,10 @@ import kotlin.test.assertTrue
 @OptIn(InternalCoroutinesApi::class)
 class CancelAndKillTests {
 
+    init {
+        System.setProperty("groostav.kotlinx.exec.trace", "true")
+    }
+
     @Test
     fun `when killing a process should suspend until process is terminated`() = runBlocking<Unit>{
         //setup
@@ -158,8 +162,6 @@ class CancelAndKillTests {
             gracefulTimeoutMillis = 99999999999
         )
 
-        delay(30)
-
         val pids = runningProcess
 //                .nonCancelling()
                 .map { it.also { println(it.formattedMessage) }}
@@ -227,23 +229,6 @@ class CancelAndKillTests {
 //        assertEquals(42, result)
     }
 
-    @Test fun `when attempting to kill unstarted process should quietly do nothing`(): Unit = runBlocking<Unit> {
-        //setup
-        val unstartedProcess = execAsync(
-            commandLine = emptyScriptCommand(),
-            expectedOutputCodes = setOf(1),
-            lazy = true
-        )
-
-        //act
-        unstartedProcess.kill()
-
-        //assert
-        assertEquals(emptyList(), unstartedProcess.toList())
-        assertEquals(1, unstartedProcess.await())
-        assertTrue(unstartedProcess.isCompleted)
-    }
-
     @Test fun `when attempting to get PID for a completed process should succeed`() = runBlocking<Unit> {
         //setup
         val deadProc = execAsync(commandLine = emptyScriptCommand())

diff --git a/core/src/test/kotlin/groostav/kotlinx/exec/TortureTests.kt b/core/src/test/kotlin/groostav/kotlinx/exec/TortureTests.kt
@@ -63,23 +63,23 @@ internal class TortureTests {
         val fakeProcess = FakeProcess().apply {
 
         }
-        interceptors.apply {
-            emit(ExitCode(0))
-            emit(StandardOutputMessage("ahah"))
-            standardOutput.close()
-            standardInput.close()
-        }
-        val firstMessage = select<String?> {
-            onTimeout(1500) { null }
-            exec.onAwait { "exit code $it" }
-            exec.onReceive { it.formattedMessage }
-        }
-        delay(500)
-
-        // assert
-        assertEquals("ahah", firstMessage)
-        assertFalse(exec.isCompleted)
-        assertFalse(exec.state.errEOF, "expected stderrEOF=false, but state=${exec.state}")
+//        interceptors.apply {
+//            emit(ExitCode(0))
+//            emit(StandardOutputMessage("ahah"))
+//            standardOutput.close()
+//            standardInput.close()
+//        }
+//        val firstMessage = select<String?> {
+//            onTimeout(1500) { null }
+//            exec.onAwait { "exit code $it" }
+//            exec.onReceive { it.formattedMessage }
+//        }
+//        delay(500)
+//
+//        // assert
+//        assertEquals("ahah", firstMessage)
+//        assertFalse(exec.isCompleted)
+//        assertFalse(exec.state.errEOF, "expected stderrEOF=false, but state=${exec.state}")
     }
 
     @Test fun `when process completes without anybody waiting for it should go into completed state anyways`() = runBlocking<Unit> {
@@ -197,6 +197,7 @@ class FakeProcess: Process() {
             val result: Byte = (stdout.tryReceive().getOrNull()
                 ?: runBlocking { (stdout.receiveCatching().getOrNull() ?: -1) })
 //            return result
+            return TODO()
         }
     }
     override fun getErrorStream(): InputStream = object: InputStream() {
@@ -235,5 +236,4 @@ class FakeProcess: Process() {
             TODO("Not yet implemented")
         }
     }
-}
 }
-Original file line number
+Diff line change
@@ Expand Up / @@ -10,6 +10,10 @@ import kotlin.test.assertTrue @@
     class BasicTests {
+        init {
+            System.setProperty("groostav.kotlinx.exec.trace", "true")
+        }
         @Test
         fun `when command returns allowed nonzero exit code should return normally`() = runBlocking<Unit>{
@@ Expand Down @@