Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HTTP 500: org.openjdk.jmc.rjmx.services.jfr.FlightRecorderException: Could not retrieve the attribute Recordings! #775

Closed
andrewazores opened this issue Dec 4, 2021 · 1 comment
Closed

HTTP 500: org.openjdk.jmc.rjmx.services.jfr.FlightRecorderException: Could not retrieve the attribute Recordings! #775

andrewazores opened this issue Dec 4, 2021 · 1 comment
Labels
bug Something isn't working

Comments

@andrewazores
Copy link
Member 

Dec 03, 2021 11:55:24 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575724},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9100/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9100","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:24 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575724},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9099/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9099","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:25 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575725},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9093/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9093","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:26 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9091/jmxrmi
Dec 03, 2021 11:55:26 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575726},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9094/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9094","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:27 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575727},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9097/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9097","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:28 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575728},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9098/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9098","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:30 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575730},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9096/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9096","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:30 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): GET /api/v1/targets 200 1ms
Dec 03, 2021 11:55:30 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1638575730},"message":{"event":{"kind":"FOUND","serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat-itests:9095/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat-itests","PORT":"9095","JAVA_MAIN":"es.andrewazor.demo.Main"}}}}}}
Dec 03, 2021 11:55:37 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): GET /api/v1/targets 200 1ms
Dec 03, 2021 11:55:45 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): GET /api/v1/targets 200 1ms
Dec 03, 2021 11:55:52 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): GET /api/v1/targets 200 1ms
Dec 03, 2021 11:55:52 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): GET /api/v1/targets 200 0ms
Dec 03, 2021 11:55:52 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9094/jmxrmi
Dec 03, 2021 11:55:54 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575754},"message":{"recording":"interleaved-1","target":"cryostat-itests:9094"}}
Dec 03, 2021 11:55:54 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): POST /api/v1/targets/cryostat-itests:9094/recordings 201 1255ms
Dec 03, 2021 11:55:54 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9095/jmxrmi
Dec 03, 2021 11:55:55 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575755},"message":{"recording":"interleaved-2","target":"cryostat-itests:9095"}}
Dec 03, 2021 11:55:55 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36100): POST /api/v1/targets/cryostat-itests:9095/recordings 201 2327ms
Dec 03, 2021 11:55:55 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9096/jmxrmi
Dec 03, 2021 11:55:56 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575756},"message":{"recording":"interleaved-3","target":"cryostat-itests:9096"}}
Dec 03, 2021 11:55:56 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36102): POST /api/v1/targets/cryostat-itests:9096/recordings 201 3308ms
Dec 03, 2021 11:55:56 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9097/jmxrmi
Dec 03, 2021 11:55:57 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575757},"message":{"recording":"interleaved-4","target":"cryostat-itests:9097"}}
Dec 03, 2021 11:55:57 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36104): POST /api/v1/targets/cryostat-itests:9097/recordings 201 4352ms
Dec 03, 2021 11:55:57 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9098/jmxrmi
Dec 03, 2021 11:55:58 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575758},"message":{"recording":"interleaved-5","target":"cryostat-itests:9098"}}
Dec 03, 2021 11:55:58 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36106): POST /api/v1/targets/cryostat-itests:9098/recordings 201 5487ms
Dec 03, 2021 11:55:58 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9100/jmxrmi
Dec 03, 2021 11:55:58 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9094
Dec 03, 2021 11:55:59 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575759},"message":{"recording":"interleaved-7","target":"cryostat-itests:9100"}}
Dec 03, 2021 11:55:59 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35854): POST /api/v1/targets/cryostat-itests:9100/recordings 201 5173ms
Dec 03, 2021 11:55:59 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9099/jmxrmi
Dec 03, 2021 11:56:00 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9095
Dec 03, 2021 11:56:00 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575760},"message":{"recording":"interleaved-6","target":"cryostat-itests:9099"}}
Dec 03, 2021 11:56:00 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36100): POST /api/v1/targets/cryostat-itests:9099/recordings 201 5117ms
Dec 03, 2021 11:56:00 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9093/jmxrmi
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9096
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1638575761},"message":{"recording":"interleaved-0","target":"cryostat-itests:9093"}}
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36102): POST /api/v1/targets/cryostat-itests:9093/recordings 201 5189ms
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36102): GET /api/v1/targets/cryostat-itests:9093/recordings 200 40ms
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9094/jmxrmi
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36100): GET /api/v1/targets/cryostat-itests:9094/recordings 200 147ms
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9097/jmxrmi
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9097
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9097
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger error
SEVERE: HTTP 500: Could not retrieve the attribute Recordings!
io.vertx.ext.web.handler.impl.HttpStatusException: Internal Server Error
Caused by: org.openjdk.jmc.rjmx.services.jfr.FlightRecorderException: Could not retrieve the attribute Recordings!
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.getAttribute(FlightRecorderCommunicationHelperV2.java:69)
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderServiceV2.getAvailableRecordings(FlightRecorderServiceV2.java:298)
	at io.cryostat.net.web.http.api.v1.TargetRecordingsGetHandler.lambda$handleAuthenticated$0(TargetRecordingsGetHandler.java:115)
	at io.cryostat.net.TargetConnectionManager.executeConnectedTask(TargetConnectionManager.java:136)
	at io.cryostat.net.web.http.api.v1.TargetRecordingsGetHandler.handleAuthenticated(TargetRecordingsGetHandler.java:111)
	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.io.IOException: The client has been closed.
	at java.management/com.sun.jmx.remote.internal.ClientCommunicatorAdmin.restart(ClientCommunicatorAdmin.java:99)
	at java.management/com.sun.jmx.remote.internal.ClientCommunicatorAdmin.gotIOException(ClientCommunicatorAdmin.java:59)
	at java.management.rmi/javax.management.remote.rmi.RMIConnector$RMIClientCommunicatorAdmin.gotIOException(RMIConnector.java:1497)
	at java.management.rmi/javax.management.remote.rmi.RMIConnector$RemoteMBeanServerConnection.getAttribute(RMIConnector.java:908)
	at org.openjdk.jmc.rjmx.subscription.internal.AttributeValueToolkit.getAttribute(AttributeValueToolkit.java:78)
	at org.openjdk.jmc.rjmx.internal.MCMBeanServerConnection.getAttribute(MCMBeanServerConnection.java:180)
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.getJfrAttribute(FlightRecorderCommunicationHelperV2.java:76)
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.getAttribute(FlightRecorderCommunicationHelperV2.java:67)
	... 13 more
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:36104): GET /api/v1/targets/cryostat-itests:9097/recordings 500 335ms

This part right before the stack trace looks suspicious:

Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat-itests:9097/jmxrmi
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9097
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for cryostat-itests:9097
Dec 03, 2021 11:56:01 PM io.cryostat.core.log.Logger error
SEVERE: HTTP 500: Could not retrieve the attribute Recordings!
io.vertx.ext.web.handler.impl.HttpStatusException: Internal Server Error

Is it possible that somehow the connection was closed prematurely, or somehow closed twice? This is without #763 so no potential concrete explanation comes to mind. Perhaps the connection was closed because the test container with port 9097 was killed by the CI runner at just the wrong moment and so this is just a spurious intermittent failure.

https://github.com/cryostatio/cryostat/runs/4414284959?check_suite_focus=true#step:9:833
@andrewazores andrewazores added the bug Something isn't working label Dec 4, 2021
@andrewazores
Copy link
Member Author

I haven't seen this in quite some time and I believe it has probably been fixed for good with the JMC8 upgrade in -core. Closing for now.

@andrewazores andrewazores mentioned this issue Jan 10, 2024
Merged
7 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@andrewazores