Another NPE/build hang

We intermittently get this NPE, followed by the build hanging (version 2.3):

org.gradle.messaging.remote.internal.MessageIOException: Could not write message [ChannelMessage channel: org.gradle.api.internal.tasks.testing.TestResultProcessor, payload: [MethodInvocation method: null(953.5, org.gradle.api.internal.tasks.testing.TestCompleteEvent@7511f909)]] to '/0:0:0:0:0:0:0:1%lo:62314'.
    at org.gradle.messaging.remote.internal.inet.SocketConnection.dispatch(SocketConnection.java:106)
    at org.gradle.messaging.remote.internal.hub.MessageHub$ConnectionDispatch.run(MessageHub.java:284)
    at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
    at java.lang.reflect.Method.hashCode(Method.java:330)
    at java.util.HashMap.hash(HashMap.java:338)
    at java.util.HashMap.get(HashMap.java:556)
    at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationWriter.writeMethod(MethodInvocationSerializer.java:71)
    at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationWriter.write(MethodInvocationSerializer.java:62)
    at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationWriter.write(MethodInvocationSerializer.java:48)
    at org.gradle.messaging.serialize.kryo.TypeSafeSerializer$2.write(TypeSafeSerializer.java:46)
    at org.gradle.messaging.remote.internal.hub.InterHubMessageSerializer$MessageWriter.write(InterHubMessageSerializer.java:108)
    at org.gradle.messaging.remote.internal.hub.InterHubMessageSerializer$MessageWriter.write(InterHubMessageSerializer.java:93)
    at org.gradle.messaging.remote.internal.inet.SocketConnection.dispatch(SocketConnection.java:103)
    ... 5 more

Related: NullPointerException followed by build hanging

java.lang.reflect.Method#getName(String) is returning null here, which is strange to say the least.

Is this only for a certain build, only on a certain machine?

This is on various windows machines, apparently during test of a given sub-project. We haven’t seen this on linux.

@adammurdoch could we put a null check in here and some diagnostics on failure to try and work out what is happening?

@Jim_Gish if we added this to a 2.5 nightly, would you be able to run with it for a while to get the diagnostics?

Sure. that would work. I’m actually trying that myself in the two places we’re getting the NPE. I’ve just added a try/catch and dumping a stack trace, since we’re only getting an abbreviated one now. I’ll send you the results when I get some. Getting a nightly from you with whatever you want to add for diagnostics will be good. Thanks, Luke.

Is there a way I can change the logging level for this one task in which these exceptions appear to be happening? I think it may somehow be related to some test code in a module that has about 500 tests. I don’t wan to use -i or -d for the whole build, but would like to change the level just for this one module.

Here’s another exception happening in this same module:

:diagnostics:services:diagnostics:testUnexpected exception thrown.
org.gradle.messaging.remote.internal.MessageIOException: Could not read message from ‘/127.0.0.1:60059’.
at org.gradle.messaging.remote.internal.inet.SocketConnection.receive(SocketConnection.java:79)
at org.gradle.messaging.remote.internal.hub.MessageHub$ConnectionReceive.run(MessageHub.java:235)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java
:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NoSuchMethodException: org.gradle.api.internal.tasks.testing.TestResultProcessor.scaleUp(java.lang.
Object, org.gradle.api.internal.tasks.testing.TestCompleteEvent)
at java.lang.Class.getDeclaredMethod(Class.java:2130)
at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationReader.readMethod(MethodI
nvocationSerializer.java:134)
at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationReader.read(MethodInvocat
ionSerializer.java:114)
at org.gradle.messaging.remote.internal.hub.MethodInvocationSerializer$MethodInvocationReader.read(MethodInvocat
ionSerializer.java:95)
at org.gradle.messaging.serialize.kryo.TypeSafeSerializer$1.read(TypeSafeSerializer.java:37)
at org.gradle.messaging.remote.internal.hub.InterHubMessageSerializer$MessageReader.read(InterHubMessageSerializ
er.java:72)
at org.gradle.messaging.remote.internal.hub.InterHubMessageSerializer$MessageReader.read(InterHubMessageSerializ
er.java:58)
at org.gradle.messaging.remote.internal.inet.SocketConnection.receive(SocketConnection.java:74)
… 5 more

You can do:

test.logging.level = LogLevel.DEBUG

Hmm. That doesn’t work, however I did do

test.testLogging {
displayGranularity -1
showCauses true
showExceptions true
showStackTraces true
exceptionFormat org.gradle.api.tasks.testing.logging.TestExceptionFormat.FULL
events “failed”
}
and that got what I needed.

Update: I patched the gradle code where the NPEs were happening with try/catch and some debug output. I’ve had about 5 runs since last night – no NPEs. I’ll keep the build spinning and see what we get. (I’m sure if I revert to the un-patched gradle, it will probably re-appear).

I’ve been looking over the past several days of cruise control runs. I’ve found several cases of intermittent test failures caused by NPEs in our code. It appears that when this happens, gradle hangs at the end of the build, and hits the timeout we’ve set.

Another night of runs hit the error a few more times. It did enter my catch block on the NPE but didn’t print my System.err.println – apparently didn’t work with my logging settings.

Tell me debug info you’'d like me to put in there and I’ll do another patched version of gradle and keep trying. Thanks.

I didn’t realise that this problem was happening in the test JVM process, and not the build process.

It appears that when this happens, gradle hangs at the end of the build, and hits the timeout we’ve set.

How is this working? What happens on timeout?

If you can dump as much as possible about the method object with a null name that would be useful. Hopefully, it has some identifying information.

I think I’ve found the problem. We had some test code which was using jmockit. It was mocking the getName method on Method. I would think this would all be done in an isolated class loader and wouldn’t infect the main thread, but given the circumstances it’s not surprising that this resulted in some bizarre behavior, including hanging the gradle process. We’ve replaced this bit of test code with something that doesn’t use jmockit and are testing it now.

Great.

It would be very helpful if you could provide some instructions that we can follow to reproduce the problem, so we can handle this kind of failure better.