Add quasar-hook agent for inspecting quasar instrumentation

node/capsule/build.gradle

@@ -34,9 +34,13 @@ task buildCordaJAR(type: FatCapsule) {
     )
     from 'NOTICE' // Copy CDDL notice
 
+
     capsuleManifest {
         applicationVersion = corda_release_version
         appClassPath = ["jolokia-agent-war-${project.rootProject.ext.jolokia_version}.war"]
+        // TODO add this once we upgrade quasar to 0.7.8
+        // def quasarExcludeExpression = "x(rx**;io**;kotlin**;jdk**;reflectasm**;groovyjarjarasm**;groovy**;joptsimple**;groovyjarjarantlr**;javassist**;com.fasterxml**;com.typesafe**;com.google**;com.zaxxer**;com.jcabi**;com.codahale**;com.esotericsoftware**;de.javakaffee**;org.objectweb**;org.slf4j**;org.w3c**;org.codehaus**;org.h2**;org.crsh**;org.fusesource**;org.hibernate**;org.dom4j**;org.bouncycastle**;org.apache**;org.objenesis**;org.jboss**;org.xml**;org.jcp**;org.jetbrains**;org.yaml**;co.paralleluniverse**;net.i2p**)"
+        // javaAgents = ["quasar-core-${quasar_version}-jdk8.jar=${quasarExcludeExpression}"]
         javaAgents = ["quasar-core-${quasar_version}-jdk8.jar"]
         systemProperties['visualvm.display.name'] = 'Corda'
         systemProperties['jdk.serialFilter'] = 'maxbytes=0'

node/src/integration-test/kotlin/net/corda/node/NodeStartupPerformanceTests.kt

@@ -0,0 +1,27 @@
+package net.corda.node
+
+import com.google.common.base.Stopwatch
+import net.corda.node.driver.driver
+import org.junit.Ignore
+import org.junit.Test
+import java.util.concurrent.TimeUnit
+
+@Ignore("Only use locally")
+class NodeStartupPerformanceTests {
+
+    // Measure the startup time of nodes. Note that this includes an RPC roundtrip, which causes e.g. Kryo initialisation.
+    @Test
+    fun `single node startup time`() {
+        driver(automaticallyStartNetworkMap = false) {
+            startNetworkMapService().get()
+            val times = ArrayList<Long>()
+            for (i in 1 .. 10) {
+                val time = Stopwatch.createStarted().apply {
+                    startNode().get()
+                }.stop().elapsed(TimeUnit.MICROSECONDS)
+                times.add(time)
+            }
+            println(times.map { it / 1_000_000.0 })
+        }
+    }
+}

node/src/main/kotlin/net/corda/node/driver/Driver.kt

@@ -107,7 +107,7 @@ interface DriverDSLExposedInterface {
      * Starts a network map service node. Note that only a single one should ever be running, so you will probably want
      * to set automaticallyStartNetworkMap to false in your [driver] call.
      */
-    fun startNetworkMapService()
+    fun startNetworkMapService(): ListenableFuture<Unit>
 
     fun waitForAllNodesToFinish()
 }
@@ -544,7 +544,7 @@ class DriverDSL(
         }
     }
 
-    override fun startNetworkMapService() {
+    override fun startNetworkMapService(): ListenableFuture<Unit> {
         val debugPort = if (isDebug) debugPortAllocation.nextPort() else null
         val apiAddress = portAllocation.nextHostAndPort().toString()
         val baseDirectory = driverDirectory / networkMapLegalName.commonName
@@ -564,6 +564,7 @@ class DriverDSL(
         log.info("Starting network-map-service")
         val startNode = startNode(executorService, config.parseAs<FullNodeConfiguration>(), config, quasarJarPath, debugPort, systemProperties)
         registerProcess(startNode)
+        return startNode.flatMap { addressMustBeBound(executorService, networkMapAddress, it) }
     }
 
     companion object {
@@ -591,6 +592,10 @@ class DriverDSL(
                         "name" to nodeConf.myLegalName,
                         "visualvm.display.name" to "corda-${nodeConf.myLegalName}"
                 )
+                // TODO Add this once we upgrade to quasar 0.7.8, this causes startup time to halve.
+                // val excludePattern = x(rx**;io**;kotlin**;jdk**;reflectasm**;groovyjarjarasm**;groovy**;joptsimple**;groovyjarjarantlr**;javassist**;com.fasterxml**;com.typesafe**;com.google**;com.zaxxer**;com.jcabi**;com.codahale**;com.esotericsoftware**;de.javakaffee**;org.objectweb**;org.slf4j**;org.w3c**;org.codehaus**;org.h2**;org.crsh**;org.fusesource**;org.hibernate**;org.dom4j**;org.bouncycastle**;org.apache**;org.objenesis**;org.jboss**;org.xml**;org.jcp**;org.jetbrains**;org.yaml**;co.paralleluniverse**;net.i2p**)"
+                // val extraJvmArguments = systemProperties.map { "-D${it.key}=${it.value}" } +
+                //        "-javaagent:$quasarJarPath=$excludePattern"
                 val extraJvmArguments = systemProperties.map { "-D${it.key}=${it.value}" } +
                         "-javaagent:$quasarJarPath"
                 val loggingLevel = if (debugPort == null) "INFO" else "DEBUG"

quasar-hook/README.md

@@ -0,0 +1,21 @@
+What is this?
+=============
+
+This is a javaagent that may be used while running applications using quasar. It hooks into quasar to track what
+methods are scanned, instrumented and used at runtime, and generates an exclude pattern that may be passed in to quasar
+to stop it from scanning classes unnecessarily.
+
+Example usage
+=============
+
+```
+./gradlew quasar-hook:jar
+java -javaagent:quasar-hook/build/libs/quasar-hook.jar="expand=com,de,org,co;truncate=net.corda" -jar path/to/corda.jar
+```
+
+The above will run corda.jar and on exit will print information about what classes were scanned/instrumented.
+
+`expand` and `truncate` tweak the output exclude pattern. `expand` is a list of packages to always expand (for example
+instead of generating `com.*` generate `com.google.*,com.typesafe.*` etc.), `truncate` is a list of packages that should
+not be included in the exclude pattern. Truncating `net.corda` means nothing should be excluded from instrumentation in
+Corda.

quasar-hook/build.gradle

@@ -0,0 +1,51 @@
+buildscript {
+    // For sharing constants between builds
+    Properties constants = new Properties()
+    file("$projectDir/../constants.properties").withInputStream { constants.load(it) }
+
+    ext.kotlin_version = constants.getProperty("kotlinVersion")
+    ext.javaassist_version = "3.12.1.GA"
+
+    repositories {
+        mavenLocal()
+        mavenCentral()
+        jcenter()
+    }
+
+    dependencies {
+        classpath "org.jetbrains.kotlin:kotlin-gradle-plugin:$kotlin_version"
+    }
+}
+
+repositories {
+    mavenLocal()
+    mavenCentral()
+    jcenter()
+}
+
+apply plugin: 'kotlin'
+apply plugin: 'kotlin-kapt'
+apply plugin: 'idea'
+
+description 'A javaagent to allow hooking into the instrumentation by Quasar'
+
+dependencies {
+    compile "org.jetbrains.kotlin:kotlin-stdlib-jre8:$kotlin_version"
+    compile "org.jetbrains.kotlin:kotlin-reflect:$kotlin_version"
+    compile "javassist:javassist:$javaassist_version"
+}
+
+jar {
+    archiveName = "${project.name}.jar"
+    manifest {
+        attributes(
+                'Premain-Class': 'net.corda.quasarhook.QuasarInstrumentationHookAgent',
+                'Can-Redefine-Classes': 'true',
+                'Can-Retransform-Classes': 'true',
+                'Can-Set-Native-Method-Prefix': 'true',
+                'Implementation-Title': "QuasarHook",
+                'Implementation-Version': rootProject.version
+        )
+    }
+    from { configurations.compile.collect { it.isDirectory() ? it : zipTree(it) } }
+}

quasar-hook/src/main/kotlin/net/corda/quasarhook/QuasarInstrumentationHook.kt

@@ -0,0 +1,299 @@
+package net.corda.quasarhook
+
+import javassist.ClassPool
+import javassist.CtClass
+import java.io.ByteArrayInputStream
+import java.lang.instrument.ClassFileTransformer
+import java.lang.instrument.Instrumentation
+import java.security.ProtectionDomain
+import java.util.*
+
+/**
+ * Used to collect classes through instrumentation.
+ */
+class ClassRecorder {
+    val usedInstrumentedClasses = HashSet<String>()
+    val instrumentedClassesWithAnnotation = HashSet<String>()
+    val instrumentedClassesWithoutAnnotation = HashSet<String>()
+    val scannedClasses = HashSet<String>()
+}
+
+/**
+ * Use global state to do the collection.
+ */
+val classRecorder = ClassRecorder()
+
+/**
+ * This is a hook called from each quasar getStack call, which happens on suspension. We construct a callstack and
+ * extract the part of the stack between the quasar scheduler and the getStack call, which should contain all methods/classes
+ * relevant to this suspension.
+ */
+fun recordUsedInstrumentedCallStack() {
+    val throwable = Throwable()
+    var index = 0
+    while (true) {
+        require (index < throwable.stackTrace.size) { "Can't find getStack call" }
+        val stackElement = throwable.stackTrace[index]
+        if (stackElement.className == "co.paralleluniverse.fibers.Stack" && stackElement.methodName == "getStack") {
+            break
+        }
+        index++
+    }
+    index++
+    while (true) {
+        require (index < throwable.stackTrace.size) { "Can't find Fiber call" }
+        val stackElement = throwable.stackTrace[index]
+        if (stackElement.className.startsWith("co.paralleluniverse")) {
+            break
+        }
+        classRecorder.usedInstrumentedClasses.add(stackElement.className)
+        index++
+    }
+}
+
+/**
+ * This is a hook called from the method instrumentor visitor. Note that this visitor is only accept()ed once we know
+ * for sure that instrumentation will happen.
+ * [hasAnnotation] may be false for classes that are forced to be instrumented. In quasar 0.7.7 for example they
+ * instrument all lambdas, irregardless of actual usage.
+ */
+fun recordInstrumentedClass(className: String, hasAnnotation: Boolean) {
+    if (hasAnnotation) {
+        classRecorder.instrumentedClassesWithAnnotation.add(className)
+    } else {
+        classRecorder.instrumentedClassesWithoutAnnotation.add(className)
+    }
+}
+
+/**
+ * This is a hook called from QuasarInstrumentor, after the exclude filtering, but before examining the bytecode.
+ */
+fun recordScannedClass(className: String?) {
+    if (className != null) {
+        classRecorder.scannedClasses.add(className)
+    }
+}
+
+/**
+ * Arguments to this javaagent.
+ *
+ * @param truncate A comma-separated list of packages to trim from the exclude patterns.
+ * @param expand A comma-separated list of packages to expand in the glob output. This is useful for certain top-level
+ *     domains that we don't want to completely exclude, because later on classes may be loaded from those namespaces
+ *     that require instrumentation.
+ * @param separator The package part separator character used in the above lists.
+ */
+data class Arguments(
+        val truncate: List<String>? = null,
+        val expand: List<String>? = null,
+        val separator: Char = '.'
+)
+
+/**
+ * This javaagent instruments quasar to extract information about what classes are scanned, instrumented, and used at
+ * runtime. On process exit the javaagent tries to calculate what an appropriate exclude pattern should be.
+ */
+class QuasarInstrumentationHookAgent {
+    companion object {
+        @JvmStatic
+        fun premain(argumentsString: String?, instrumentation: Instrumentation) {
+
+            var arguments = Arguments()
+            argumentsString?.let {
+                it.split(";").forEach {
+                    val (key, value) = it.split("=")
+                    when (key) {
+                        "truncate" -> arguments = arguments.copy(truncate = value.split(","))
+                        "expand" -> arguments = arguments.copy(expand = value.split(","))
+                        "separator" -> arguments = arguments.copy(separator = value.toCharArray()[0])
+                    }
+                }
+            }
+
+            Runtime.getRuntime().addShutdownHook(Thread {
+                println("Instrumented classes (with Suspendable): ${classRecorder.instrumentedClassesWithAnnotation.size}")
+                classRecorder.instrumentedClassesWithAnnotation.forEach {
+                    println("  $it")
+                }
+                println("Instrumented classes (without Suspendable): ${classRecorder.instrumentedClassesWithoutAnnotation.size}")
+                classRecorder.instrumentedClassesWithoutAnnotation.forEach {
+                    println("  $it")
+                }
+                println("Used instrumented classes: ${classRecorder.usedInstrumentedClasses.size}")
+                classRecorder.usedInstrumentedClasses.forEach {
+                    println("  $it")
+                }
+                println("Scanned classes: ${classRecorder.scannedClasses.size}")
+                classRecorder.scannedClasses.take(20).forEach {
+                    println("  $it")
+                }
+                println("  (...)")
+                val scannedTree = PackageTree.fromStrings(classRecorder.scannedClasses.toList(), '/')
+                val instrumentedTree = PackageTree.fromStrings(classRecorder.instrumentedClassesWithAnnotation.toList(), '/')
+                println("Suggested exclude globs:")
+                val truncate = arguments.truncate?.let { PackageTree.fromStrings(it, arguments.separator) }
+                // The separator append is a hack, it causes a package with an empty name to be added to the exclude tree,
+                // which practically causes that level of the tree to be always expanded in the output globs.
+                val expand = arguments.expand?.let { PackageTree.fromStrings(it.map { "$it${arguments.separator}" }, arguments.separator) }
+                val truncatedTree = truncate?.let { scannedTree.truncate(it)} ?: scannedTree
+                val expandedTree = expand?.let { instrumentedTree.merge(it) } ?: instrumentedTree
+                val globs = truncatedTree.toGlobs(expandedTree)
+                globs.forEach {
+                    println("  $it")
+                }
+                println("Quasar exclude expression:")
+                println("  x(${globs.joinToString(";")})")
+            })
+            instrumentation.addTransformer(QuasarInstrumentationHook)
+        }
+    }
+
+}
+
+object QuasarInstrumentationHook : ClassFileTransformer {
+    val classPool = ClassPool.getDefault()
+
+    val hookClassName = "net.corda.quasarhook.QuasarInstrumentationHookKt"
+
+    val instrumentMap = mapOf<String, (CtClass) -> Unit>(
+            "co/paralleluniverse/fibers/Stack" to { clazz ->
+                // This is called on each suspend, we hook into it to get the stack trace of actually used Suspendables
+                val getStackMethod = clazz.methods.single { it.name ==  "getStack" }
+                getStackMethod.insertBefore(
+                        "$hookClassName.${::recordUsedInstrumentedCallStack.name}();"
+                )
+            },
+            "co/paralleluniverse/fibers/instrument/InstrumentMethod" to { clazz ->
+                // This is called on each instrumented method
+                val acceptMethod = clazz.methods.single { it.name == "accept" }
+                acceptMethod.insertBefore(
+                        "$hookClassName.${::recordInstrumentedClass.name}(this.className, hasAnnotation);"
+                )
+            },
+            "co/paralleluniverse/fibers/instrument/QuasarInstrumentor" to { clazz ->
+                val instrumentClassMethods = clazz.methods.filter {
+                    it.name == "instrumentClass"
+                }
+                // TODO this is very brittle, we want to match on a specific instrumentClass() function. We could use the function signature, but that may change between versions anyway. Why is this function overloaded??
+                instrumentClassMethods[0].insertBefore(
+                        "$hookClassName.${::recordScannedClass.name}(className);"
+                )
+            }
+    )
+
+    override fun transform(
+            loader: ClassLoader?,
+            className: String,
+            classBeingRedefined: Class<*>?,
+            protectionDomain: ProtectionDomain?,
+            classfileBuffer: ByteArray
+    ): ByteArray {
+        return try {
+            val instrument = instrumentMap.get(className)
+            return instrument?.let {
+                val clazz = classPool.makeClass(ByteArrayInputStream(classfileBuffer))
+                it(clazz)
+                clazz.toBytecode()
+            } ?: classfileBuffer
+        } catch (throwable: Throwable) {
+            println("SOMETHING WENT WRONG")
+            throwable.printStackTrace(System.out)
+            classfileBuffer
+        }
+   }
+}
+
+data class Glob(val parts: List<String>, val isFull: Boolean) {
+    override fun toString(): String {
+        if (isFull) {
+            return parts.joinToString(".")
+        } else {
+            return "${parts.joinToString(".")}**"
+        }
+    }
+}
+
+/**
+ * Build up a tree from parts of the package names.
+ */
+data class PackageTree(val branches: Map<String, PackageTree>) {
+    fun isEmpty() = branches.isEmpty()
+
+    /**
+     * Merge the tree with [other].
+     */
+    fun merge(other: PackageTree): PackageTree {
+        val mergedBranches = HashMap(branches)
+        other.branches.forEach { (key, tree) ->
+            mergedBranches.compute(key) { _, previousTree ->
+                previousTree?.merge(tree) ?: tree
+            }
+        }
+        return PackageTree(mergedBranches)
+    }
+
+    /**
+     * Truncate the tree below [other].
+     */
+    fun truncate(other: PackageTree): PackageTree {
+        if (other.isEmpty()) {
+            return empty
+        } else {
+            val truncatedBranches = HashMap(branches)
+            other.branches.forEach { (key, tree) ->
+                truncatedBranches.compute(key) { _, previousTree ->
+                    previousTree?.truncate(tree) ?: empty
+                }
+            }
+            return PackageTree(truncatedBranches)
+        }
+    }
+
+    companion object {
+        val empty = PackageTree(emptyMap())
+        fun fromString(fullClassName: String, separator: Char): PackageTree {
+            var current = empty
+            fullClassName.split(separator).reversed().forEach {
+                current = PackageTree(mapOf(it to current))
+            }
+            return current
+        }
+
+        fun fromStrings(fullClassNames: List<String>, separator: Char): PackageTree {
+            return mergeAll(fullClassNames.map { PackageTree.fromString(it, separator) })
+        }
+
+        fun mergeAll(trees: List<PackageTree>): PackageTree {
+            return trees.foldRight(PackageTree.empty, PackageTree::merge)
+        }
+    }
+
+    /**
+     * Construct minimal globs that match this tree but don't match [excludeTree].
+     */
+    fun toGlobs(excludeTree: PackageTree): List<Glob> {
+        data class State(
+                val include: PackageTree,
+                val exclude: PackageTree,
+                val globSoFar: List<String>
+        )
+        val toExpandList = LinkedList(listOf(State(this, excludeTree, emptyList())))
+        val globs = ArrayList<Glob>()
+        while (true) {
+            val state = toExpandList.pollFirst() ?: break
+            if (state.exclude.branches.isEmpty()) {
+                globs.add(Glob(state.globSoFar, state.include.isEmpty()))
+            } else {
+                state.include.branches.forEach { (key, subTree) ->
+                    val excludeSubTree = state.exclude.branches[key]
+                    if (excludeSubTree != null) {
+                        toExpandList.addLast(State(subTree, excludeSubTree, state.globSoFar + key))
+                    } else {
+                        globs.add(Glob(state.globSoFar + key, subTree.isEmpty()))
+                    }
+                }
+            }
+        }
+        return globs
+    }
+}

settings.gradle

@@ -31,3 +31,4 @@ include 'samples:network-visualiser'
 include 'samples:simm-valuation-demo'
 include 'samples:raft-notary-demo'
 include 'samples:bank-of-corda-demo'
+include 'quasar-hook'