NPE in c.m.g.sample.aggregation.HeapOccupancyAfterCollection.extractHeapOccupancy

[dsgrieve]

Don't dismiss as 'it's only a sample' as this may expose some underlying problem, or expose some lack of coverage in unit testing.

Describe the bug
022-10-31T20:35:27.3983818Z [INFO] Running com.microsoft.gctoolkit.integration.core.PreunifiedJavaVirtualMachineConfigurationTest
2022-10-31T20:35:27.9909813Z Oct 31, 2022 8:35:27 PM com.microsoft.gctoolkit.vertx.aggregator.AggregatorVerticle lambda$record$0
2022-10-31T20:35:27.9910852Z WARNING: Error in aggregator
2022-10-31T20:35:27.9912261Z java.lang.NullPointerException
2022-10-31T20:35:27.9913483Z at com.microsoft.gctoolkit.sample@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.sample.aggregation.HeapOccupancyAfterCollection.extractHeapOccupancy(HeapOccupancyAfterCollection.java:27)
2022-10-31T20:35:27.9914614Z at com.microsoft.gctoolkit.api@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.aggregator.JVMEventDispatcher.dispatch(JVMEventDispatcher.java:77)
2022-10-31T20:35:27.9915751Z at com.microsoft.gctoolkit.api@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.aggregator.Aggregator.consume(Aggregator.java:118)
2022-10-31T20:35:27.9916766Z at com.microsoft.gctoolkit.vertx@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.vertx.aggregator.AggregatorVerticle$AggregatorWrapper.consume(AggregatorVerticle.java:38)
2022-10-31T20:35:27.9975222Z at com.microsoft.gctoolkit.vertx@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.vertx.aggregator.AggregatorVerticle.lambda$record$0(AggregatorVerticle.java:105)
2022-10-31T20:35:27.9975883Z at java.base/java.lang.Iterable.forEach(Iterable.java:75)
2022-10-31T20:35:27.9976860Z at com.microsoft.gctoolkit.vertx@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.vertx.aggregator.AggregatorVerticle.record(AggregatorVerticle.java:103)
2022-10-31T20:35:27.9977761Z at com.microsoft.gctoolkit.vertx@2.0.11-SNAPSHOT/com.microsoft.gctoolkit.vertx.aggregator.AggregatorVerticle.lambda$start$2(AggregatorVerticle.java:137)
2022-10-31T20:35:27.9978422Z at io.vertx.core@4.3.4/io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:264)
2022-10-31T20:35:27.9979046Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.MessageConsumerImpl.dispatch(MessageConsumerImpl.java:177)
2022-10-31T20:35:27.9979717Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.HandlerRegistration$InboundDeliveryContext.execute(HandlerRegistration.java:137)
2022-10-31T20:35:27.9980354Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.DeliveryContextBase.next(DeliveryContextBase.java:72)
2022-10-31T20:35:27.9980912Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.DeliveryContextBase.dispatch(DeliveryContextBase.java:43)
2022-10-31T20:35:27.9981541Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.HandlerRegistration.dispatch(HandlerRegistration.java:98)
2022-10-31T20:35:27.9982183Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.MessageConsumerImpl.deliver(MessageConsumerImpl.java:183)
2022-10-31T20:35:27.9982798Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.MessageConsumerImpl.doReceive(MessageConsumerImpl.java:168)
2022-10-31T20:35:27.9983426Z at io.vertx.core@4.3.4/io.vertx.core.eventbus.impl.HandlerRegistration.lambda$receive$0(HandlerRegistration.java:49)
2022-10-31T20:35:27.9984033Z at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
2022-10-31T20:35:27.9984658Z at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
2022-10-31T20:35:27.9985244Z at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
2022-10-31T20:35:27.9985794Z at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
2022-10-31T20:35:27.9986383Z at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
2022-10-31T20:35:27.9986985Z at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
2022-10-31T20:35:27.9987520Z at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2022-10-31T20:35:27.9987997Z at java.base/java.lang.Thread.run(Thread.java:829)
To Reproduce
Steps to reproduce the behavior:

1. Go to '...'
2. Click on '....'
3. Scroll down to '....'
4. See error

Expected behavior
A clear and concise description of what you expected to happen.

Screenshots
If applicable, add screenshots to help explain your problem.

Desktop (please complete the following information):

• OS: [e.g. iOS]
• Browser [e.g. chrome, safari]
• Version [e.g. 22]

Smartphone (please complete the following information):

• Device: [e.g. iPhone6]
• OS: [e.g. iOS8.1]
• Browser [e.g. stock browser, safari]
• Version [e.g. 22]

Additional context
Add any other context about the problem here.

[gofow]

Hi, I'd like to do this. Maybe this NPE problem is caused by something due to multithreading. Although it is hard to reproduce and has a very low probability of occurrence, my suggestion is to add 'is null' check before invoking a method. It will be more robust and prescriptive. Would you mind assigning the issue to me? @dsgrieve @karianna

[kcpeppe]

@gofow, happy to have you tackle this issue. We had a problem that feels similar when testing with machines that had low core counts. The issue was that vert.x wasn't fully started before the log file streaming started. The test failed because the initial part of the log was dropped by vert.x. This was fixed by adjusting the code that ensured vert.x verticles were fully started prior to streaming the log. Not saying this is the issue but it feels like a chunk of the log file is getting dropped instead of being pushed forward to the Aggregations or the Aggregations are being read before the stream has been fully processed. Or, it could be something completely else. I can't reproduce it so it's all speculation

[gofow]

@kcpeppe Yes, you're right. BTW, I was wondering how you ensure that the vert.x verticles are fully started prior to streaming the log? And thank you for sharing your insights. It will be very inspiring and helpful for me.

[kcpeppe]

We use a phaser up front to create a starting line and then there is shutdown code in the verticle which can be used to sync the shutdown. You can find it all in the vert.x module