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.

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

feat(discoveryplugin): look up plugin callback credentials in database #1377

Merged
merged 7 commits into from
Mar 7, 2023

Conversation

andrewazores
Copy link
Member

@andrewazores andrewazores commented Feb 21, 2023

Welcome to Cryostat! 👋

Before contributing, make sure you have:

  • Read the contributing guidelines
  • Linked a relevant issue which this PR resolves
  • Linked any other relevant issues, PR's, or documentation, if any
  • Resolved all conflicts, if any
  • Rebased your branch PR on top of the latest upstream main branch
  • Attached at least one of the following labels to the PR: [chore, ci, docs, feat, fix, test]
  • Signed the last commit: git commit --amend --signoff

Fixes: #1376

Description of the change:

If a discovery plugin (ex. the Agent) has registered using a callback URL that includes userinfo (ex. http://user:pass@example.com),
this same userinfo should be included by Cryostat both in the request URL as well as copied to Authorization header when Cryostat communicates with that plugin, for example when pinging the plugin to ensure it is still live and reachable.

When a discovery plugin wants to register with Cryostat, it will first define a stored credential for itself. Then it will register itself using a special value for the userinfo of the plugin callback URI which references that stored credential. Cryostat looks up that credential and includes it for authentication on the plugin callback requests it makes in the future, both to validate the plugin during registration time as well as periodically later for heartbeat checks.

Motivation for the change:

Plugins should require an authentication challenge on requests since these requests can trigger the plugin to refresh registration with the Cryostat server. Without an authentication challenge, any client may ping the plugin instance and cause it to resend registration to Cryostat. This causes undue increased load on the Cryostat server for no productive purpose.

How to manually test:

  1. Check out this PR image
  2. Check out associated Agent PR, build agent into local m2 repo, and rebuild quarkus-test container image
  3. Run smoketest.sh using this PR image and the updated quarkus-test with updated -agent
  4. Verify from logs and target discovery queries that the agent has registered and published itself with generated basic credentials, and that the agent requires these credentials to be passed with requests.

@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-8175dc3c2297cfc65c5cd0c80c307b256b7151dd sh smoketest.sh

@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-fe6c4c6eb8fa7e591325eff12cc61f0c55a77b24 sh smoketest.sh

Copy link
Member

@maxcao13 maxcao13 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a question:

Feb 23, 2023 7:18:19 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 19:18:19 GMT] 182ms "POST /api/v2.2/discovery HTTP/1.1" 201 813 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.5)"
Feb 23, 2023 7:18:19 PM io.cryostat.core.log.Logger info
INFO: GET http://agent:i16pw781fehyuify@localhost:9988/ status 401: Unauthorized

The quarkus-agent-plugin-2 sends a post request to the discovery endpoint here and is met with a 201 response along with the userinfo within the uri. Then Cryostat responds with a GET on the root endpoint of the agent but is met with a 401 status.

Later the plugin tries to register again:

Feb 23, 2023 7:18:19 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 19:18:19 GMT] 100ms "POST /api/v2.2/discovery HTTP/1.1" 201 813 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.5)"
Feb 23, 2023 7:18:19 PM io.cryostat.core.log.Logger info
INFO: Observing new target: io.cryostat.platform.ServiceRef@3490e520[alias=quarkus-test-agent,annotations=io.cryostat.platform.ServiceRef$Annotations@21711384[cryostat={HOST=cryostat, PORT=9988, JAVA_MAIN=/deployments/quarkus-run.jar, PID=1, START_TIME=1677179882, REALM=quarkus-test-agent},platform={}],jvmId=sAdr8LLOIRdXa8Wp6pQjrZSVLC46oG-x4D4mYlVpJWY=,labels={},serviceUri=http://agent:i16pw781fehyuify@localhost:9988/]

This time, cryostat seems to successfully register the plugin.

Then sometimes we are met with another 401 unauthorized callback somewhere later even though we have registered successfully before

Feb 23, 2023 7:23:16 PM io.cryostat.core.log.Logger info
INFO: POST http://agent:i16pw781fehyuify@localhost:9988/ status 401: Unauthorized
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: 
    /* delete io.cryostat.discovery.PluginInfo */ delete 
        from
            PluginInfo 
        where
            id=?
Feb 23, 2023 7:23:16 PM io.cryostat.core.log.Logger info
INFO: Stale discovery service http://agent:i16pw781fehyuify@localhost:9988/ removed

For future reference, what is happening here?

@andrewazores
Copy link
Member Author

Weird. I'll circle back around to these PRs and try to reproduce that.

@andrewazores
Copy link
Member Author

Oh, I wonder if this is something going on with the callback POST vs GET. The callback ping on registration is a GET and on heartbeat check it's a POST I think, or maybe the other way around. Perhaps the plugin is only responding successfully to one or the other.

@andrewazores
Copy link
Member Author

Hmm... I don't think I'm seeing that behaviour. I mvn installed the corresponding -agent PR, rebuilt quarkus-test, and then ran CRYOSTAT_DISCOVERY_PING_PERIOD=10000 sh smoketest.sh h2mem. I also modified the smoketest script:

diff --git a/smoketest.sh b/smoketest.sh
index 081f2a70..47343d8a 100755
--- a/smoketest.sh
+++ b/smoketest.sh
@@ -89,29 +89,29 @@ runPostgres() {
 }
 
 runDemoApps() {
-    podman run \
-        --name vertx-fib-demo-1 \
-        --env HTTP_PORT=8081 \
-        --env JMX_PORT=9093 \
-        --pod cryostat-pod \
-        --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
+    # podman run \
+    #     --name vertx-fib-demo-1 \
+    #     --env HTTP_PORT=8081 \
+    #     --env JMX_PORT=9093 \
+    #     --pod cryostat-pod \
+    #     --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
 
-    podman run \
-        --name vertx-fib-demo-2 \
-        --env HTTP_PORT=8082 \
-        --env JMX_PORT=9094 \
-        --env USE_AUTH=true \
-        --pod cryostat-pod \
-        --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
+    # podman run \
+    #     --name vertx-fib-demo-2 \
+    #     --env HTTP_PORT=8082 \
+    #     --env JMX_PORT=9094 \
+    #     --env USE_AUTH=true \
+    #     --pod cryostat-pod \
+    #     --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
 
-    podman run \
-        --name vertx-fib-demo-3 \
-        --env HTTP_PORT=8083 \
-        --env JMX_PORT=9095 \
-        --env USE_SSL=true \
-        --env USE_AUTH=true \
-        --pod cryostat-pod \
-        --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
+    # podman run \
+    #     --name vertx-fib-demo-3 \
+    #     --env HTTP_PORT=8083 \
+    #     --env JMX_PORT=9095 \
+    #     --env USE_SSL=true \
+    #     --env USE_AUTH=true \
+    #     --pod cryostat-pod \
+    #     --rm -d quay.io/andrewazores/vertx-fib-demo:0.9.1
 
     local webPort;
     if [ -z "$CRYOSTAT_WEB_PORT" ]; then
@@ -127,15 +127,15 @@ runDemoApps() {
 
     # this config is broken on purpose (missing required env vars) to test the agent's behaviour
     # when not properly set up
-    podman run \
-        --name quarkus-test-agent-0 \
-        --pod cryostat-pod \
-        --env JAVA_OPTS="-Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -javaagent:/deployments/app/cryostat-agent.jar" \
-        --env QUARKUS_HTTP_PORT=10009 \
-        --env ORG_ACME_CRYOSTATSERVICE_ENABLED="false" \
-        --env CRYOSTAT_AGENT_WEBCLIENT_SSL_TRUST_ALL="true" \
-        --env CRYOSTAT_AGENT_WEBCLIENT_SSL_VERIFY_HOSTNAME="false" \
-        --rm -d quay.io/andrewazores/quarkus-test:latest
+    # podman run \
+    #     --name quarkus-test-agent-0 \
+    #     --pod cryostat-pod \
+    #     --env JAVA_OPTS="-Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -javaagent:/deployments/app/cryostat-agent.jar" \
+    #     --env QUARKUS_HTTP_PORT=10009 \
+    #     --env ORG_ACME_CRYOSTATSERVICE_ENABLED="false" \
+    #     --env CRYOSTAT_AGENT_WEBCLIENT_SSL_TRUST_ALL="true" \
+    #     --env CRYOSTAT_AGENT_WEBCLIENT_SSL_VERIFY_HOSTNAME="false" \
+    #     --rm -d quay.io/andrewazores/quarkus-test:latest
 
     podman run \
         --name quarkus-test-agent-1 \
@@ -154,24 +154,25 @@ runDemoApps() {
         --env CRYOSTAT_AGENT_AUTHORIZATION="Basic $(echo user:pass | base64)" \
         --env CRYOSTAT_AGENT_HARVESTER_PERIOD_MS=60000 \
         --env CRYOSTAT_AGENT_HARVESTER_MAX_FILES=10 \
+        --env CRYOSTAT_AGENT_REGISTRATION_RETRY_MS=30000 \
         --rm -d quay.io/andrewazores/quarkus-test:latest
 
-    podman run \
-        --name quarkus-test-agent-2 \
-        --pod cryostat-pod \
-        --env JAVA_OPTS="-Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -javaagent:/deployments/app/cryostat-agent.jar" \
-        --env QUARKUS_HTTP_PORT=10011 \
-        --env ORG_ACME_CRYOSTATSERVICE_ENABLED="false" \
-        --env CRYOSTAT_AGENT_APP_NAME="quarkus-test-agent" \
-        --env CRYOSTAT_AGENT_WEBCLIENT_SSL_TRUST_ALL="true" \
-        --env CRYOSTAT_AGENT_WEBCLIENT_SSL_VERIFY_HOSTNAME="false" \
-        --env CRYOSTAT_AGENT_WEBSERVER_HOST="localhost" \
-        --env CRYOSTAT_AGENT_WEBSERVER_PORT="9988" \
-        --env CRYOSTAT_AGENT_CALLBACK="http://localhost:9988/" \
-        --env CRYOSTAT_AGENT_BASEURI="${protocol}://localhost:${webPort}/" \
-        --env CRYOSTAT_AGENT_TRUST_ALL="true" \
-        --env CRYOSTAT_AGENT_AUTHORIZATION="Basic $(echo user:pass | base64)" \
-        --rm -d quay.io/andrewazores/quarkus-test:latest
+    # podman run \
+    #     --name quarkus-test-agent-2 \
+    #     --pod cryostat-pod \
+    #     --env JAVA_OPTS="-Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -javaagent:/deployments/app/cryostat-agent.jar" \
+    #     --env QUARKUS_HTTP_PORT=10011 \
+    #     --env ORG_ACME_CRYOSTATSERVICE_ENABLED="false" \
+    #     --env CRYOSTAT_AGENT_APP_NAME="quarkus-test-agent" \
+    #     --env CRYOSTAT_AGENT_WEBCLIENT_SSL_TRUST_ALL="true" \
+    #     --env CRYOSTAT_AGENT_WEBCLIENT_SSL_VERIFY_HOSTNAME="false" \
+    #     --env CRYOSTAT_AGENT_WEBSERVER_HOST="localhost" \
+    #     --env CRYOSTAT_AGENT_WEBSERVER_PORT="9988" \
+    #     --env CRYOSTAT_AGENT_CALLBACK="http://localhost:9988/" \
+    #     --env CRYOSTAT_AGENT_BASEURI="${protocol}://localhost:${webPort}/" \
+    #     --env CRYOSTAT_AGENT_TRUST_ALL="true" \
+    #     --env CRYOSTAT_AGENT_AUTHORIZATION="Basic $(echo user:pass | base64)" \
+    #     --rm -d quay.io/andrewazores/quarkus-test:latest
 
     # copy a jboss-client.jar into /clientlib first
     # manual entry URL: service:jmx:remote+http://localhost:9990

so that there is only the one sample app instance (to keep the logs as clean as possible), and to delay the registration timing so that all of Cryostat's startup stuff is completed including discovering itself over JDP etc. I don't think any of that should affect how the plugin registration/publication happens.

I'll keep tinkering with it but at the moment I'm not sure what could be causing the behaviour you observed.

@andrewazores
Copy link
Member Author

andrewazores commented Feb 23, 2023

Here are some server-side logs:

... [trimmed startup lines]
INFO: GET http://agent:9zka38z9gkbbz5q9@localhost:9977/ status 204: No Content
Hibernate: 
    /* insert io.cryostat.discovery.PluginInfo
        */ insert 
        into
            PluginInfo
            (callback, realm, subtree, id) 
        values
            (?, ?, ?, ?)
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=?
Feb 23, 2023 10:24:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:24:22 GMT] 100ms "POST /api/v2.2/discovery HTTP/1.1" 201 813 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:24:22 PM io.cryostat.core.log.Logger info
INFO: GET http://agent:yfj378nahgumz2jg@localhost:9988/ status 204: No Content
Hibernate: 
    /* insert io.cryostat.discovery.PluginInfo
        */ insert 
        into
            PluginInfo
            (callback, realm, subtree, id) 
        values
            (?, ?, ?, ?)
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=?
Feb 23, 2023 10:24:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:24:22 GMT] 28ms "POST /api/v2.2/discovery HTTP/1.1" 201 813 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:24:22 PM io.cryostat.core.log.Logger info
INFO: Observing new target: io.cryostat.platform.ServiceRef@3f89aacd[alias=quarkus-test-agent,annotations=io.cryostat.platform.ServiceRef$Annotations@3088be96[cryostat={HOST=cryostat, PORT=9988, JAVA_MAIN=/deployments/quarkus-run.jar, PID=1, START_TIME=1677191051, REALM=quarkus-test-agent},platform={}],jvmId=6B7n_-m3A3cvfuIpErn63i3MXRGCK0bhaNl9L4uYkxo=,labels={},serviceUri=http://agent:yfj378nahgumz2jg@localhost:9988/]
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: 
    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=?
Hibernate: 
    /* select
        generatedAlias0 
    from
        StoredCredentials as generatedAlias0 */ select
            storedcred0_.id as id1_1_,
            storedcred0_.matchExpression as matchexp2_1_,
            storedcred0_.password as password3_1_,
            storedcred0_.username as username4_1_ 
        from
            StoredCredentials storedcred0_
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_
Feb 23, 2023 10:24:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:24:22 GMT] 32ms "POST /api/v2.2/discovery/68c68149-5bd8-45a6-8f7f-ee1c2fa85379?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..1TQr6tMWrtt9T6K-.J621bfpRA4ZpmaXbFqI0fc2gqa-Xyebn0Ee2a5MF5vjcd1-bYX5jqQq_0abcPdHVe5duz5kHSojf5pQUYghkHjCYODNG1iFSkvUmG___LoZaN5I7Tmi7tgGVRnKa22ngZTlhvSIHOjEJSEvJA3oDJWfr6QIR4ROSNA-l6oVNcNSylDCMX2XmLAqT9vbm0BRRLgeGpWhghBS8c1Lu-zgVJlZpVql9pKi8jk42YbkZEYZtPee5W94Jmm3GxhQ4LuxEpmiH87HO6pkxNGQ9__2ySwXONSM7wmuaysdz50jPvcTuV6U0qc2V8boPg0woKdv3PYjeRjf7Zr3nv212wXL4d6zgRRC9tHcO7ERb7kOxmIGB489FfPceL2gUYmse3iYJ9iMKOTW5JXmOFMM_iOngC9N_k8_uNVOJZmlkqSbYIu88-3xdNelGuOep8SThyU_5VS8oVj2FzPAYpJ6HtOij4hIVhfVmbXSBmTDuivPxWdwIOVK6zQiWZTWRUaWHr8Z5vwoK0f4eqV7M5bJ02UrtY339EzbDkhn5gtPD0ArMdjC_esfhlZHVFZEbdugUQjCkAJj1N2wLsQ.7sxM61piPsl1FVG-w2yNAw HTTP/1.1" 200 65 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:24:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1677191062},"message":{"event":{"serviceRef":{"jvmId":"6B7n_-m3A3cvfuIpErn63i3MXRGCK0bhaNl9L4uYkxo=","connectUrl":"http://agent:yfj378nahgumz2jg@localhost:9988/","alias":"quarkus-test-agent","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9988","JAVA_MAIN":"/deployments/quarkus-run.jar","PID":"1","START_TIME":"1677191051","REALM":"quarkus-test-agent"}}},"kind":"FOUND"}}}
Feb 23, 2023 10:24:22 PM io.cryostat.core.log.Logger info
INFO: Observing new target: io.cryostat.platform.ServiceRef@856d90d[alias=quarkus-test-agent,annotations=io.cryostat.platform.ServiceRef$Annotations@6913677[cryostat={HOST=cryostat, PORT=9977, JAVA_MAIN=/deployments/quarkus-run.jar, PID=1, START_TIME=1677191050, REALM=quarkus-test-agent},platform={}],jvmId=NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=,labels={},serviceUri=http://agent:9zka38z9gkbbz5q9@localhost:9977/]
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: 
    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=?
Hibernate: 
    /* select
        generatedAlias0 
    from
        StoredCredentials as generatedAlias0 */ select
            storedcred0_.id as id1_1_,
            storedcred0_.matchExpression as matchexp2_1_,
            storedcred0_.password as password3_1_,
            storedcred0_.username as username4_1_ 
        from
            StoredCredentials storedcred0_
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_
Feb 23, 2023 10:24:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:24:22 GMT] 10ms "POST /api/v2.2/discovery/a4cebb5e-4e88-4404-97d8-cd4d40dcf9d4?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..BTdLoTWZRlixfcdo.uVirOseCSEtg3ps9tKwdehVwqdxBBW2DSchuHsv2BDFlTeVYSSsoeDRXPwu38C6MpVAtjxZh7geezPupdXodsOXKB9r7EOsguZj5l1l2UXpTZYe8sJOfXy7-MWaQNLLxi76T_dp9fuIC3VWkBDSC8NWOEKe0A6WVycCs2KlCp63v62XJ23NMtEMa3vLtDnxcDXYQr4nBBjdPc6srgRreD0Y2hu9mJw8F9nKM62VH_FSGKcIn5WHO-WKQpuQ2l9fr7qljhr6QFE-u2MpINZpg0-75FDDPfnZM-CbvV4ajVIiuLo8719o8MH6CxdwoX6UXG03qGS-s5VGio6Y0sAzLbZmill984R4f879-WnPNlqnOWiX7Kf1mm9SlAwyOPqJRX4XPPPK_cRb4taTShe1NRhrjgK9OHKWgtiBK_0gB-hYKn9gVJ7dTY_8MqitW3N66oYc93tUFsSlXbxuXjs-k8FI3gLEkXeEmXl-S2SfGVx9arjeO35zi0L9nmpdNlirFdnILOzOncbNuDkdVd5S4FhtFDFzXHW9RvoKRdXTSmDOYNRgFqGa8b_OCfllSkEKvpJaI49MNvg._rZbWcq1d_d4f0Nped-kUA HTTP/1.1" 200 65 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:24:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1677191062},"message":{"event":{"serviceRef":{"jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","connectUrl":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","alias":"quarkus-test-agent","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9977","JAVA_MAIN":"/deployments/quarkus-run.jar","PID":"1","START_TIME":"1677191050","REALM":"quarkus-test-agent"}}},"kind":"FOUND"}}}
Feb 23, 2023 10:24:32 PM io.cryostat.core.log.Logger info
INFO: Removing cached connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi: EXPIRED
Feb 23, 2023 10:24:32 PM io.cryostat.core.log.Logger info
INFO: Connection for service:jmx:rmi:///jndi/rmi://cryostat:9093/jmxrmi closed
Feb 23, 2023 10:25:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingMetadataUpdated","type":{"type":"application","subType":"json"},"serverTime":1677191122},"message":{"metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"recordingName":"quarkus-test-agent_default_20230223T222522Z.jfr","target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/"}}
Feb 23, 2023 10:25:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ArchivedRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1677191122},"message":{"target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","recording":{"downloadUrl":"https://localhost:8181/api/beta/recordings/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222522Z.jfr","name":"quarkus-test-agent_default_20230223T222522Z.jfr","reportUrl":"https://localhost:8181/api/beta/reports/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222522Z.jfr","metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"size":489338,"archivedTime":1677191122000}}}
Feb 23, 2023 10:25:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:25:22 GMT] 86ms "POST /api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY= HTTP/1.1" 200 211 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:26:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingMetadataUpdated","type":{"type":"application","subType":"json"},"serverTime":1677191182},"message":{"metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"recordingName":"quarkus-test-agent_default_20230223T222622Z.jfr","target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/"}}
Feb 23, 2023 10:26:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ArchivedRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1677191182},"message":{"target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","recording":{"downloadUrl":"https://localhost:8181/api/beta/recordings/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222622Z.jfr","name":"quarkus-test-agent_default_20230223T222622Z.jfr","reportUrl":"https://localhost:8181/api/beta/reports/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222622Z.jfr","metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"size":981836,"archivedTime":1677191182000}}}
Feb 23, 2023 10:26:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:26:22 GMT] 44ms "POST /api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY= HTTP/1.1" 200 211 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:27:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingMetadataUpdated","type":{"type":"application","subType":"json"},"serverTime":1677191242},"message":{"metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"recordingName":"quarkus-test-agent_default_20230223T222722Z.jfr","target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/"}}
Feb 23, 2023 10:27:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ArchivedRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1677191242},"message":{"target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","recording":{"downloadUrl":"https://localhost:8181/api/beta/recordings/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222722Z.jfr","name":"quarkus-test-agent_default_20230223T222722Z.jfr","reportUrl":"https://localhost:8181/api/beta/reports/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222722Z.jfr","metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"size":488725,"archivedTime":1677191242000}}}
Feb 23, 2023 10:27:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:27:22 GMT] 26ms "POST /api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY= HTTP/1.1" 200 211 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
Feb 23, 2023 10:28:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingMetadataUpdated","type":{"type":"application","subType":"json"},"serverTime":1677191302},"message":{"metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"recordingName":"quarkus-test-agent_default_20230223T222822Z.jfr","target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/"}}
Feb 23, 2023 10:28:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ArchivedRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1677191302},"message":{"target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","recording":{"downloadUrl":"https://localhost:8181/api/beta/recordings/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222822Z.jfr","name":"quarkus-test-agent_default_20230223T222822Z.jfr","reportUrl":"https://localhost:8181/api/beta/reports/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222822Z.jfr","metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"size":487559,"archivedTime":1677191302000}}}
Feb 23, 2023 10:28:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:28:22 GMT] 35ms "POST /api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY= HTTP/1.1" 200 211 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"
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_
Feb 23, 2023 10:29:17 PM io.cryostat.core.log.Logger info
INFO: POST http://agent:yfj378nahgumz2jg@localhost:9988/ status 204: No Content
Feb 23, 2023 10:29:17 PM io.cryostat.core.log.Logger info
INFO: POST http://agent:9zka38z9gkbbz5q9@localhost:9977/ status 204: No Content
Feb 23, 2023 10:29:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"RecordingMetadataUpdated","type":{"type":"application","subType":"json"},"serverTime":1677191362},"message":{"metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"recordingName":"quarkus-test-agent_default_20230223T222922Z.jfr","target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/"}}
Feb 23, 2023 10:29:22 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"ArchivedRecordingCreated","type":{"type":"application","subType":"json"},"serverTime":1677191362},"message":{"target":"http://agent:9zka38z9gkbbz5q9@localhost:9977/","recording":{"downloadUrl":"https://localhost:8181/api/beta/recordings/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222922Z.jfr","name":"quarkus-test-agent_default_20230223T222922Z.jfr","reportUrl":"https://localhost:8181/api/beta/reports/http:%2F%2Fagent:9zka38z9gkbbz5q9@localhost:9977%2F/quarkus-test-agent_default_20230223T222922Z.jfr","metadata":{"labels":{"template.name":"default","jvmId":"NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=","template.type":"TARGET","pushType":"SCHEDULED"}},"size":973663,"archivedTime":1677191362000}}}
Feb 23, 2023 10:29:22 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 22:29:22 GMT] 39ms "POST /api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY= HTTP/1.1" 200 211 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.6)"

and the agent-side logs from quarkus-test-1:


Starting the Java application using /opt/jboss/container/java/run/run-java.sh ...
INFO exec  java -Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -Dcom.sun.management.jmxremote.port=9097 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -javaagent:/deployments/app/cryostat-agent.jar -XX:+UseParallelGC -XX:MinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=20 -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:+ExitOnOutOfMemoryError -cp "." -jar /deployments/quarkus-run.jar 
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/deployments/app/cryostat-agent.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/deployments/lib/main/org.jboss.slf4j.slf4j-jboss-logmanager-1.1.0.Final.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Slf4jLoggerFactory]
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2023-02-23 22:24:11,733 INFO  [io.cry.age.Agent] (cryostat-agent-main) Cryostat Agent starting...
2023-02-23 22:24:11,899 INFO  [io.cry.cor.net.JFRConnectionToolkit] (cryostat-agent-main) Computed self JVM ID: NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=
2023-02-23 22:24:11,900 INFO  [io.cry.age.CryostatClient] (cryostat-agent-main) Using Cryostat baseuri https://localhost:8181/
2023-02-23 22:24:11,907 INFO  [io.cry.age.Registration] (cryostat-agent-main) io.cryostat.agent.Registration started
2023-02-23 22:24:11,907 INFO  [io.cry.age.Agent] (cryostat-agent-main) Startup complete
2023-02-23 22:24:11,924 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST https://localhost:8181/api/v2.2/discovery HTTP/1.1
2023-02-23 22:24:11,935 SEVERE [io.cry.age.Registration] (cryostat-agent-worker-0) Registration failure: java.util.concurrent.ExecutionException: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	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.agent.Registration.tryRegister(Registration.java:137)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at io.cryostat.agent.Registration.lambda$tryRegister$0(Registration.java:130)
	at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
	at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482)
	... 6 more
Caused by: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:273)
	at io.cryostat.agent.CryostatClient.lambda$supply$11(CryostatClient.java:265)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
	... 6 more
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
	at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:271)
	... 8 more
Caused by: java.net.ConnectException: Connection refused
	at java.base/sun.nio.ch.Net.pollConnect(Native Method)
	at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
	at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
	at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
	at java.base/java.net.Socket.connect(Socket.java:633)
	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
	... 19 more

2023-02-23 22:24:11,935 INFO  [io.cry.age.Registration] (cryostat-agent-worker-0) Registration retry period: PT5S
2023-02-23 22:24:12,179 INFO  [io.quarkus] (main) quarkus-test 1.0.0-SNAPSHOT on JVM (powered by Quarkus 2.7.2.Final) started in 0.383s. Listening on: http://0.0.0.0:10010
2023-02-23 22:24:12,180 INFO  [io.quarkus] (main) Profile prod activated. 
2023-02-23 22:24:12,180 INFO  [io.quarkus] (main) Installed features: [cdi, rest-client, rest-client-jackson, resteasy, smallrye-context-propagation, vertx]
2023-02-23 22:24:16,936 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST https://localhost:8181/api/v2.2/discovery HTTP/1.1
2023-02-23 22:24:16,937 SEVERE [io.cry.age.Registration] (cryostat-agent-worker-0) Registration failure: java.util.concurrent.ExecutionException: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	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.agent.Registration.tryRegister(Registration.java:137)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at io.cryostat.agent.Registration.lambda$tryRegister$0(Registration.java:130)
	at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
	at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482)
	... 6 more
Caused by: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:273)
	at io.cryostat.agent.CryostatClient.lambda$supply$11(CryostatClient.java:265)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
	... 6 more
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
	at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:271)
	... 8 more
Caused by: java.net.ConnectException: Connection refused
	at java.base/sun.nio.ch.Net.pollConnect(Native Method)
	at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
	at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
	at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
	at java.base/java.net.Socket.connect(Socket.java:633)
	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
	... 19 more

2023-02-23 22:24:16,937 INFO  [io.cry.age.Registration] (cryostat-agent-worker-0) Registration retry period: PT5S
2023-02-23 22:24:21,938 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST https://localhost:8181/api/v2.2/discovery HTTP/1.1
2023-02-23 22:24:22,137 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-1) GET /
2023-02-23 22:24:22,145 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-1) GET / : 204
2023-02-23 22:24:22,199 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-2) POST https://localhost:8181/api/v2.2/discovery : 201
2023-02-23 22:24:22,221 INFO  [io.cry.age.Registration] (cryostat-agent-worker-2) Registered as a4cebb5e-4e88-4404-97d8-cd4d40dcf9d4
2023-02-23 22:24:22,223 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-2) JFR Harvester starting
2023-02-23 22:24:22,327 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-2) JFR Harvester started using template "default" with period PT1M
2023-02-23 22:24:22,329 INFO  [io.cry.age.Registration] (cryostat-agent-worker-2) publishing self as http://agent:9zka38z9gkbbz5q9@localhost:9977/
2023-02-23 22:24:22,339 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-2) POST https://localhost:8181/api/v2.2/discovery/a4cebb5e-4e88-4404-97d8-cd4d40dcf9d4?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..BTdLoTWZRlixfcdo.uVirOseCSEtg3ps9tKwdehVwqdxBBW2DSchuHsv2BDFlTeVYSSsoeDRXPwu38C6MpVAtjxZh7geezPupdXodsOXKB9r7EOsguZj5l1l2UXpTZYe8sJOfXy7-MWaQNLLxi76T_dp9fuIC3VWkBDSC8NWOEKe0A6WVycCs2KlCp63v62XJ23NMtEMa3vLtDnxcDXYQr4nBBjdPc6srgRreD0Y2hu9mJw8F9nKM62VH_FSGKcIn5WHO-WKQpuQ2l9fr7qljhr6QFE-u2MpINZpg0-75FDDPfnZM-CbvV4ajVIiuLo8719o8MH6CxdwoX6UXG03qGS-s5VGio6Y0sAzLbZmill984R4f879-WnPNlqnOWiX7Kf1mm9SlAwyOPqJRX4XPPPK_cRb4taTShe1NRhrjgK9OHKWgtiBK_0gB-hYKn9gVJ7dTY_8MqitW3N66oYc93tUFsSlXbxuXjs-k8FI3gLEkXeEmXl-S2SfGVx9arjeO35zi0L9nmpdNlirFdnILOzOncbNuDkdVd5S4FhtFDFzXHW9RvoKRdXTSmDOYNRgFqGa8b_OCfllSkEKvpJaI49MNvg._rZbWcq1d_d4f0Nped-kUA HTTP/1.1
2023-02-23 22:24:22,377 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-1) cryostat-agent(1) RUNNING
2023-02-23 22:24:22,406 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST https://localhost:8181/api/v2.2/discovery/a4cebb5e-4e88-4404-97d8-cd4d40dcf9d4?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..BTdLoTWZRlixfcdo.uVirOseCSEtg3ps9tKwdehVwqdxBBW2DSchuHsv2BDFlTeVYSSsoeDRXPwu38C6MpVAtjxZh7geezPupdXodsOXKB9r7EOsguZj5l1l2UXpTZYe8sJOfXy7-MWaQNLLxi76T_dp9fuIC3VWkBDSC8NWOEKe0A6WVycCs2KlCp63v62XJ23NMtEMa3vLtDnxcDXYQr4nBBjdPc6srgRreD0Y2hu9mJw8F9nKM62VH_FSGKcIn5WHO-WKQpuQ2l9fr7qljhr6QFE-u2MpINZpg0-75FDDPfnZM-CbvV4ajVIiuLo8719o8MH6CxdwoX6UXG03qGS-s5VGio6Y0sAzLbZmill984R4f879-WnPNlqnOWiX7Kf1mm9SlAwyOPqJRX4XPPPK_cRb4taTShe1NRhrjgK9OHKWgtiBK_0gB-hYKn9gVJ7dTY_8MqitW3N66oYc93tUFsSlXbxuXjs-k8FI3gLEkXeEmXl-S2SfGVx9arjeO35zi0L9nmpdNlirFdnILOzOncbNuDkdVd5S4FhtFDFzXHW9RvoKRdXTSmDOYNRgFqGa8b_OCfllSkEKvpJaI49MNvg._rZbWcq1d_d4f0Nped-kUA : 200
2023-02-23 22:24:22,406 INFO  [io.cry.age.Registration] (cryostat-agent-worker-1) Publish success
2023-02-23 22:25:22,499 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST 200 (quarkus-test-agent_default_20230223T222522Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 477 KB/PT0.101899859S
2023-02-23 22:26:22,437 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-2) POST 200 (quarkus-test-agent_default_20230223T222622Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 958 KB/PT0.05021086S
2023-02-23 22:27:22,427 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST 200 (quarkus-test-agent_default_20230223T222722Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 477 KB/PT0.034787914S
2023-02-23 22:28:22,434 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST 200 (quarkus-test-agent_default_20230223T222822Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 476 KB/PT0.042605926S
2023-02-23 22:29:17,845 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-2) POST /
2023-02-23 22:29:17,846 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-2) POST / : 204
2023-02-23 22:29:22,436 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST 200 (quarkus-test-agent_default_20230223T222922Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 950 KB/PT0.046950364S
2023-02-23 22:30:22,415 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST 200 (quarkus-test-agent_default_20230223T223022Z.jfr -> https://localhost:8181/api/beta/recordings/NimlT1UcplJXTRgy_PvjrEptvUBMsD3BCuc-albzAdY=): 477 KB/PT0.024948956S

@maxcao13
Copy link
Member

Hm... let me try again.

@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-05597db7a630cb4f032c7fc80b82ed08dfe3997e sh smoketest.sh

@maxcao13
Copy link
Member

Oh, I think I was using the wrong version of cryostat and checked out the pr without packing, but it's interesting how the plugin is registered for a bit without giving correct credentials, before deregistering.

When I used the correct version, it worked as expected. Good work, sorry about that!

maxcao13
maxcao13 previously approved these changes Feb 23, 2023
@andrewazores
Copy link
Member Author

Oh, I think I was using the wrong version of cryostat and checked out the pr without packing, but it's interesting how the plugin is registered for a bit without giving correct credentials, before deregistering.

Yea hold on, this doesn't sound good. Could you retrace your steps and figure out a reproducer? I need to be sure that this isn't an attack vector getting around the authentication mechanism.

@maxcao13
Copy link
Member

Oh, I think I was using the wrong version of cryostat and checked out the pr without packing, but it's interesting how the plugin is registered for a bit without giving correct credentials, before deregistering.

Yea hold on, this doesn't sound good. Could you retrace your steps and figure out a reproducer? I need to be sure that this isn't an attack vector getting around the authentication mechanism.

I think you can checkout current main but keep the correct agent plugin implementation. Also keep the smoketest to remove the extra noisy containers and I think the result will be the same. I'll try again to confirm.

@maxcao13
Copy link
Member

maxcao13 commented Feb 23, 2023

I run with h2mem and with your smoketest setup:
on this particular setup I used this:
CRYOSTAT_DISABLE_SSL=true CRYOSTAT_CORS_ORIGIN=http://localhost:9000 CRYOSTAT_IMAGE=quay.io/cryostat/cryostat:latest sh smoketest.sh h2mem but with the latest image on the main branch

and I get these logs:

Feb 23, 2023 11:35:23 PM io.cryostat.core.log.Logger info
INFO: GET http://agent:3lr7orzimq1hmt5m@localhost:9977/ status 401: Unauthorized

later...

Feb 23, 2023 11:35:23 PM org.slf4j.impl.JDK14LoggerAdapter fillCallerData
INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 23:35:23 GMT] 180ms "POST /api/v2.2/discovery HTTP/1.1" 201 807 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.5)"
Feb 23, 2023 11:35:23 PM io.cryostat.core.log.Logger info
INFO: Observing new target: io.cryostat.platform.ServiceRef@610563ab[alias=quarkus-test-agent,annotations=io.cryostat.platform.ServiceRef$Annotations@12dbf1e9[cryostat={HOST=cryostat, PORT=9977, JAVA_MAIN=/deployments/quarkus-run.jar, PID=1, START_TIME=1677195291, REALM=quarkus-test-agent},platform={}],jvmId=0z5t3_RDHt06hrHreke2qwKoFeOLsAMS1e3NZe24Roo=,labels={},serviceUri=http://agent:3lr7orzimq1hmt5m@localhost:9977/]

and then even later...

INFO: 127.0.0.1 - - [Thu, 23 Feb 2023 23:35:23 GMT] 72ms "POST /api/v2.2/discovery/ffba92da-ff02-4009-900b-7e946f91d872?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..Jxy7Jwq12G0z5HGA.AtQy-y6ky6nPAKeyz_wOPtxiF0O6oWus3HCptVlRDhDd6dOLSD0FNO_vft3Ty2lP4qfBigJmGP5XOE3xxo8dFYHgl61H1AS4s2VPfF66dWTaqZzl_ffR6jPsJr_yS9Cf57phBlhiL0hms9KMSiGWjAcaty8ZCKuf3W5SsGxbG14Y7DKq8fyhLk1HDX9as9eY3XMSbAxlGmXfU_aNQ3mbs4OwBfw8-kOM1SVKNSMPhdqqig9csCpXvHv84HPErlTYUtYPC5swhH2taXAtVr7QhOI2LAVyPyHSo5_FpncxpVgq3Jvc3B0192pPssScP4sZRu6rUKZ9ixnNrpYPqobxkOB7xPlJKfntm_m2V8FojC4HR8ujqoIPbLxWPlLdNl_ckO7AFNTco7ZVAdJYuSY_WkcfVTwKP9PI65R29MU3z8c5j9N_lOTV5N4DAqRJ6l34AvXKaJchfE34vOxZQBAJlGfg5o3vqahiF_Mf-5TH5n-CdBXyTM_5pznbb_fifAYOBUX7N0Pg_d-DcyY6JnUIAxCfHWueeEYBKXq8KZdOtyXhq4hP9oVenZ18xSWzUW1dPqyS.9ThG7gMtF1Y-rMim0jhzLw HTTP/1.1" 200 65 bytes "-" "Apache-HttpClient/4.5.13 (Java/17.0.5)"
Feb 23, 2023 11:35:23 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1677195323},"message":{"event":{"serviceRef":{"jvmId":"0z5t3_RDHt06hrHreke2qwKoFeOLsAMS1e3NZe24Roo=","connectUrl":"http://agent:3lr7orzimq1hmt5m@localhost:9977/","alias":"quarkus-test-agent","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9977","JAVA_MAIN":"/deployments/quarkus-run.jar","PID":"1","START_TIME":"1677195291","REALM":"quarkus-test-agent"}}},"kind":"FOUND"}}}

@maxcao13
Copy link
Member

maxcao13 commented Feb 23, 2023

podman logs:

Starting the Java application using /opt/jboss/container/java/run/run-java.sh ...
INFO exec  java -Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -Dcom.sun.management.jmxremote.port=9097 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -javaagent:/deployments/app/cryostat-agent.jar -XX:+UseParallelGC -XX:MinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=20 -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:+ExitOnOutOfMemoryError -cp "." -jar /deployments/quarkus-run.jar 
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/deployments/app/cryostat-agent.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/deployments/lib/main/org.jboss.slf4j.slf4j-jboss-logmanager-1.1.0.Final.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Slf4jLoggerFactory]
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2023-02-23 23:34:52,011 INFO  [io.cry.age.Agent] (cryostat-agent-main) Cryostat Agent starting...
2023-02-23 23:34:52,722 INFO  [io.cry.cor.net.JFRConnectionToolkit] (cryostat-agent-main) Computed self JVM ID: 0z5t3_RDHt06hrHreke2qwKoFeOLsAMS1e3NZe24Roo=
2023-02-23 23:34:52,727 INFO  [io.cry.age.CryostatClient] (cryostat-agent-main) Using Cryostat baseuri http://localhost:8181/
2023-02-23 23:34:52,753 INFO  [io.cry.age.Registration] (cryostat-agent-main) io.cryostat.agent.Registration started
2023-02-23 23:34:52,753 INFO  [io.cry.age.Agent] (cryostat-agent-main) Startup complete
2023-02-23 23:34:52,829 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST http://localhost:8181/api/v2.2/discovery HTTP/1.1
2023-02-23 23:34:52,904 SEVERE [io.cry.age.Registration] (cryostat-agent-worker-0) Registration failure: java.util.concurrent.ExecutionException: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
        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.agent.Registration.tryRegister(Registration.java:137)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: io.cryostat.agent.RegistrationException: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
        at io.cryostat.agent.Registration.lambda$1(Registration.java:130)
        at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
        at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
        at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482)
        ... 6 more
Caused by: java.util.concurrent.CompletionException: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
        at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:273)
        at io.cryostat.agent.CryostatClient.lambda$11(CryostatClient.java:265)
        at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
        ... 6 more
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8181 [localhost/127.0.0.1, localhost/0:0:0:0:0:0:0:1] failed: Connection refused
        at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
        at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
        at io.cryostat.agent.CryostatClient.executeQuiet(CryostatClient.java:271)
        ... 8 more
Caused by: java.net.ConnectException: Connection refused
        at java.base/sun.nio.ch.Net.pollConnect(Native Method)
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
        at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
        at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
        at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
        at java.base/java.net.Socket.connect(Socket.java:633)
        at org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75)
        at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
        ... 19 more

2023-02-23 23:34:52,905 INFO  [io.cry.age.Registration] (cryostat-agent-worker-0) Registration retry period: PT30S
2023-02-23 23:34:53,480 INFO  [io.quarkus] (main) quarkus-test 1.0.0-SNAPSHOT on JVM (powered by Quarkus 2.7.2.Final) started in 1.182s. Listening on: http://0.0.0.0:10010
2023-02-23 23:34:53,480 INFO  [io.quarkus] (main) Profile prod activated. 
2023-02-23 23:34:53,480 INFO  [io.quarkus] (main) Installed features: [cdi, rest-client, rest-client-jackson, resteasy, smallrye-context-propagation, vertx]
2023-02-23 23:35:22,906 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-0) POST http://localhost:8181/api/v2.2/discovery HTTP/1.1
2023-02-23 23:35:23,059 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-2) GET /
2023-02-23 23:35:23,075 INFO  [io.cry.age.WebServer] (cryostat-agent-worker-2) GET / : 401
2023-02-23 23:35:23,177 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST http://localhost:8181/api/v2.2/discovery : 201
2023-02-23 23:35:23,205 INFO  [io.cry.age.Registration] (cryostat-agent-worker-1) Registered as ffba92da-ff02-4009-900b-7e946f91d872
2023-02-23 23:35:23,207 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-1) JFR Harvester starting
2023-02-23 23:35:23,415 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-1) JFR Harvester started using template "default" with period PT16H40M
2023-02-23 23:35:23,425 INFO  [io.cry.age.Registration] (cryostat-agent-worker-1) publishing self as http://agent:3lr7orzimq1hmt5m@localhost:9977/
2023-02-23 23:35:23,459 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-1) POST http://localhost:8181/api/v2.2/discovery/ffba92da-ff02-4009-900b-7e946f91d872?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..Jxy7Jwq12G0z5HGA.AtQy-y6ky6nPAKeyz_wOPtxiF0O6oWus3HCptVlRDhDd6dOLSD0FNO_vft3Ty2lP4qfBigJmGP5XOE3xxo8dFYHgl61H1AS4s2VPfF66dWTaqZzl_ffR6jPsJr_yS9Cf57phBlhiL0hms9KMSiGWjAcaty8ZCKuf3W5SsGxbG14Y7DKq8fyhLk1HDX9as9eY3XMSbAxlGmXfU_aNQ3mbs4OwBfw8-kOM1SVKNSMPhdqqig9csCpXvHv84HPErlTYUtYPC5swhH2taXAtVr7QhOI2LAVyPyHSo5_FpncxpVgq3Jvc3B0192pPssScP4sZRu6rUKZ9ixnNrpYPqobxkOB7xPlJKfntm_m2V8FojC4HR8ujqoIPbLxWPlLdNl_ckO7AFNTco7ZVAdJYuSY_WkcfVTwKP9PI65R29MU3z8c5j9N_lOTV5N4DAqRJ6l34AvXKaJchfE34vOxZQBAJlGfg5o3vqahiF_Mf-5TH5n-CdBXyTM_5pznbb_fifAYOBUX7N0Pg_d-DcyY6JnUIAxCfHWueeEYBKXq8KZdOtyXhq4hP9oVenZ18xSWzUW1dPqyS.9ThG7gMtF1Y-rMim0jhzLw HTTP/1.1
2023-02-23 23:35:23,602 INFO  [io.cry.age.Harvester] (cryostat-agent-worker-2) cryostat-agent(1) RUNNING
2023-02-23 23:35:23,684 INFO  [io.cry.age.CryostatClient] (cryostat-agent-worker-2) POST http://localhost:8181/api/v2.2/discovery/ffba92da-ff02-4009-900b-7e946f91d872?token=eyJjdHkiOiJKV1QiLCJlbmMiOiJBMjU2R0NNIiwiYWxnIjoiZGlyIn0..Jxy7Jwq12G0z5HGA.AtQy-y6ky6nPAKeyz_wOPtxiF0O6oWus3HCptVlRDhDd6dOLSD0FNO_vft3Ty2lP4qfBigJmGP5XOE3xxo8dFYHgl61H1AS4s2VPfF66dWTaqZzl_ffR6jPsJr_yS9Cf57phBlhiL0hms9KMSiGWjAcaty8ZCKuf3W5SsGxbG14Y7DKq8fyhLk1HDX9as9eY3XMSbAxlGmXfU_aNQ3mbs4OwBfw8-kOM1SVKNSMPhdqqig9csCpXvHv84HPErlTYUtYPC5swhH2taXAtVr7QhOI2LAVyPyHSo5_FpncxpVgq3Jvc3B0192pPssScP4sZRu6rUKZ9ixnNrpYPqobxkOB7xPlJKfntm_m2V8FojC4HR8ujqoIPbLxWPlLdNl_ckO7AFNTco7ZVAdJYuSY_WkcfVTwKP9PI65R29MU3z8c5j9N_lOTV5N4DAqRJ6l34AvXKaJchfE34vOxZQBAJlGfg5o3vqahiF_Mf-5TH5n-CdBXyTM_5pznbb_fifAYOBUX7N0Pg_d-DcyY6JnUIAxCfHWueeEYBKXq8KZdOtyXhq4hP9oVenZ18xSWzUW1dPqyS.9ThG7gMtF1Y-rMim0jhzLw : 200
2023-02-23 23:35:23,685 INFO  [io.cry.age.Registration] (cryostat-agent-worker-2) Publish success

@maxcao13
Copy link
Member

Oh and now I get this:

Feb 23, 2023 11:40:06 PM io.cryostat.core.log.Logger info
INFO: POST http://agent:3lr7orzimq1hmt5m@localhost:9977/ status 401: Unauthorized
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: 
    /* delete io.cryostat.discovery.PluginInfo */ delete 
        from
            PluginInfo 
        where
            id=?
Feb 23, 2023 11:40:06 PM io.cryostat.core.log.Logger info
INFO: Stale discovery service http://agent:3lr7orzimq1hmt5m@localhost:9977/ removed
Feb 23, 2023 11:40:06 PM io.cryostat.core.log.Logger info
INFO: Outgoing WS message: {"meta":{"category":"TargetJvmDiscovery","type":{"type":"application","subType":"json"},"serverTime":1677195606},"message":{"event":{"serviceRef":{"jvmId":"0z5t3_RDHt06hrHreke2qwKoFeOLsAMS1e3NZe24Roo=","connectUrl":"http://agent:3lr7orzimq1hmt5m@localhost:9977/","alias":"quarkus-test-agent","labels":{},"annotations":{"platform":{},"cryostat":{"HOST":"cryostat","PORT":"9977","JAVA_MAIN":"/deployments/quarkus-run.jar","PID":"1","START_TIME":"1677195291","REALM":"quarkus-test-agent"}}},"kind":"LOST"}}}

@andrewazores
Copy link
Member Author

Got it. The backend has a bug causing it to consider any response from the plugin as a successful callback ping, not only 2xx codes.

@andrewazores
Copy link
Member Author

The bug should be fixed now. The agent generates Basic credentials at startup and clears the password from memory after it has finished registering and publishing itself. It then regenerates fresh credentials whenever it is pinged and prompted to refresh its registration, and again clears that password from memory once the registration refresh is completed.

This does mean unfortunately that the HTTP connection URL that it publishes for itself is now unstable, since the URL includes the Basic credentials, so each time Cryostat prompts Agents to refresh their registration they end up being picked up as lost and re-found targets. I need to think some more about how to resolve this. Maybe the correct approach is actually that the agent should be talking to Cryostat and registering an actual Credential resource for itself and updating that over time, rather than embedding the credentials in the connection URL.

@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-aa02c087dbe64ecdad0f55033a7494e6ff771843 sh smoketest.sh

@andrewazores
Copy link
Member Author

andrewazores commented Feb 24, 2023

New approach. The plugin generates its random credentials in-memory, then POSTs these to the Cryostat server to store as a credentials object. Once that request completes successfully, the generated password is cleared from memory (the char[] is overwritten and I was careful to not create any other copies of the password than this one single array allocation that gets cleared). The plugin receives back the credentials ID and retains that. Then the plugin registers itself with Cryostat as a discovery plugin, using storedcredentials:${id} as the userinfo of the plugin callback, where id is the credentials ID that was initially received. When Cryostat sees the plugin registration with a callback of this form, it treats that as a special case and uses it to directly look up the stored credentials from the encrypted database and uses that to set the authentication details of the callback ping request that it makes to validate the plugin. Once that is done and the plugin has registered itself with Cryostat, then it continues to publish a record of itself as a discoverable target. The originally defined credential already contained a forward reference to this agent instance's jvmId hash, so Cryostat will be able to look up credentials to the target without the connectUrl containing the credentials directly (this is the same mechanism we already normally use for JMX stored credentials). Once the agent has finished this process it only needs to be able to authenticate incoming POST/GET callback requests using the request username vs expected username and a hash of the request password vs a hash of the expected (generated) password. This works fine since the generated password was cleared much earlier - as soon as the encrypted credentials object was stored on the server - and the agent can just hang on to the SHA-256 of that password in memory.

As a nice side effect, this authenticated two-way handshake protocol also means that the old timing issue where stale plugin definitions could conflict with new plugin instances when both are torn down and recreated in close timing to each other, should no longer happen. If Cryostat has a stale definition for a plugin then when it attempts to do a startup ping to verify which plugins are still present, the ping should fail because the definition will point to stored credentials that are no longer valid for the new plugin instance, so Cryostat will prune the stale plugin definition. The plugin should then eventually try to re-register and succeed now that there is no stale duplicate definition in the way.

@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-98ce3f74657553b57283e836e74410e2325fc394 sh smoketest.sh

@andrewazores andrewazores changed the title feat(discoveryplugin): copy callback userinfo to auth header, if any feat(discoveryplugin): look up plugin callback credentials in database Feb 24, 2023
@github-actions
Copy link
Contributor

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-edd037400ca00d75b91242447cb0e7ac91893533 sh smoketest.sh

@maxcao13
Copy link
Member

maxcao13 commented Feb 28, 2023

image

Seems like the frontend doesnt recognize the credential to match any target for some reason... maybe just a visual bug.

@andrewazores
Copy link
Member Author

andrewazores commented Feb 28, 2023

I noticed that too. I don't know if it's a visual bug on the frontend or actually a bug in the backend's evaluation of the expression against the list of targets. I suspect it's on the backend. I'll take a further look into it - it should obviously have exactly one match (or zero, if the agent has disappeared without properly deregistering itself and cleaning up its credential) for each such credential defined in this way.

@andrewazores
Copy link
Member Author

On that note though, the frontend needs to be updated to remove specific references to JMX, since these stored credentials will also be used for HTTP-based Agent connections.

maxcao13
maxcao13 previously approved these changes Feb 28, 2023
Copy link
Member

@maxcao13 maxcao13 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good! Callback pings and registration work as expected with proper authentication and code looks fine.

@github-actions
Copy link
Contributor

github-actions bot commented Mar 3, 2023

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-eb76e56fd15a840e7d499ffbc252a44aa2ffa9b3 sh smoketest.sh

@andrewazores
Copy link
Member Author

@maxcao13 very very minor change to smoketest.sh in the last commit, otherwise just rebasing.

@github-actions
Copy link
Contributor

github-actions bot commented Mar 3, 2023

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-9697a2abc6d15a1fe76913314ccf2e6ee69c1e69 sh smoketest.sh

@github-actions
Copy link
Contributor

github-actions bot commented Mar 3, 2023

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-9459a3b99274503c75278474da6d278b358da6aa sh smoketest.sh

maxcao13
maxcao13 previously approved these changes Mar 6, 2023
Copy link
Member

@maxcao13 maxcao13 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Works and looks fine to me.

@github-actions
Copy link
Contributor

github-actions bot commented Mar 6, 2023

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-ff660b5fbd5dc81bb88a3e2d70270510083f71ff sh smoketest.sh

@github-actions
Copy link
Contributor

github-actions bot commented Mar 6, 2023

Test image available:

$ CRYOSTAT_IMAGE=ghcr.io/cryostatio/cryostat:pr-1377-af605be7ebda60f1b4d5fe4a19626d676acded40 sh smoketest.sh

@andrewazores andrewazores merged commit caff52d into cryostatio:main Mar 7, 2023
@andrewazores andrewazores deleted the agent-connection branch March 7, 2023 01:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
feat New feature or request safe-to-test
Projects
No open projects
Status: Done
Development

Successfully merging this pull request may close these issues.

[Task] Support authenticated HTTP requests to Agent
2 participants