Bug Report: BinaryLinkClient::pushFrame, in fringe cases, is reentrant

Berry, Matt maberry at amazon.com
Fri Oct 11 20:41:25 UTC 2019


I've hit a bit of an edge case, which has revealed something about JMH that might merit changing. 

My understanding is that when JMH is configured to fork the JVM to run a test, it establishes a line of communication between the two JVMs in the form of a BinaryLink{Client,Server} pair. This BinaryLink is used to send both structured data via push{Results,Metadata,Exception} and unstructured data via the ForwardingPrintStream wired up to the forked JVM's stdout and stderr. 

The edge case I hit goes something like this:
1. The child JVM pushes the iteration parameters over the link (BaseRunner::runBenchmark, line 226)
2. During the Java serialization process, a SUID needs to get calculated for an Object[] (ObjectStreamClass::computeDefaultSUID)
3. The JVM loads the preferred crypto provider to provide a hash function to calculate the SUID (MessageDigest::getInstance -> ProviderConfig::doLoadProvider)
4. In my JVM, I've configured Corretto as the crypto provider and during first initialization it logs to java.util.logging [1]
5. JUL was configured to log to stderr
6. stderr is writing to the ForwardingPrintStream, which writes to the BinaryLinkClient

The result is that stderr is emitted right in the middle of the frame that runBenchmark was trying to emit. When the BinaryLinkServer reads this data, the deserialization process blows up violently. The exact behavior is going to depend on the data written to stderr. In my case, the message was [2] from (ObjectStreamClass.java:782) but, depending on what bits get set, some invariant in that class will not be happy.

I've confirmed this line of thinking by configuring JUL to not log to stderr, which avoids the issue altogether.

My guess is that it was never intended for the pushFrame method to be reentrant in this way. An option for dealing with this would be to use distinct BinaryLinks for sending stderr/stdout, separate from the BinaryLink used to send the frames JMH uses for reporting. Another option would be to make pushFrame reentrant by buffering messages.

A demonstration of the issue is available in this git repository [3].

-Matt

[1] https://github.com/corretto/amazon-corretto-crypto-provider/blob/develop/src/com/amazon/corretto/crypto/provider/Loader.java#L166
[2] [Ljava.lang.Object;; serializable and externalizable flags conflict
[3] https://github.com/AWS-MattB/jmh-bug-report

$ mvn package && java -jar target/benchmarks.jar
<binary link had failed, forked VM corrupted the stream? Use EXTRA verbose to print exception>
java.io.InvalidClassException: [Ljava.lang.Object;; serializable and externalizable flags conflict
...
	at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:430)
	at org.openjdk.jmh.runner.link.BinaryLinkServer$Handler.run(BinaryLinkServer.java:254)


More information about the jmh-dev mailing list