Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 786053fe authored by Chalard Jean's avatar Chalard Jean
Browse files

Improve interpreter logging

(this also fixes a small bug where the line numbers reported in
InterpretExceptions were wrong in TrackRecordTest by finding
the method from the stack trace that is actually annotated with
@Test)

This will help determining why testMultiplePoll is flaky.
Presumably it's just the time being slightly too long because
the device is loaded, but with this logs will tell.

Sample output before (redacted for readability)
InterpretException: java.lang.AssertionError: Expected value to be true.
	at TrackRecordTest.testMultiplePoll:thread1(TrackRecordTest.kt:267)
        ...
Caused by: java.lang.AssertionError: Expected value to be true.
        ...

Sample output after
InterpretException: Failure: poll(2, 2) = 18 time 6..9
	at TrackRecordTest.testMultiplePoll:thread1(TrackRecordTest.kt:267)
        ...
Caused by: java.lang.AssertionError: 41 not in 240..360
        ...

Test: android.net.testutils.TrackRecordTest#testMultiplePoll
      (which is the flaky test)
Test: NetworkStackTests

Change-Id: I67c94ca7e5a7b2cd351c8f236b606c46cf05f2e3
parent 2b7882e7
Loading
Loading
Loading
Loading
+1 −0
Original line number Diff line number Diff line
@@ -23,6 +23,7 @@ java_library {
    defaults: ["lib_mockito_extended"],
    static_libs: [
        "kotlin-test",
        "junit",
    ],
}

+22 −9
Original line number Diff line number Diff line
@@ -91,7 +91,7 @@ open class ConcurrentIntepreter<T>(
                        // testing. Instead, catch the exception, cancel other threads, and report
                        // nicely. Catch throwable because fail() is AssertionError, which inherits
                        // from Error.
                        crash = InterpretException(threadIndex, callSite.lineNumber + lineNum,
                        crash = InterpretException(threadIndex, it, callSite.lineNumber + lineNum,
                                callSite.className, callSite.methodName, callSite.fileName, e)
                    }
                    barrier.await()
@@ -103,18 +103,29 @@ open class ConcurrentIntepreter<T>(
    }

    // Helper to get the stack trace for a calling method
    protected fun getCallingMethod(depth: Int): StackTraceElement {
    private fun getCallingStackTrace(): Array<StackTraceElement> {
        try {
            throw RuntimeException()
        } catch (e: RuntimeException) {
            return e.stackTrace[depth]
            return e.stackTrace
        }
    }

    // Override this if you don't call interpretTestSpec directly to get the correct file
    // and line for failure in the error message.
    // 0 is this method here, 1 is getCallingMethod(int), 2 is interpretTestSpec, 3 the lambda
    open fun getCallingMethod() = getCallingMethod(4)
    // Find the calling method. This is the first method in the stack trace that is annotated
    // with @Test.
    fun getCallingMethod(): StackTraceElement {
        val stackTrace = getCallingStackTrace()
        return stackTrace.find { element ->
            val clazz = Class.forName(element.className)
            // Because the stack trace doesn't list the formal arguments, find all methods with
            // this name and return this name if any of them is annotated with @Test.
            clazz.declaredMethods
                    .filter { method -> method.name == element.methodName }
                    .any { method -> method.getAnnotation(org.junit.Test::class.java) != null }
        } ?: stackTrace[3]
        // If no method is annotated return the 4th one, because that's what it usually is :
        // 0 is getCallingStackTrace, 1 is this method, 2 is ConcurrentInterpreter#interpretTestSpec
    }
}

private fun <T> getDefaultInstructions() = listOf<InterpretMatcher<T>>(
@@ -124,7 +135,8 @@ private fun <T> getDefaultInstructions() = listOf<InterpretMatcher<T>>(
    Regex("(.*)//.*") to { i, t, r -> i.interpret(r.strArg(1), t) },
    // Interpret "XXX time x..y" : run XXX and check it took at least x and not more than y
    Regex("""(.*)\s*time\s*(\d+)\.\.(\d+)""") to { i, t, r ->
        assertTrue(measureTimeMillis { i.interpret(r.strArg(1), t) } in r.timeArg(2)..r.timeArg(3))
        val time = measureTimeMillis { i.interpret(r.strArg(1), t) }
        assertTrue(time in r.timeArg(2)..r.timeArg(3), "$time not in ${r.timeArg(2)..r.timeArg(3)}")
    },
    // Interpret "XXX = YYY" : run XXX and assert its return value is equal to YYY. "null" supported
    Regex("""(.*)\s*=\s*(null|\d+)""") to { i, t, r ->
@@ -141,12 +153,13 @@ private fun <T> getDefaultInstructions() = listOf<InterpretMatcher<T>>(
class SyntaxException(msg: String, cause: Throwable? = null) : RuntimeException(msg, cause)
class InterpretException(
    threadIndex: Int,
    instr: String,
    lineNum: Int,
    className: String,
    methodName: String,
    fileName: String,
    cause: Throwable
) : RuntimeException(cause) {
) : RuntimeException("Failure: $instr", cause) {
    init {
        stackTrace = arrayOf(StackTraceElement(
                className,
+0 −2
Original line number Diff line number Diff line
@@ -356,8 +356,6 @@ private object TRTInterpreter : ConcurrentIntepreter<TrackRecord<Int>>(interpret
    } else {
        interpretTestSpec(spec, ArrayTrackRecord())
    }

    override fun getCallingMethod() = getCallingMethod(4)
}

/*