diff --git a/experimental/quasar-hook/README.md b/experimental/quasar-hook/README.md new file mode 100644 index 0000000000..43a253a5af --- /dev/null +++ b/experimental/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 experimental:quasar-hook:jar +java -javaagent:experimental/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. \ No newline at end of file diff --git a/experimental/quasar-hook/build.gradle b/experimental/quasar-hook/build.gradle new file mode 100644 index 0000000000..08b10c30a0 --- /dev/null +++ b/experimental/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) } } +} diff --git a/experimental/quasar-hook/src/main/kotlin/net/corda/quasarhook/QuasarInstrumentationHook.kt b/experimental/quasar-hook/src/main/kotlin/net/corda/quasarhook/QuasarInstrumentationHook.kt new file mode 100644 index 0000000000..960688379b --- /dev/null +++ b/experimental/quasar-hook/src/main/kotlin/net/corda/quasarhook/QuasarInstrumentationHook.kt @@ -0,0 +1,288 @@ +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() + val instrumentedClasses = HashSet() + val scannedClasses = HashSet() +} + +/** + * 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 should only be called once we're sure + * instrumentation will happen. + */ +fun recordInstrumentedClass(className: String) { + classRecorder.instrumentedClasses.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? = null, + val expand: List? = 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: ${classRecorder.instrumentedClasses.size}") + classRecorder.instrumentedClasses.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.instrumentedClasses.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 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.declaredMethods.single { it.name == "collectCodeBlocks" } + acceptMethod.insertBefore( + "$hookClassName.${::recordInstrumentedClass.name}(this.className);" + ) + }, + "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, 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) { + 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, separator: Char): PackageTree { + return mergeAll(fullClassNames.map { PackageTree.fromString(it, separator) }) + } + + fun mergeAll(trees: List): 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 { + data class State( + val include: PackageTree, + val exclude: PackageTree, + val globSoFar: List + ) + val toExpandList = LinkedList(listOf(State(this, excludeTree, emptyList()))) + val globs = ArrayList() + 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 + } +} diff --git a/node/capsule/build.gradle b/node/capsule/build.gradle index a3d4c6e650..22be033db1 100644 --- a/node/capsule/build.gradle +++ b/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' diff --git a/node/src/integration-test/kotlin/net/corda/node/NodeStartupPerformanceTests.kt b/node/src/integration-test/kotlin/net/corda/node/NodeStartupPerformanceTests.kt new file mode 100644 index 0000000000..f6d75d6f6a --- /dev/null +++ b/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() + 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 }) + } + } +} diff --git a/node/src/main/kotlin/net/corda/node/driver/Driver.kt b/node/src/main/kotlin/net/corda/node/driver/Driver.kt index 4e4a8047ee..22fc5499e7 100644 --- a/node/src/main/kotlin/net/corda/node/driver/Driver.kt +++ b/node/src/main/kotlin/net/corda/node/driver/Driver.kt @@ -104,7 +104,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 fun waitForAllNodesToFinish() @@ -561,7 +561,7 @@ class DriverDSL( } } - override fun startNetworkMapService() { + override fun startNetworkMapService(): ListenableFuture { val debugPort = if (isDebug) debugPortAllocation.nextPort() else null val apiAddress = portAllocation.nextHostAndPort().toString() val baseDirectory = driverDirectory / networkMapLegalName.commonName @@ -581,6 +581,7 @@ class DriverDSL( log.info("Starting network-map-service") val startNode = startNode(executorService, config.parseAs(), config, quasarJarPath, debugPort, systemProperties) registerProcess(startNode) + return startNode.flatMap { addressMustBeBound(executorService, networkMapAddress, it) } } override fun pollUntilNonNull(pollName: String, pollInterval: Duration, warnCount: Int, check: () -> A?): ListenableFuture { @@ -615,6 +616,10 @@ class DriverDSL( "visualvm.display.name" to "corda-${nodeConf.myLegalName}", "java.io.tmpdir" to System.getProperty("java.io.tmpdir") // Inherit from parent process ) + // 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" diff --git a/settings.gradle b/settings.gradle index 4c136033aa..bbf3702dcd 100644 --- a/settings.gradle +++ b/settings.gradle @@ -17,6 +17,7 @@ include 'webserver' include 'webserver:webcapsule' include 'experimental' include 'experimental:sandbox' +include 'experimental:quasar-hook' include 'verifier' include 'test-utils' include 'tools:explorer' @@ -30,4 +31,4 @@ include 'samples:irs-demo' include 'samples:network-visualiser' include 'samples:simm-valuation-demo' include 'samples:raft-notary-demo' -include 'samples:bank-of-corda-demo' +include 'samples:bank-of-corda-demo' \ No newline at end of file