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

Cleanly handle Snapshots taken when there is no source data #715

Closed
andrewazores opened this issue Oct 12, 2021 · 2 comments · Fixed by #743
Closed

Cleanly handle Snapshots taken when there is no source data #715

andrewazores opened this issue Oct 12, 2021 · 2 comments · Fixed by #743
Assignees
@hareetd
Labels
bug Something isn't working

Comments

@andrewazores
Copy link
Member

It is currently possible to take a Snapshot recording even when the target VM has no running recordings, or has only empty recordings, etc. This will reliably create recordings with 0 length.

This can be easily reproduced:

$ sh smoketest.sh
$ https POST :8181/api/v1/targets/localhost:9093/snapshot

Or:

  1. Open the web-client
  2. Select a target application with no active recordings
  3. Navigate to Recordings
  4. Click Create
  5. Switch to Snapshot tab
  6. Click Create

These 0-length snapshots cause various problems for other features:

Report Generation:
image

View in Grafana / Download Recording / Download Report:
image

Attempting to archive such a recording appears to fail silently in the web-client UI, but the backend logs show this:

Oct 12, 2021 7:01:26 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:53814): POST /api/v1/auth 200 0ms
Oct 12, 2021 7:01:28 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:53814): POST /api/v1/auth 200 0ms
Oct 12, 2021 7:01:28 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi
Oct 12, 2021 7:01:28 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:53814): PATCH /api/v1/targets/service%3Ajmx%3Armi%3A%2F%2F%2Fjndi%2Frmi%3A%2F%2Fcryostat%3A9093%2Fjmxrmi/recordings/snapshot-1 204 79ms
Oct 12, 2021 7:01:28 PM io.cryostat.core.log.Logger error
SEVERE: HTTP 500: io.cryostat.recordings.EmptyRecordingException: java.io.IOException: java.io.IOException: No recording data available
	io.vertx.ext.web.handler.impl.HttpStatusException: Internal Server Error
Caused by: java.util.concurrent.ExecutionException: io.cryostat.recordings.EmptyRecordingException: java.io.IOException: java.io.IOException: No recording data available
	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.web.http.api.v1.TargetRecordingPatchSave.handle(TargetRecordingPatchSave.java:67)
	at io.cryostat.net.web.http.api.v1.TargetRecordingPatchHandler.handleAuthenticated(TargetRecordingPatchHandler.java:108)
	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.recordings.EmptyRecordingException: java.io.IOException: java.io.IOException: No recording data available
	at io.cryostat.recordings.RecordingArchiveHelper.writeRecordingToDestination(RecordingArchiveHelper.java:361)
	at io.cryostat.recordings.RecordingArchiveHelper.lambda$saveRecording$0(RecordingArchiveHelper.java:138)
	at io.cryostat.net.TargetConnectionManager.executeConnectedTask(TargetConnectionManager.java:136)
	at io.cryostat.recordings.RecordingArchiveHelper.saveRecording(RecordingArchiveHelper.java:131)
	... 11 more
Caused by: java.io.IOException: java.io.IOException: No recording data available
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.invokeOperation(JfrRecordingInputStreamV2.java:206)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.openStream(JfrRecordingInputStreamV2.java:181)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.openStream(JfrRecordingInputStreamV2.java:167)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.readStreamIdentifier(JfrRecordingInputStreamV2.java:120)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.fill(JfrRecordingInputStreamV2.java:104)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.read(JfrRecordingInputStreamV2.java:94)
	at java.base/java.io.InputStream.read(InputStream.java:271)
	at java.base/java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
	at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:271)
	at io.cryostat.recordings.RecordingArchiveHelper.writeRecordingToDestination(RecordingArchiveHelper.java:356)
	... 14 more
Caused by: java.io.IOException: java.io.IOException: No recording data available
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.invokeOperation(FlightRecorderCommunicationHelperV2.java:84)
	at org.openjdk.jmc.rjmx.services.jfr.internal.JfrRecordingInputStreamV2.invokeOperation(JfrRecordingInputStreamV2.java:197)
	... 23 more
Caused by: javax.management.MBeanException: java.io.IOException: No recording data available
	at java.management/com.sun.jmx.mbeanserver.MBeanIntrospector.unwrapInvocationTargetException(MBeanIntrospector.java:313)
	at java.management/com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:239)
	at java.management/com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138)
	at java.management/com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252)
	at java.management/javax.management.StandardMBean.invoke(StandardMBean.java:405)
	at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:809)
	at java.management/com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1466)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1307)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1399)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:827)
	at java.base/jdk.internal.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at java.rmi/sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:359)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:200)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:197)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.Transport.serviceCall(Transport.java:196)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:562)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
	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:834)
	at java.rmi/sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:303)
	at java.rmi/sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:279)
	at java.rmi/sun.rmi.server.UnicastRef.invoke(UnicastRef.java:164)
	at jdk.remoteref/jdk.jmx.remote.internal.rmi.PRef.invoke(Unknown Source)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl_Stub.invoke(Unknown Source)
	at java.management.rmi/javax.management.remote.rmi.RMIConnector$RemoteMBeanServerConnection.invoke(RMIConnector.java:1021)
	at org.openjdk.jmc.rjmx.internal.MCMBeanServerConnection.invoke(MCMBeanServerConnection.java:259)
	at org.openjdk.jmc.rjmx.ConnectionToolkit.invokeOperation(ConnectionToolkit.java:196)
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.invokeJfrOperation(FlightRecorderCommunicationHelperV2.java:91)
	at org.openjdk.jmc.rjmx.services.jfr.internal.FlightRecorderCommunicationHelperV2.invokeOperation(FlightRecorderCommunicationHelperV2.java:82)
	... 24 more
Caused by: java.io.IOException: No recording data available
	at jdk.management.jfr/jdk.management.jfr.FlightRecorderMXBeanImpl.openStream(FlightRecorderMXBeanImpl.java:152)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:71)
	at jdk.internal.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at java.base/sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:260)
	at java.management/com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:193)
	at java.management/com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:175)
	at java.management/com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:117)
	at java.management/com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:54)
	at java.management/com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237)
	at java.management/com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138)
	at java.management/com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252)
	at java.management/javax.management.StandardMBean.invoke(StandardMBean.java:405)
	at java.management/com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:809)
	at java.management/com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doOperation(RMIConnectionImpl.java:1466)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl$PrivilegedOperation.run(RMIConnectionImpl.java:1307)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.doPrivilegedOperation(RMIConnectionImpl.java:1399)
	at java.management.rmi/javax.management.remote.rmi.RMIConnectionImpl.invoke(RMIConnectionImpl.java:827)
	at java.base/jdk.internal.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at java.rmi/sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:359)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:200)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:197)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.Transport.serviceCall(Transport.java:196)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:562)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
	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:834)

When a Snapshot is created, Cryostat should check that the resultant recording is non-empty. If it is empty then the snapshot should be deleted and an appropriate HTTP response sent to the user, other than a 200, so that there is some indication that the request was received and processed but there is no result (HTTP 204 sounds appropriate, but this implies there is no response body. HTTP 202?)
@andrewazores andrewazores added the bug Something isn't working label Oct 12, 2021
This was referenced Oct 12, 2021
Open
Closed
@hareetd hareetd self-assigned this Oct 21, 2021
@hareetd
Copy link
Contributor

hareetd commented Oct 25, 2021 •
edited
Loading

Since this issue requires API changes (introduction of a new status code) should I apply these changes to just the v2 version of the TargetSnapshotPostHandler or both v1 and v2? From meetings, I remember hearing that we'll pick and choose which changes from main to incorporate into the v2 branch.

@andrewazores
Copy link
Member Author

I think in this case we can apply it to both. I would consider this to be a bugfix, and that clients shouldn't be relying on the 0-length snapshots being valid and returning a 200 status.

@hareetd hareetd mentioned this issue Nov 2, 2021
Merged
@hareetd hareetd mentioned this issue Nov 30, 2021
Closed
@andrewazores andrewazores moved this to Done in 2.1.0 Release Dec 9, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@hareetd hareetd

Labels
bug Something isn't working
Projects
No open projects
2.1.0 Release
Status: Done
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix(snapshot): Cleanly handle empty snapshots
2 participants
@andrewazores @hareetd