fix(archives): add target-specific archive API endpoints

[hareetd]

Fixes #1046 Depends on https://github.com/cryostatio/cryostat-web/pull/499

Summary:

1. I've added five new beta target-specific archived recording handlers: RecordingDeleteHandler, RecordingUploadPostHandler, RecordingGetHandler, RecordingGetWithJwtHandler, ReportGetHandler and ReportGetWithJwtHandler. They're essentially equivalent to their v1/v2 counterparts, except with an added sourceTarget request parameter that expects the JMX connection URL of the source target for the archived recording in question.

2. The WebServer now points to the beta RecordingGetHandler and ReportGetHandler endpoints when the WebServer#getArchivedDownloadUrl and WebServer#getArchivedReportUrl methods are called, respectively. This means archived recording-related notifications will now contain target-specific download URLs. Notifications have also been updated so that the target field is equal to "uploads" rather than the empty string for uploaded recordings. This is because for the new target-specific handlers the sourceTarget parameter cannot be set to the empty string in place of a connectUrl for uploaded recordings. Since the "uploads" string is the logical alternative to use for this parameter, in order to maintain consistency, notifications also explicitly identify a recording as having originated as an upload directly into Cryostat's archives.

3. The implementation should still preserve the functionality of the older, non-target-specific v1/v2 handlers. I didn't have time to manually test but unit and integration tests are all passing. In the case where such an endpoint is called, the archives are searched using only the recording name, which is still error-prone for the reasons discussed in https://github.com/cryostatio/cryostat-web/issues/445. Perhaps these handlers should now be marked as deprecated?

4. For the cached report path, if no sourceTarget is provided the report is placed inside a new default subdirectory which is itself inside the temporary directory provided by the WebServer. Uploaded recordings are placed inside an uploads subdirectory and target-specific recordings inside a subdirectory named according to the target's Base32 encoded connectUrl. See my comment below on issues with creating these subdirectories.

5. The web-client in https://github.com/cryostatio/cryostat-web/pull/499 has been updated to use the new beta handlers in place of the old ones (I might have missed something though, so please double-check). Unfortunately, the View Report functionality is broken as it keeps timing out with the report not being delivered. However, I'm experiencing this behavior on the main branch as well, so could be a general issue or an error on my part. The report dropdown generation works as expected.

6. See also cryostatio/cryostat#1045 when working on the backend implementation discussed above. The fix applied to the existing handler should also be present in the new handlers.

original comment by @andrewazores: https://github.com/cryostatio/cryostat-web/issues/445#issuecomment-1219655394

I ran out of time to implement this request. New tests and HTTP API documentation also need to be added still.

7. Overall, I didn't have as much time as I would have liked to check things over, so please take a closer look at the code as it touches on a lot of the archived recordings-related functionality. Thanks!

TODOs [Max, Thuan]:

• [x] Fixed generation of archive sub-directories should be checked for existence and updated test mocks.
• [x] Deprecating old v1/v2 handlers and updating tests for rejection when requests are sent to deprecated endpoints.
• [x] Fixed View Report concurrency issue that leads to report generation timeout error.
• [x] Updated archive-related tests.
• [x] Overall clean-ups
• [x] Uploaded recordings' metadata should be handled.

[github-actions[bot]]

This PR/issue depends on:

• cryostatio/cryostat-web#499 By Dependent Issues (🤖). Happy coding!

[hareetd]

There are still some minor kinks to iron out, I'm hoping to have the implementation done and working by tomorrow, likely won't have time to add new tests (I'm updating existing tests as I go).

[andrewazores]

@maxcao13 @tthvo this is in a mostly completed state now but as @hareetd says, it's still in need of some finishing touches before merge. Would either of you like to take over the development side as I review it? I don't think this is far off from being mergeable.

[andrewazores]

Thanks for taking this on and getting so much of it done in the final stretch of your internship, @hareetd . This looks quite good as it is, and I'm really looking forward to getting it merged because it's also an important milestone for #520/cryostat-agent.

[hareetd]

@andrewazores No problem, it was a fun way to end off the internship :-). Also, good to hear that it's an important part of those features, it'll definitely be nice to have a more clear link between targets and their archived data.

Well, this is my final sign-off. Best of luck with Cryostat and hopefully our paths cross in the future!

[tthvo]

I think we can start on this! There is also front-end work so I will talk with @maxcao13 to divide the work to get them done.

[tthvo]

The implementation should still preserve the functionality of the older, non-target-specific v1/v2 handlers. I didn't have time to manually test but unit and integration tests are all passing. In the case where such an endpoint is called, the archives are searched using only the recording name, which is still error-prone for the reasons discussed in https://github.com/cryostatio/cryostat-web/issues/445. Perhaps these handlers should now be marked as deprecated?

To avoid such issue, we start to disable these handlers by setting isAvailable() to return false and mark the classes as @Deprecated for now. Though, I believe we want to remove them later as https://github.com/cryostatio/cryostat/pull/971#issuecomment-1227765350. Any thoughts?

Edit: With this, Cryostat will return 404 if requested to these non-target-specific routes.

[andrewazores]

Perhaps the most client-friendly thing to do for the next release is to mark the class as @Deprecated and return a 410 Gone status. We could also send a response header that informs the client that they should use the updated API endpoint(s) instead.

[andrewazores]

Oh boy, that's a bunch of conflicts :/

Can we also add some logic either to these new handlers or within ex. RecordingArchiveHelper so that the sourceTarget is verified to exist? I think think should be as simple as checking that the sourceTarget URL matches some connectUrl in discoveryStorage.listDiscoverableServices().

[maxcao13]

Oh boy, that's a bunch of conflicts :/

Yeah, I've been dreading these conflicts cause I've been working on both :-)

Can we also add some logic either to these new handlers or within ex. RecordingArchiveHelper so that the sourceTarget is verified to exist? I think think should be as simple as checking that the sourceTarget URL matches some connectUrl in discoveryStorage.listDiscoverableServices().

For sure, thanks for the feedback. I'm wondering about task 6, https://github.com/cryostatio/cryostat-web/issues/445#issuecomment-1219655394 This PR no longer has to include this issue right?

I think all we need to do about the uploading metadata issue now is to update the web-client to handle the recent merge https://github.com/cryostatio/cryostat/pull/1063 with this associated PR https://github.com/cryostatio/cryostat-web/pull/499 ?

[andrewazores]

I believe so, yes.

[maxcao13]

Can we also add some logic either to these new handlers or within ex. RecordingArchiveHelper so that the sourceTarget is verified to exist? I think think should be as simple as checking that the sourceTarget URL matches some connectUrl in discoveryStorage.listDiscoverableServices().

If we do it this way, the endpoints won't be able to work if the sourceTarget is something like cryostat:9091 because the discoverableServices is a list of ServiceRefs and the connectUrl is something like service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi. We could go the route of testing a connection to the sourceTarget through the connectUrl to solve this, but then it just seems like re-using functionality of a TargetRecording.

Also, if a user still wanted to delete an archived recording from their fs (from the command line), but the target was gone and removed from the database, I don't think either solutions would work.

What do you think?

[andrewazores]

Command line (curl, httpie) vs web-client shouldn't matter, in the end they're both talking to the API as the source of data about what is present and what actions can be performed.

If we do it this way, the endpoints won't be able to work if the sourceTarget is something like cryostat:9091 because the discoverableServices is a list of ServiceRefs and the connectUrl is something like service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi.

So we can apply the transformation of cryostat:9091 -> service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi early, at the API endpoints, rather than allowing those "bare" host:port values to trickle all the way down. Anything that is already in storage can be pretty easily checked for proper JMXServiceURL format and migrated if it's not. Or if the plan is for the archives to also use the jvmId, which is pretty reasonable, then the storage and migration should be handled the same way that you did for the metadata.

Though, this now has me wondering what to do about push-only agents. They won't publish JMXServiceURLs and won't be connectable over JMX, so Cryostat won't be able to compute a jvmId hash for them. Their connectUrl is probably going to be the http:// callback URL or maybe modified with some custom scheme like cryostat-agent:// to mark what they are. But the built-in discoveries use null for their callback URL.

Perhaps we need another set of similar endpoints for agents to push JFR files to? Rather than using the connectUrl as the targetId/sourceTarget, they would use their discovery registration ID.

Also, if a user still wanted to delete an archived recording from their fs (from the command line), but the target was gone and removed from the database, I don't think either solutions would work.

Fair - so just don't enforce that check on the deletion action, but do enforce it on the upload.

[maxcao13]

So we can apply the transformation of cryostat:9091 -> service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi early, at the API endpoints, rather than allowing those "bare" host:port values to trickle all the way down. Anything that is already in storage can be pretty easily checked for proper JMXServiceURL format and migrated if it's not. Or if the plan is for the archives to also use the jvmId, which is pretty reasonable, then the storage and migration should be handled the same way that you did for the metadata.

I'll probably start to use the jvmIds here as well because of https://github.com/cryostatio/cryostat/issues/972

Though, this now has me wondering what to do about push-only agents. They won't publish JMXServiceURLs and won't be connectable over JMX, so Cryostat won't be able to compute a jvmId hash for them. Their connectUrl is probably going to be the http:// callback URL or maybe modified with some custom scheme like cryostat-agent:// to mark what they are. But the built-in discoveries use null for their callback URL.

Perhaps we need another set of similar endpoints for agents to push JFR files to? Rather than using the connectUrl as the targetId/sourceTarget, they would use their discovery registration ID.

Seems reasonable, I guess that should be another PR for later.

[maxcao13]

Ignoring tests, thoughts on the structure or anything else?

The reason I have the migration and TargetDiscoveryEvent accept Archives logic in the RecordingMetadataManager is because I felt that both did similar things and I needed a way to be able to manage the subdirectories again because of the fact that jvmIds change after every run (since they include time as part of the hash). So putting it in different classes felt odd as they both would fight for the jvmId map, and even though it's a ConcurrentMap, to me it made sense to just put all the similar logic in the same class so that they make sense synchronously. Maybe it even makes sense to rename the RecordingMetadataManager to something like RecordingFilesManager or something like that.

Something else I added is a "metadata-like" file in each archives/* subdirectory very helpfully named connectUrl. All it does is contain the connectUrl for the associated archived directory. The reason something like that is needed is again, because of the way jvmIds work and the reason why we didn't need this in the metadata PR is because the targetId was contained in the metadata itself so it was easy to read it from a json file. And the reason why it wasn't needed before was because the subdirectory was literally just the base32 encoding of the folder name. I was also thinking maybe just including the encoded targetId part of the folder name, but just appended by some delimiter like - or _, but a small disadvantage would be the huge subdirectory name and parsing it. I did it the way in the PR as just a quick and dirty method but I doesn't have to be this way.

I still need to update the web-client and update tests.

[andrewazores]

Ignoring tests, thoughts on the structure or anything else?

The reason I have the migration and TargetDiscoveryEvent accept Archives logic in the RecordingMetadataManager is because I felt that both did similar things and I needed a way to be able to manage the subdirectories again because of the fact that jvmIds change after every run (since they include time as part of the hash). So putting it in different classes felt odd as they both would fight for the jvmId map, and even though it's a ConcurrentMap, to me it made sense to just put all the similar logic in the same class so that they make sense synchronously. Maybe it even makes sense to rename the RecordingMetadataManager to something like RecordingFilesManager or something like that.

Sure, this all makes sense. I will note that the nature of the jvmId being a consistent hash of "fixed" (for the target's lifecycle) properties should mean that we can have various different classes which all compute and maintain their own jvmId maps, and they would all end up agreeing with each other since the computed hash is the same for a given target no matter who is looking at it. But, keeping only one such jvmId map around makes practical sense for a lot of reasons, so the JvmIdHelper class makes sense. This does seem like it could possibly be merged with the TargetConnectionManager, but that can be a refactoring for later.

Something else I added is a "metadata-like" file in each archives/* subdirectory very helpfully named connectUrl. All it does is contain the connectUrl for the associated archived directory. The reason something like that is needed is again, because of the way jvmIds work and the reason why we didn't need this in the metadata PR is because the targetId was contained in the metadata itself so it was easy to read it from a json file. And the reason why it wasn't needed before was because the subdirectory was literally just the base32 encoding of the folder name. I was also thinking maybe just including the encoded targetId part of the folder name, but just appended by some delimiter like - or _, but a small disadvantage would be the huge subdirectory name and parsing it. I did it the way in the PR as just a quick and dirty method but I doesn't have to be this way.

I think this solution is fine. The subdirectory name could really explode in length if we encode the URL and append that on top of something else like an ID hash. If URLs are particularly long we might even run into the Linux filename length limit.

[maxcao13]

I missed this in the other PR but noticed that you deprecated the RecordingsPostHandler and RecordingsGetHandler in the HTTP docs. Those are not being replaced in this PR so a new issue will have to be made.

[andrewazores]

Archive migration doesn't seem to have worked for me:

[trimmed]
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi Metadata transfer: 19Hg0b1dcO7oZs7IXds_PILYOVpbCHkhHSLnbj45_N8= -> nFSPcJntBSMrB1UOZMSPXlQBkZhM3SAsHCek_CqT6iQ=
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi Metadata successfully transferred: 19Hg0b1dcO7oZs7IXds_PILYOVpbCHkhHSLnbj45_N8= -> nFSPcJntBSMrB1UOZMSPXlQBkZhM3SAsHCek_CqT6iQ=
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger error
SEVERE: Archives subdirectory could not be renamed upon target restart
java.nio.file.NoSuchFileException: /opt/cryostat.d/recordings.d/GE4UQZZQMIYWIY2PG5XVU4ZXJFMGI427KBEUYWKPKZYGEQ2INNUEQU2MNZRGUNBVL5HDQPI=
	at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
	at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106)
	at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
	at java.base/sun.nio.fs.UnixFileSystemProvider.newDirectoryStream(UnixFileSystemProvider.java:440)
	at java.base/java.nio.file.Files.newDirectoryStream(Files.java:482)
	at java.base/java.nio.file.Files.list(Files.java:3792)
	at io.cryostat.core.sys.FileSystem.listDirectoryChildren(FileSystem.java:98)
	at io.cryostat.recordings.RecordingArchiveHelper.transferArchives(RecordingArchiveHelper.java:196)
	at io.cryostat.recordings.RecordingMetadataManager.accept(RecordingMetadataManager.java:420)
	at io.cryostat.recordings.RecordingMetadataManager.accept(RecordingMetadataManager.java:92)
	at io.cryostat.discovery.AbstractPlatformClientVerticle.lambda$notifyAsyncTargetDiscovery$0(AbstractPlatformClientVerticle.java:71)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at io.cryostat.discovery.AbstractPlatformClientVerticle.notifyAsyncTargetDiscovery(AbstractPlatformClientVerticle.java:71)
	at io.cryostat.discovery.DiscoveryStorage.lambda$update$10(DiscoveryStorage.java:238)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
	at java.base/java.util.HashMap$KeySpliterator.forEachRemaining(HashMap.java:1707)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
	at io.cryostat.discovery.DiscoveryStorage.update(DiscoveryStorage.java:238)
	at io.cryostat.discovery.BuiltInDiscovery.lambda$start$1(BuiltInDiscovery.java:107)
	at io.cryostat.platform.AbstractPlatformClient.lambda$notifyAsyncTargetDiscovery$0(AbstractPlatformClient.java:65)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at io.cryostat.platform.AbstractPlatformClient.notifyAsyncTargetDiscovery(AbstractPlatformClient.java:65)
	at io.cryostat.platform.internal.DefaultPlatformClient.accept(DefaultPlatformClient.java:96)
	at io.cryostat.platform.internal.DefaultPlatformClient.accept(DefaultPlatformClient.java:65)
	at io.cryostat.core.net.discovery.JvmDiscoveryClient$1.lambda$onDiscovery$0(JvmDiscoveryClient.java:75)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at io.cryostat.core.net.discovery.JvmDiscoveryClient$1.onDiscovery(JvmDiscoveryClient.java:73)
	at org.openjdk.jmc.jdp.client.PacketProcessor.fireEvent(PacketProcessor.java:103)
	at org.openjdk.jmc.jdp.client.PacketProcessor.process(PacketProcessor.java:82)
	at org.openjdk.jmc.jdp.client.PacketListener.run(PacketListener.java:77)
	at java.base/java.lang.Thread.run(Thread.java:833)

Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1663976907},"message":{"event":{"serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9093","JAVA_MAIN":"es.andrewazor.demo.Main","REALM":"JDP"}}},"kind":"FOUND"}}}
Hibernate: 
    select
        plugininfo0_.id as id1_0_0_,
        plugininfo0_.callback as callback2_0_0_,
        plugininfo0_.realm as realm3_0_0_,
        plugininfo0_.subtree as subtree4_0_0_ 
    from
        PluginInfo plugininfo0_ 
    where
        plugininfo0_.id=?
Hibernate: 
    /* load io.cryostat.discovery.PluginInfo */ select
        plugininfo0_.id as id1_0_0_,
        plugininfo0_.callback as callback2_0_0_,
        plugininfo0_.realm as realm3_0_0_,
        plugininfo0_.subtree as subtree4_0_0_ 
    from
        PluginInfo plugininfo0_ 
    where
        plugininfo0_.id=?
Hibernate: 
    /* update
        io.cryostat.discovery.PluginInfo */ update
            PluginInfo 
        set
            callback=?,
            realm=?,
            subtree=? 
        where
            id=?
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Target service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi did not have a jvmId
Hibernate: 
    /* select
        generatedAlias0 
    from
        PluginInfo as generatedAlias0 */ select
            plugininfo0_.id as id1_0_,
            plugininfo0_.callback as callback2_0_,
            plugininfo0_.realm as realm3_0_,
            plugininfo0_.subtree as subtree4_0_ 
        from
            PluginInfo plugininfo0_
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Created jvmId vLA7wcAJF-psQ9K4nU8kw_7Cns-eZLegW1y6B9rhZzg= for target service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1663976907},"message":{"event":{"serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi","alias":"/deployments/quarkus-run.jar","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"10000","JAVA_MAIN":"/deployments/quarkus-run.jar","REALM":"JDP"}}},"kind":"FOUND"}}}
Hibernate: 
    select
        plugininfo0_.id as id1_0_0_,
        plugininfo0_.callback as callback2_0_0_,
        plugininfo0_.realm as realm3_0_0_,
        plugininfo0_.subtree as subtree4_0_0_ 
    from
        PluginInfo plugininfo0_ 
    where
        plugininfo0_.id=?
Hibernate: 
    /* load io.cryostat.discovery.PluginInfo */ select
        plugininfo0_.id as id1_0_0_,
        plugininfo0_.callback as callback2_0_0_,
        plugininfo0_.realm as realm3_0_0_,
        plugininfo0_.subtree as subtree4_0_0_ 
    from
        PluginInfo plugininfo0_ 
    where
        plugininfo0_.id=?
Hibernate: 
    /* update
        io.cryostat.discovery.PluginInfo */ update
            PluginInfo 
        set
            callback=?,
            realm=?,
            subtree=? 
        where
            id=?
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Target service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi did not have a jvmId
Sep 23, 2022 11:48:27 PM io.cryostat.core.log.Logger info
INFO: Creating connection for service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 23, 2022 11:48:28 PM io.cryostat.core.log.Logger info
INFO: Created jvmId KnmCa0dnx1chHG-akfKVdPkKAn2tVyFJPsSkCEam-8A= for target service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 23, 2022 11:48:28 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1663976908},"message":{"event":{"serviceRef":{"connectUrl":"service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi","alias":"es.andrewazor.demo.Main","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9094","JAVA_MAIN":"es.andrewazor.demo.Main","REALM":"JDP"}}},"kind":"FOUND"}}}
Sep 23, 2022 11:48:28 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ActiveRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1663976908},"message":{"target":"service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi","recording":{"downloadUrl":"http://localhost:8181/api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Fcryostat:9093%2Fjmxrmi/recordings/auto_myrule","reportUrl":"http://localhost:8181/api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Fcryostat:9093%2Fjmxrmi/reports/auto_myrule","metadata":{"labels":{}},"id":1,"name":"auto_myrule","state":"RUNNING","startTime":1663976908091,"duration":0,"continuous":true,"toDisk":true,"maxSize":52428800,"maxAge":0}}}
Sep 23, 2022 11:48:28 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ActiveRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1663976908},"message":{"target":"service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi","recording":{"downloadUrl":"http://localhost:8181/api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Fcryostat:9094%2Fjmxrmi/recordings/auto_myrule","reportUrl":"http://localhost:8181/api/v1/targets/service:jmx:rmi:%2F%2F%2Fjndi%2Frmi:%2F%2Fcryostat:9094%2Fjmxrmi/reports/auto_myrule","metadata":{"labels":{}},"id":1,"name":"auto_myrule","state":"RUNNING","startTime":1663976908806,"duration":0,"continuous":true,"toDisk":true,"maxSize":52428800,"maxAge":0}}}
Sep 23, 2022 11:48:32 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi: EXPIRED
Sep 23, 2022 11:48:32 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi closed
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:37028): GET /api/v1/notifications_url 200 0ms
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger warn
WARNING: HTTP 401: HTTP Authorization Failure
io.vertx.ext.web.handler.HttpException: Unauthorized
Caused by: io.cryostat.net.web.http.api.v2.ApiException: HTTP Authorization Failure
	at io.cryostat.net.web.http.api.v2.AuthPostHandler.lambda$handle$3(AuthPostHandler.java:136)
	at java.base/java.util.Optional.orElseGet(Optional.java:364)
	at io.cryostat.net.web.http.api.v2.AuthPostHandler.handle(AuthPostHandler.java:117)
	at io.cryostat.net.web.http.api.v2.AbstractV2RequestHandler.handle(AbstractV2RequestHandler.java:121)
	at io.cryostat.net.web.http.api.v2.AbstractV2RequestHandler.handle(AbstractV2RequestHandler.java:75)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: io.cryostat.net.UnknownUserException: User information requested for unknown user: "null"
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.net.web.http.api.v2.AuthPostHandler.lambda$handle$3(AuthPostHandler.java:132)
	... 13 more
Caused by: io.cryostat.net.UnknownUserException: User information requested for unknown user: "null"
	at io.cryostat.net.BasicAuthManager.getUserInfo(BasicAuthManager.java:93)
	at io.cryostat.net.web.http.api.v2.AuthPostHandler.lambda$handle$3(AuthPostHandler.java:125)
	... 13 more
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:37012): POST /api/v2.1/auth 401 60ms
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:37018): GET /health 200 185ms
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:37018): GET /api/v1/grafana_datasource_url 200 0ms
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:37028): GET /api/v1/grafana_dashboard_url 200 0ms
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9096/jmxrmi: EXPIRED
Sep 23, 2022 11:48:33 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9096/jmxrmi closed
Sep 23, 2022 11:48:34 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi: EXPIRED
Sep 23, 2022 11:48:34 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9095/jmxrmi: EXPIRED
Sep 23, 2022 11:48:34 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9095/jmxrmi closed
Sep 23, 2022 11:48:34 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9091/jmxrmi closed
Sep 23, 2022 11:48:36 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9197/jmxrmi: EXPIRED
Sep 23, 2022 11:48:36 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9097/jmxrmi: EXPIRED
Sep 23, 2022 11:48:36 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9097/jmxrmi closed
Sep 23, 2022 11:48:36 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9197/jmxrmi closed
Sep 23, 2022 11:48:37 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi: EXPIRED
Sep 23, 2022 11:48:37 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi closed
Sep 23, 2022 11:48:38 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi: EXPIRED
Sep 23, 2022 11:48:38 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi: EXPIRED
Sep 23, 2022 11:48:38 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi closed
Sep 23, 2022 11:48:38 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi closed
Sep 23, 2022 11:48:52 PM io.cryostat.core.log.Logger warn
WARNING: Target unreachable service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi, msg null
Sep 23, 2022 11:48:52 PM io.cryostat.core.log.Logger info
INFO: Active recording lost auto_myrule, deleting...
Sep 23, 2022 11:48:52 PM io.cryostat.core.log.Logger info
INFO: Deleted metadata file /opt/cryostat.d/conf.d/metadata/GE4UQZZQMIYWIY2PG5XVU4ZXJFMGI427KBEUYWKPKZYGEQ2INNUEQU2MNZRGUNBVL5HDQPI=/MF2XI327NV4XE5LMMU======.json
Sep 23, 2022 11:48:52 PM io.cryostat.core.log.Logger info
INFO: Successfully pruned all stale metadata
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35986): OPTIONS /api/v2.1/auth 204 0ms
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35996): POST /api/v2.1/auth 200 1ms
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Connected remote client 10.0.2.100:36006
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"WsClientActivity","type":{"type":"application","subType":"json"},"serverTime":1663977048},"message":{"10.0.2.100:36006":"connected"}}
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Exception thrown
io.cryostat.net.AuthorizationErrorException: 
	at io.cryostat.messaging.MessagingServer.lambda$start$4(MessagingServer.java:156)
	at io.cryostat.net.AbstractAuthManager$1.execute(AbstractAuthManager.java:79)
	at io.cryostat.messaging.MessagingServer.lambda$start$5(MessagingServer.java:159)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Disconnected remote client 10.0.2.100:36006 due to authentication failure
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"WsClientActivity","type":{"type":"application","subType":"json"},"serverTime":1663977048},"message":{"10.0.2.100:36006":"auth failure"}}
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Disconnected remote client 10.0.2.100:36006
Sep 23, 2022 11:50:48 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"WsClientActivity","type":{"type":"application","subType":"json"},"serverTime":1663977048},"message":{"10.0.2.100:36006":"disconnected"}}
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35996): POST /api/v2.1/auth 200 0ms
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: Connected remote client 10.0.2.100:36020
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"WsClientActivity","type":{"type":"application","subType":"json"},"serverTime":1663977049},"message":{"10.0.2.100:36020":"connected"}}
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: Authenticated remote client 10.0.2.100:36020
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"WsClientActivity","type":{"type":"application","subType":"json"},"serverTime":1663977049},"message":{"10.0.2.100:36020":"accepted"}}
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35986): OPTIONS /api/v1/recordings 204 0ms
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger info
INFO: (10.0.2.100:35986): OPTIONS /api/v1/targets 204 0ms
Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger warn
WARNING: Couldn't get connectUrl from file system
java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:248)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:528)
	at io.cryostat.net.web.http.api.v1.RecordingsGetHandler.handleAuthenticated(RecordingsGetHandler.java:113)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:99)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:69)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

Sep 23, 2022 11:50:49 PM io.cryostat.core.log.Logger error
SEVERE: HTTP 500: java.util.concurrent.ExecutionException: java.io.IOException
io.vertx.ext.web.handler.HttpException: Internal Server Error
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.net.web.http.api.v1.RecordingsGetHandler.handleAuthenticated(RecordingsGetHandler.java:113)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:99)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:69)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:528)
	... 12 more
Caused by: java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:248)
	... 13 more

$ tree archive/
archive/
├── file-uploads
└── ONSXE5TJMNSTU2TNPA5HE3LJHIXS6L3KNZSGSL3SNVUTULZPMNZHS33TORQXIORZGA4TGL3KNV4HE3LJ
    └── es-andrewazor-demo-Main_auto_myrule_20220923T132954Z.jfr

Also, when I use this combined with the corresponding frontend PR, the archives are unavailable:

To reproduce, basically just create a rule definition like this:

{"name":"myrule","description":"","matchExpression":"target.alias == 'es.andrewazor.demo.Main'","eventSpecifier":"template=Profiling,type=TARGET","archivalPeriodSeconds":0,"initialDelaySeconds":0,"preservedArchives":0,"maxAgeSeconds":0,"maxSizeBytes":52428800}

with a main Cryostat build and smoketest.sh, then rebuild with this PR applied and restart.

[maxcao13]

Archive migration doesn't seem to have worked for me:

Whoops, I changed a method from returning null and null checking to run as a CompletableFuture and try catching it and forgot I was using it in the migration. Should be fine now.

[andrewazores]

Looks like this needs a spotless:apply and a rebase.

I tried rebuilding and doing a migration again, with the following rule definition used to generate some archived data on the pre-PR run:

{"name":"myrule","description":"","matchExpression":"target.alias == 'es.andrewazor.demo.Main'","eventSpecifier":"template=Profiling,type=TARGET","archivalPeriodSeconds":30,"initialDelaySeconds":10,"preservedArchives":5,"maxAgeSeconds":32,"maxSizeBytes":52428800}

and I'm still seeing exceptions like the following logged:

Sep 26, 2022 4:25:03 PM io.cryostat.core.log.Logger error
SEVERE: Exception thrown
java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.rules.PeriodicArchiver.run(PeriodicArchiver.java:108)
	at io.cryostat.rules.RuleProcessor.lambda$activate$5(RuleProcessor.java:274)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:889)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:274)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:176)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:508)
	... 19 more
Caused by: java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:234)
	... 20 more

There are also more exceptions at startup earlier on. Full logs attached. cryostat-migration.log

[maxcao13]

Looks like this needs a spotless:apply and a rebase.

I tried rebuilding and doing a migration again, with the following rule definition used to generate some archived data on the pre-PR run:

{"name":"myrule","description":"","matchExpression":"target.alias == 'es.andrewazor.demo.Main'","eventSpecifier":"template=Profiling,type=TARGET","archivalPeriodSeconds":30,"initialDelaySeconds":10,"preservedArchives":5,"maxAgeSeconds":32,"maxSizeBytes":52428800}

and I'm still seeing exceptions like the following logged:

Sep 26, 2022 4:25:03 PM io.cryostat.core.log.Logger error
SEVERE: Exception thrown
java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.rules.PeriodicArchiver.run(PeriodicArchiver.java:108)
	at io.cryostat.rules.RuleProcessor.lambda$activate$5(RuleProcessor.java:274)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:889)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:274)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:176)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:508)
	... 19 more
Caused by: java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:234)
	... 20 more

There are also more exceptions at startup earlier on. Full logs attached. cryostat-migration.log

I think those are harmless exception logs because I use future.completeExceptionally afterwards but I'll fix to catch them to prevent them from being printed.

[maxcao13]

There are also more exceptions at startup earlier on. Full logs attached. cryostat-migration.log

Also, looking at the log file, there seems to be logger prints there from a previous commit that I've since removed. For example,

INFO: trying to access lock: service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: not locked: service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: connections: key: service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: connections: key: service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: connections: key: service:jmx:rmi:///jndi/rmi://cryostat:10000/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: connections: key: service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: STARTRULERECORDING RULEPROCESSER service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi
Sep 26, 2022 4:22:52 PM io.cryostat.core.log.Logger info
INFO: trying to access lock: service:jmx:rmi:///jndi/rmi://cryostat:9094/jmxrmi

I had the "trying to access lock" logger print in TargetConnectManager to check the locking mechanism but have since removed it, for instance. I'm not sure where that is coming from.

[andrewazores]

Ah, okay, I'll try again. Maybe I forgot to actually check out the commit after fetching. Sorry for the noise.

[andrewazores]

Working well now that I properly checked out the latest commits! :-)

[tthvo]

Seeing this error when running latest commit of this PR and cryostatio/cryostat-web#499:

SEVERE: HTTP 500: java.util.concurrent.ExecutionException: java.io.IOException
io.vertx.ext.web.handler.HttpException: Internal Server Error
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.net.web.http.api.v1.RecordingsGetHandler.handleAuthenticated(RecordingsGetHandler.java:113)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:99)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:69)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:524)
	... 12 more
Caused by: java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:241)
	... 13 more

[andrewazores]

I see this in the logs, too:

java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "targetId" is null
	at io.cryostat.recordings.JvmIdHelper.getJvmId(JvmIdHelper.java:111)
	at io.cryostat.recordings.JvmIdHelper.getJvmId(JvmIdHelper.java:124)
	at io.cryostat.recordings.RecordingArchiveHelper.getCachedReportPath(RecordingArchiveHelper.java:423)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteReport(RecordingArchiveHelper.java:413)
	at io.cryostat.recordings.RecordingArchiveHelper.handleDeleteRecordingRequest(RecordingArchiveHelper.java:384)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteRecording(RecordingArchiveHelper.java:333)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteRecording(RecordingArchiveHelper.java:342)
	at io.cryostat.rules.PeriodicArchiver.pruneArchive(PeriodicArchiver.java:159)
	at io.cryostat.rules.PeriodicArchiver.run(PeriodicArchiver.java:129)
	at io.cryostat.rules.RuleProcessor.lambda$activate$5(RuleProcessor.java:274)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:889)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:274)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:176)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

it seems to be harmless, probably because it stems from a rule archiving task happening in the background. I'm not sure what the connection descriptor with a null targetId is, though.

[maxcao13]

RecordingArchiveHelper

I see this in the logs, too:

java.lang.NullPointerException: Cannot invoke "String.equals(Object)" because "targetId" is null
	at io.cryostat.recordings.JvmIdHelper.getJvmId(JvmIdHelper.java:111)
	at io.cryostat.recordings.JvmIdHelper.getJvmId(JvmIdHelper.java:124)
	at io.cryostat.recordings.RecordingArchiveHelper.getCachedReportPath(RecordingArchiveHelper.java:423)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteReport(RecordingArchiveHelper.java:413)
	at io.cryostat.recordings.RecordingArchiveHelper.handleDeleteRecordingRequest(RecordingArchiveHelper.java:384)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteRecording(RecordingArchiveHelper.java:333)
	at io.cryostat.recordings.RecordingArchiveHelper.deleteRecording(RecordingArchiveHelper.java:342)
	at io.cryostat.rules.PeriodicArchiver.pruneArchive(PeriodicArchiver.java:159)
	at io.cryostat.rules.PeriodicArchiver.run(PeriodicArchiver.java:129)
	at io.cryostat.rules.RuleProcessor.lambda$activate$5(RuleProcessor.java:274)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:889)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:860)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:50)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:274)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.AbstractContext.emit(AbstractContext.java:53)
	at io.vertx.core.impl.EventLoopContext.emit(EventLoopContext.java:22)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:883)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:176)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

it seems to be harmless, probably because it stems from a rule archiving task happening in the background. I'm not sure what the connection descriptor with a null targetId is, though.

Ah I see the bug, thanks for catching that.

[maxcao13]

Seeing this error when running latest commit of this PR and cryostatio/cryostat-web#499:

SEVERE: HTTP 500: java.util.concurrent.ExecutionException: java.io.IOException
io.vertx.ext.web.handler.HttpException: Internal Server Error
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.net.web.http.api.v1.RecordingsGetHandler.handleAuthenticated(RecordingsGetHandler.java:113)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:99)
	at io.cryostat.net.web.http.AbstractAuthenticatedRequestHandler.handle(AbstractAuthenticatedRequestHandler.java:69)
	at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at io.cryostat.recordings.RecordingArchiveHelper.getRecordings(RecordingArchiveHelper.java:524)
	... 12 more
Caused by: java.io.IOException
	at java.base/java.util.Optional.orElseThrow(Optional.java:403)
	at io.cryostat.recordings.RecordingArchiveHelper.getConnectUrlFromPath(RecordingArchiveHelper.java:241)
	... 13 more

This is happening because there is a folder in the archives directory called "unlabelled". I'm not sure if this is from a previous release or a previous commit in the current release so I will double check. If its the latter, all that needs to be done is to delete the folder. If the former, then I need to add another if case.

[tthvo]

Right! Just removing unlabelled archive folder fixes the issue :D Worked well!

[maxcao13]

This is happening because there is a folder in the archives directory called "unlabelled". I'm not sure if this is from a previous release or a previous commit in the current release so I will double check. If its the latter, all that needs to be done is to delete the folder. If the former, then I need to add another if case.

Seems like the "unlabelled" folder was a product of #924 so I believe it doesn't need to be added as a extra case.