search

cryostatio / cryostat-legacy

OUTDATED - See the new repository below! -- Secure JDK Flight Recorder management for containerized JVMs
https://github.com/cryostatio/cryostat
Other
224 stars 31 forks source link

HTTP 500: NPE during report generation #666

Closed andrewazores closed 1 year ago

andrewazores commented 3 years ago

Depends on: https://github.com/cryostatio/cryostat-core/issues/95

Cause: https://github.com/cryostatio/cryostat/issues/666#issuecomment-989105967

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

andrewazores commented 3 years ago

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

andrewazores commented 2 years ago

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

https://github.com/openjdk/jmc/commit/ad9b602d9219c726239f848672ee27da96611254

Here is the corresponding OpenJDK bug:

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

hareetd commented 2 years ago

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 commented 2 years ago

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: https://github.com/cryostatio/cryostat-core/pull/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 commented 2 years ago

Makes sense, thank you.

andrewazores commented 2 years ago

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.