HTTP 500: NPE during report generation #666

andrewazores · 2021-08-27T19:12:50Z

Cause: cryostatio/cryostat#666 (comment)

INFO: (10.0.2.100:40302): GET /api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Flocalhost:9091%2Fjmxrmi/recordings/workflow_itest 200 150ms
Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger info
INFO: io.cryostat.net.reports.SubprocessReportGenerator starting
Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger info
INFO: io.cryostat.net.reports.SubprocessReportGenerator adjusting subprocess OOM score
Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger info
INFO: io.cryostat.net.reports.SubprocessReportGenerator processing report
java.lang.NullPointerException
	at org.openjdk.jmc.flightrecorder.parser.synthetic.SyntheticAttributeExtension$ModuleExportSink.addEvent(SyntheticAttributeExtension.java:206)
	at org.openjdk.jmc.flightrecorder.internal.parser.v1.TypeManager$EventTypeEntry.readEvent(TypeManager.java:318)
	at org.openjdk.jmc.flightrecorder.internal.parser.v1.TypeManager.readEvent(TypeManager.java:406)
	at org.openjdk.jmc.flightrecorder.internal.parser.v1.ChunkLoaderV1.call(ChunkLoaderV1.java:91)
	at org.openjdk.jmc.flightrecorder.internal.parser.v1.ChunkLoaderV1.call(ChunkLoaderV1.java:47)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger error
SEVERE: Exception thrown
io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at io.cryostat.net.reports.SubprocessReportGenerator.lambda$exec$0(SubprocessReportGenerator.java:154)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger error
SEVERE: Exception thrown
java.util.concurrent.ExecutionException: io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
	at io.cryostat.net.reports.ActiveRecordingReportCache.getReport(ActiveRecordingReportCache.java:135)
	at io.cryostat.net.reports.ActiveRecordingReportCache.lambda$new$0(ActiveRecordingReportCache.java:92)
	at com.github.benmanes.caffeine.cache.LocalLoadingCache.lambda$newMappingFunction$3(LocalLoadingCache.java:192)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$13(BoundedLocalCache.java:2431)
	at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1908)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2429)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2412)
	at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:104)
	at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:54)
	at io.cryostat.net.reports.ActiveRecordingReportCache.get(ActiveRecordingReportCache.java:99)
	at io.cryostat.net.reports.ReportService.get(ReportService.java:65)
	at io.cryostat.net.web.http.api.v1.TargetReportGetHandler.handleAuthenticated(TargetReportGetHandler.java:119)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:90)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:65)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$2(ContextImpl.java:313)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at io.cryostat.net.reports.SubprocessReportGenerator.lambda$exec$0(SubprocessReportGenerator.java:154)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger error
SEVERE: Exception thrown
io.vertx.ext.web.handler.impl.HttpStatusException: Internal Server Error
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2022)
	at io.cryostat.net.web.http.api.v1.TargetReportGetHandler.handleAuthenticated(TargetReportGetHandler.java:120)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:90)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:65)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$2(ContextImpl.java:313)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.util.concurrent.ExecutionException: io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
	at io.cryostat.net.reports.ActiveRecordingReportCache.getReport(ActiveRecordingReportCache.java:135)
	at io.cryostat.net.reports.ActiveRecordingReportCache.lambda$new$0(ActiveRecordingReportCache.java:92)
	at com.github.benmanes.caffeine.cache.LocalLoadingCache.lambda$newMappingFunction$3(LocalLoadingCache.java:192)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$doComputeIfAbsent$13(BoundedLocalCache.java:2431)
	at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1908)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.doComputeIfAbsent(BoundedLocalCache.java:2429)
	at com.github.benmanes.caffeine.cache.BoundedLocalCache.computeIfAbsent(BoundedLocalCache.java:2412)
	at com.github.benmanes.caffeine.cache.LocalCache.computeIfAbsent(LocalCache.java:104)
	at com.github.benmanes.caffeine.cache.LocalLoadingCache.get(LocalLoadingCache.java:54)
	at io.cryostat.net.reports.ActiveRecordingReportCache.get(ActiveRecordingReportCache.java:99)
	at io.cryostat.net.reports.ReportService.get(ReportService.java:65)
	at io.cryostat.net.web.http.api.v1.TargetReportGetHandler.handleAuthenticated(TargetReportGetHandler.java:119)
	... 9 more
Caused by: io.cryostat.net.reports.SubprocessReportGenerator$ReportGenerationException: [6] An unspecified unexpected exception occurred.
	at io.cryostat.net.reports.SubprocessReportGenerator.lambda$exec$0(SubprocessReportGenerator.java:154)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

Aug 27, 2021 7:07:20 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:40302): GET /api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Flocalhost:9091%2Fjmxrmi/reports/workflow_itest 500 750ms

[INFO] --- maven-failsafe-plugin:2.22.2:integration-test (failsafe-tests) @ cryostat ---
[INFO] 
[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running itest.ApiListingIT
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.762 s - in itest.ApiListingIT
[INFO] Running itest.CredentialsIT
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[INFO] Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.25 s - in itest.CredentialsIT
[INFO] Running itest.RulesPostFormIT
[WARN] [stderr] HTTP 409: Conflict
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.253 s - in itest.RulesPostFormIT
[INFO] Running itest.TargetEventsGetIT
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.672 s - in itest.TargetEventsGetIT
[INFO] Running itest.TargetRecordingPatchIT
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.153 s - in itest.TargetRecordingPatchIT
[INFO] Running itest.NoopAuthIT
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.015 s - in itest.NoopAuthIT
[INFO] Running itest.NotificationsUrlIT
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 s - in itest.NotificationsUrlIT
[INFO] Running itest.GrafanaSetupIT
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.019 s - in itest.GrafanaSetupIT
[INFO] Running itest.RulesPostJsonIT
[WARN] [stderr] HTTP 415: Unsupported Media Type
[WARN] [stderr] HTTP 409: Conflict
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 415: Unsupported Media Type
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.092 s - in itest.RulesPostJsonIT
[INFO] Running itest.RecordingWorkflowIT
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 6.901 s <<< FAILURE! - in itest.RecordingWorkflowIT
[ERROR] testWorkflow  Time elapsed: 6.901 s  <<< ERROR!
java.util.concurrent.ExecutionException: java.lang.Exception: HTTP 500
	at itest.RecordingWorkflowIT.testWorkflow(RecordingWorkflowIT.java:231)
Caused by: java.lang.Exception: HTTP 500
[INFO] Running itest.HealthIT
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.013 s - in itest.HealthIT
[INFO] Running itest.CryostatTemplateIT
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.306 s - in itest.CryostatTemplateIT
[INFO] Running itest.TargetRecordingOptionsIT
[INFO] Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.389 s - in itest.TargetRecordingOptionsIT
[INFO] Running itest.MessagingServerIT
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.03 s - in itest.MessagingServerIT
[INFO] Running itest.UploadCertificateIT
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 409: Conflict
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.075 s - in itest.UploadCertificateIT
[INFO] Running itest.UploadRecordingIT
[WARN] Tests run: 1, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 0.33 s - in itest.UploadRecordingIT
[INFO] Running itest.ClientAssetsIT
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.156 s - in itest.ClientAssetsIT
[INFO] Running itest.TargetReportIT
[WARN] [stderr] HTTP 404: Not Found
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.471 s - in itest.TargetReportIT
[INFO] Running itest.InterleavedExternalTargetRequestsIT
[INFO] [stdout] {"cryostatVersion":"v2.0.0-SNAPSHOT-198-g37e7236b","datasourceAvailable":true,"dashboardAvailable":true}[podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9098, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 769e1dec8544d292955dd4379497405c5633982c0269d67d07b1f8fea4307dd9
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9100, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 48b102d7d358140f0b158e8408789dba30d47c80bf308065e777b16a85c9dc46
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9099, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 139f468b4ba73261aae4fba3688ecf706f20582dea5131b5af9dd142618ecae1
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9093, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] a9ad03b1eb96a95b80bf1a51b4cde2bc6448f96b97146cec4879de7481053d07
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9096, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 37a1d0464c1caa90740114ceffefe1dddc00c54d9c9a89544b786ac950f09403
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9094, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 785e9456cde0fae6b0e20c2f0f59194eb2a8782017b40a71d4529fbb361f1450
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9095, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] bec293d6db9d78aa6bc774ab6c42a23ae38eeb210a50d5c9453367b95b5d3833
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9097, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 8f9beb2ea909d10849f19e438a767cef3b270aa2e4e0ef12b18040c8e3014551
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 48b102d7d358140f0b158e8408789dba30d47c80bf308065e777b16a85c9dc46]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 8f9beb2ea909d10849f19e438a767cef3b270aa2e4e0ef12b18040c8e3014551]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 785e9456cde0fae6b0e20c2f0f59194eb2a8782017b40a71d4529fbb361f1450]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", bec293d6db9d78aa6bc774ab6c42a23ae38eeb210a50d5c9453367b95b5d3833]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 769e1dec8544d292955dd4379497405c5633982c0269d67d07b1f8fea4307dd9]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 37a1d0464c1caa90740114ceffefe1dddc00c54d9c9a89544b786ac950f09403]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", a9ad03b1eb96a95b80bf1a51b4cde2bc6448f96b97146cec4879de7481053d07]
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 139f468b4ba73261aae4fba3688ecf706f20582dea5131b5af9dd142618ecae1]
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[INFO] [stdout] "running"
[WARN] [stderr] 6/9 targets found - waiting for discovery to complete
[INFO] [stdout] expected target count (9) observed, counting success 1/3
[INFO] [stdout] expected target count (9) observed, counting success 2/3
[INFO] [stdout] expected target count (9) observed, counting success 3/3
[INFO] [stdout] discovery complete
[INFO] [stdout] discovery completed in 22530ms
[INFO] [stdout] Elapsed time: 9555ms
[INFO] [stdout] [podman, kill, 769e1dec8544d292955dd4379497405c5633982c0269d67d07b1f8fea4307dd9]
[INFO] [stdout] 769e1dec8544d292955dd4379497405c5633982c0269d67d07b1f8fea4307dd9
[INFO] [stdout] [podman, kill, 48b102d7d358140f0b158e8408789dba30d47c80bf308065e777b16a85c9dc46]
[INFO] [stdout] 48b102d7d358140f0b158e8408789dba30d47c80bf308065e777b16a85c9dc46
[INFO] [stdout] [podman, kill, 139f468b4ba73261aae4fba3688ecf706f20582dea5131b5af9dd142618ecae1]
[INFO] [stdout] 139f468b4ba73261aae4fba3688ecf706f20582dea5131b5af9dd142618ecae1
[INFO] [stdout] [podman, kill, a9ad03b1eb96a95b80bf1a51b4cde2bc6448f96b97146cec4879de7481053d07]
[INFO] [stdout] a9ad03b1eb96a95b80bf1a51b4cde2bc6448f96b97146cec4879de7481053d07
[INFO] [stdout] [podman, kill, 37a1d0464c1caa90740114ceffefe1dddc00c54d9c9a89544b786ac950f09403]
[INFO] [stdout] 37a1d0464c1caa90740114ceffefe1dddc00c54d9c9a89544b786ac950f09403
[INFO] [stdout] [podman, kill, 785e9456cde0fae6b0e20c2f0f59194eb2a8782017b40a71d4529fbb361f1450]
[INFO] [stdout] 785e9456cde0fae6b0e20c2f0f59194eb2a8782017b40a71d4529fbb361f1450
[INFO] [stdout] [podman, kill, bec293d6db9d78aa6bc774ab6c42a23ae38eeb210a50d5c9453367b95b5d3833]
[INFO] [stdout] bec293d6db9d78aa6bc774ab6c42a23ae38eeb210a50d5c9453367b95b5d3833
[INFO] [stdout] [podman, kill, 8f9beb2ea909d10849f19e438a767cef3b270aa2e4e0ef12b18040c8e3014551]
[INFO] [stdout] 8f9beb2ea909d10849f19e438a767cef3b270aa2e4e0ef12b18040c8e3014551
[WARN] [stderr] 9 targets found - too many (expected 1)! Waiting to see if JDP settles...
[WARN] [stderr] 9 targets found - too many (expected 1)! Waiting to see if JDP settles...
[INFO] [stdout] expected target count (1) observed, counting success 1/3
[INFO] [stdout] expected target count (1) observed, counting success 2/3
[INFO] [stdout] expected target count (1) observed, counting success 3/3
[INFO] [stdout] discovery complete
[INFO] [stdout] discovery completed in 30028ms
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 67.317 s - in itest.InterleavedExternalTargetRequestsIT
[INFO] Running itest.AutoRulesIT
[WARN] [stderr] HTTP 400: Bad Request
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9093, --env, USE_AUTH=true, quay.io/andrewazores/vertx-fib-demo:0.6.0]
[INFO] [stdout] 4a824dde05726160b0ca6b2e383112842978fbbbdbe977cc73d6f54a963b67da
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 4a824dde05726160b0ca6b2e383112842978fbbbdbe977cc73d6f54a963b67da]
[INFO] [stdout] "running"
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 404: Not Found
[INFO] [stdout] [podman, kill, 4a824dde05726160b0ca6b2e383112842978fbbbdbe977cc73d6f54a963b67da]
[INFO] [stdout] 4a824dde05726160b0ca6b2e383112842978fbbbdbe977cc73d6f54a963b67da
[WARN] [stderr] 2 targets found - too many (expected 1)! Waiting to see if JDP settles...
[WARN] [stderr] 2 targets found - too many (expected 1)! Waiting to see if JDP settles...
[INFO] [stdout] expected target count (1) observed, counting success 1/3
[INFO] [stdout] expected target count (1) observed, counting success 2/3
[INFO] [stdout] expected target count (1) observed, counting success 3/3
[INFO] [stdout] discovery complete
[INFO] [stdout] discovery completed in 30022ms
[INFO] Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 41.384 s - in itest.AutoRulesIT
[INFO] Running itest.TemplatePostDeleteIT
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.024 s - in itest.TemplatePostDeleteIT
[INFO] Running itest.TargetRecordingsClientErrorIT
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 15, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.181 s - in itest.TargetRecordingsClientErrorIT
[INFO] Running itest.DiscoveryIT
[INFO] [stdout] [podman, run, --quiet, --pod=cryostat-itests, --detach, --rm, --env, JMX_PORT=9093, quay.io/andrewazores/vertx-fib-demo:0.7.0]
[INFO] [stdout] 43a76418fa757690e915e3028c3f5c95fecb188ebc16cadfc5f59b2432e8188e
[INFO] [stdout] [podman, container, inspect, --format="{{.State.Status}}", 43a76418fa757690e915e3028c3f5c95fecb188ebc16cadfc5f59b2432e8188e]
[INFO] [stdout] "running"
[WARN] [stderr] 1/2 targets found - waiting for discovery to complete
[INFO] [stdout] expected target count (2) observed, counting success 1/3
[INFO] [stdout] expected target count (2) observed, counting success 2/3
[INFO] [stdout] expected target count (2) observed, counting success 3/3
[INFO] [stdout] discovery complete
[INFO] [stdout] discovery completed in 22517ms
[INFO] [stdout] [podman, kill, 43a76418fa757690e915e3028c3f5c95fecb188ebc16cadfc5f59b2432e8188e]
[INFO] [stdout] 43a76418fa757690e915e3028c3f5c95fecb188ebc16cadfc5f59b2432e8188e
[WARN] [stderr] 2 targets found - too many (expected 1)! Waiting to see if JDP settles...
[WARN] [stderr] 2 targets found - too many (expected 1)! Waiting to see if JDP settles...
[INFO] [stdout] expected target count (1) observed, counting success 1/3
[INFO] [stdout] expected target count (1) observed, counting success 2/3
[INFO] [stdout] expected target count (1) observed, counting success 3/3
[INFO] [stdout] discovery complete
[INFO] [stdout] discovery completed in 30024ms
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 53.163 s - in itest.DiscoveryIT
[INFO] Running itest.ReportIT
[WARN] [stderr] HTTP 404: Not Found
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.686 s - in itest.ReportIT
[INFO] Running itest.TargetPostDeleteIT
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 400: Bad Request
[WARN] [stderr] HTTP 400: Bad Request
[INFO] Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.065 s - in itest.TargetPostDeleteIT
[INFO] Running itest.SnapshotIT
[WARN] [stderr] HTTP 404: Not Found
[WARN] [stderr] HTTP 404: Not Found
[INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.222 s - in itest.SnapshotIT
[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   RecordingWorkflowIT.testWorkflow:231 » Execution java.lang.Exception: HTTP 500
[INFO] 
[ERROR] Tests run: 97, Failures: 0, Errors: 1, Skipped: 1
[INFO] 
[INFO] 
[INFO] --- exec-maven-plugin:3.0.0:exec (capture-oci-logs) @ cryostat ---
[INFO] 
[INFO] --- exec-maven-plugin:3.0.0:exec (stop-jfr-datasource) @ cryostat ---
[INFO] [stdout] jfr-datasource-itest
[INFO] 
[INFO] --- exec-maven-plugin:3.0.0:exec (stop-grafana) @ cryostat ---
[INFO] [stdout] grafana-itest
[INFO] 
[INFO] --- exec-maven-plugin:3.0.0:exec (stop-container) @ cryostat ---
[INFO] [stdout] cryostat-itest
[INFO] 
[INFO] --- exec-maven-plugin:3.0.0:exec (destroy-pod) @ cryostat ---
[INFO] [stdout] a2a8e0fee9a55230cfd1e96aed661ff3759de1e0b6870d4d8f442457e6bb1458
[INFO] 
[INFO] --- maven-failsafe-plugin:2.22.2:verify (failsafe-tests) @ cryostat ---
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  04:52 min (Wall Clock)
[INFO] Finished at: 2021-08-27T15:10:11-04:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-failsafe-plugin:2.22.2:verify (failsafe-tests) on project cryostat: There are test failures.
[ERROR] 
[ERROR] Please refer to /home/andrew/workspace/cryostat/target/failsafe-reports for the individual test results.
[ERROR] Please refer to dump files (if any exist) [date].dump, [date]-jvmRun[N].dump and [date].dumpstream.
[ERROR] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException

cryostat-itest-2021-08-27T19:05:18Z.log

The text was updated successfully, but these errors were encountered:

andrewazores · 2021-09-02T12:22:46Z

https://github.com/cryostatio/cryostat/pull/677/checks?check_run_id=3489998749#step:9:508

andrewazores · 2021-12-08T19:00:50Z

This is a JMC JFR parser bug and appears to have been fixed in upstream JMC:

openjdk/jmc@ad9b602

Here is the corresponding OpenJDK bug:

https://bugs.openjdk.java.net/browse/JMC-7337

hareetd · 2021-12-08T19:06:45Z

I'm not familiar with what the steps are in this situation. Do we update our JMC JFR dependencies to include this upstream fix?

andrewazores · 2021-12-08T19:10:18Z

I'm not familiar with what the steps are in this situation. Do we update our JMC JFR dependencies to include this upstream fix?

There is already a -core PR in progress trying to do this: cryostatio/cryostat-core#99

Unfortunately it's not quite so straightforward as simply bumping the JMC version referenced in the pom.xml, because for downstream build reasons we also embed an older fork (7.1 IIRC) of some of the JMC sources directly into the -core sources (basically everything within https://github.com/cryostatio/cryostat-core/tree/main/src/main/java/org/openjdk/jmc). So all of those embedded sources would also need to be updated, which would probably mean deleting them all and copying the same directories out of the JMC 8.1.1 sources back into -core to re-embed the newest versions. So far this is all a pretty easy set of steps to take, but then there's a bit more legwork to do to ensure that everything is still buildable after this and everything still works as expected. I don't think JMC 8.1.1 is out yet, and as explained in that -core issue we can't use 8.1.0 (it fixes this NPE but breaks report generation altogether in a different way apparently).

hareetd · 2021-12-08T19:11:56Z

Makes sense, thank you.

andrewazores · 2021-12-08T19:13:01Z

Once the JMC project gets their additional application bundles extracted out and moved into their JMC Core library and published somewhere like Maven Central then hopefully we can drop our embedded version of the sources, which will make future JMC version upgrades much simpler and cleaner for us.

andrewazores added the bug Something isn't working label Aug 27, 2021

hareetd self-assigned this Nov 15, 2021

jan-law mentioned this issue Nov 19, 2021

feat(jwt): implement JWT auth for asset downloads #719

Merged

hareetd mentioned this issue Dec 2, 2021

HTTP 500: ClassCastException during report generation #767

Closed

andrewazores mentioned this issue Dec 7, 2021

feat(reports): sidecar container report generation #779

Merged

andrewazores mentioned this issue Dec 8, 2021

feat(jmcagent): add API handlers for JMC agent plugin #731

Merged

andrewazores added blocked dependent labels Dec 8, 2021

hareetd mentioned this issue Jan 6, 2022

fix(archiveupload): Delete improperly-named file uploads #787

Merged

jan-law mentioned this issue Jan 14, 2022

fix(notifications): Send notification on explicit recording stop #796

Merged

This was referenced Feb 2, 2022

feat(reports): Add custom JFR event for report rules #801

Merged

feat(notifications): Add "Recording Stopped" notification on implied stop #810

Merged

tthvo mentioned this issue May 25, 2022

chore(api): Move Probe handlers from beta to v2 package #956

Merged

andrewazores mentioned this issue Sep 28, 2022

Upgrading JMC Core API version cryostatio/jfr-datasource#133

Open

andrewazores mentioned this issue Apr 14, 2023

build(deps): bump cryostat-core from 2.19.2 to 2.20.0 #1453

Merged

andrewazores closed this as completed in #1453 Apr 14, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HTTP 500: NPE during report generation #666

HTTP 500: NPE during report generation #666

andrewazores commented Aug 27, 2021 •

edited

Loading

andrewazores commented Sep 2, 2021

andrewazores commented Dec 8, 2021

hareetd commented Dec 8, 2021

andrewazores commented Dec 8, 2021 •

edited

Loading

hareetd commented Dec 8, 2021

andrewazores commented Dec 8, 2021

HTTP 500: NPE during report generation #666

HTTP 500: NPE during report generation #666

Comments

andrewazores commented Aug 27, 2021 • edited Loading

andrewazores commented Sep 2, 2021

andrewazores commented Dec 8, 2021

hareetd commented Dec 8, 2021

andrewazores commented Dec 8, 2021 • edited Loading

hareetd commented Dec 8, 2021

andrewazores commented Dec 8, 2021

andrewazores commented Aug 27, 2021 •

edited

Loading

andrewazores commented Dec 8, 2021 •

edited

Loading