breakfix: Caddy unable to load plugin on startup while using Google OAuth 2.0

[lucasbaile]

Describe the issue

Hello!

We've been using this plugin with Caddy to use Google SSO and authenticate on a internal page but recently we've noticed the authentification stopped working. Initially, Caddy was still up but we were getting the "Unauthorized" page when going through the SSO flow

While investigating I tried restarting our caddy service and noticed that at this point Waddy is not starting at all correctly anymore, with the following error logs:

Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.5906324,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"warn","ts":1692966259.595415,"msg":"Caddyfile input is not formatted; run 'caddy fmt --overwrite' to fix inconsistencies","adapter":"caddyfile","file":"/etc/caddy/Caddyfile","line":9}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.598708,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.599086,"logger":"http.auto_https","msg":"server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS","server_name":"srv0","https_port":443}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.5991147,"logger":"http.auto_https","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"warn","ts":1692966259.5991294,"logger":"http.auto_https","msg":"server is listening only on the HTTP port, so no automatic HTTPS will be applied to this server","server_name":"srv1","http_port":80}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.5994086,"logger":"security","msg":"provisioning app instance","app":"security"}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.6013534,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00095f480"}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"error","ts":1692966259.7911687,"logger":"security","msg":"failed provisioning app server instance","app":"security","error":"server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value"}
Aug 25 14:24:19 int-docs caddy[7688]: {"level":"info","ts":1692966259.7914274,"logger":"tls.cache.maintenance","msg":"stopped background certificate maintenance","cache":"0xc00095f480"}
Aug 25 14:24:19 int-docs caddy[7688]: Error: loading initial config: loading new config: loading http app module: provision http: server srv0: setting up route handlers: route 0: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 0: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 0: loading handler modules: position 0: loading module 'authenticator': provision http.handlers.authenticator: loading security app module: provision security: server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value

Initially we were running Caddy version 2.5.2 and caddy-security version 1.1.14, but we also tried updating to the latest versions (Caddy 2.7.4 and caddy-security 1.1.19), but the startup error message is exactly the same

I've triple-checked that nothing on our Google Cloud console configuration has changed and our credentials are still valid and enabled, and nothing else changed on our side

Any help would be appreciated, as I couldn't find anything related in my research

Configuration

/etc/caddy/Caddyfile

# The Caddyfile is an easy way to configure your Caddy web server.
#
# https://caddyserver.com/docs/caddyfile

# As an alternative to editing the above site block, you can add your own site
# block files in the Caddyfile.d directory, and they will be included as long
# as they use the .caddyfile extension.
import Caddyfile.d/*.caddyfile

/etc/caddy/Caddyfile.d/auth.caddyfile

{
    order authenticate before respond
    order authorize before basicauth

    security {
        oauth identity provider google {
            realm google
            driver google
            client_id XXXXXXXXXXXX
            client_secret XXXXXXXXXXXX
            scopes openid email profile
        }

        authentication portal myportal-ui.surfly.com {
            crypto default token lifetime 3600
            crypto key sign-verify {env.JWT_SHARED_KEY}
            enable identity provider google
            cookie domain ui.surfly.com

            transform user {
                match realm google
                action add role authp/user
            }

            transform user {
                match realm google
                match email sysadmin@surfly.com
                action add role authp/admin
            }
        }

        authorization policy mypolicy-ui.surfly.com {
            set auth url https://auth.ui.surfly.com/oauth2/google/authorization-code-callback
            crypto key verify {env.JWT_SHARED_KEY}
            allow roles authp/admin authp/user
            validate bearer header
            inject headers with claims
        }
    }
}

auth.ui.surfly.com {
    authenticate with myportal-ui.surfly.com
}

/etc/caddy/Caddyfile.d/ui.caddyfile

ui.surfly.com {
    authorize with mypolicy-ui.surfly.com

    file_server * {
        root /web-data/suimono
    }
    log {
        format console
    }
}

Version Information

Image running Caddy 2.5.2

http.authentication.providers.authorizer v1.1.14
http.handlers.authenticator v1.1.14
http.handlers.trace v1.1.10
security v1.1.14

Image running Caddy 2.7.4

http.authentication.providers.authorizer v1.1.19
http.handlers.authenticator v1.1.19
http.handlers.trace v1.1.11
security v1.1.19

Expected behavior

Expected caddy to load the plugin correctly and authenticate correctly using Google OAuth 2.0

Additional context

We run caddy using a podman image that's custom-built to add the caddy-security plugin. This is the Containerfile used:

ARG CADDY_VERSION
ARG CADDY_SECURITY_VERSION
FROM docker.io/library/caddy:${CADDY_VERSION}-builder AS builder
RUN xcaddy build --with github.com/greenpau/caddy-security@${CADDY_SECURITY_VERSION} --with github.com/greenpau/caddy-trace

ARG CADDY_VERSION
FROM docker.io/library/caddy:${CADDY_VERSION}
COPY --from=builder /usr/bin/caddy /usr/bin/caddy

We use auto-generated Let's Encrypt certificates through Caddy, so that's why we don't have a tls section and/or certificates configured

[bluelu]

Hi,

We are experiencing the same problem since this morning.

We did not change anything in our configuration, we did not restart caddy and also we didn't do any changes on the google side. We tried to issue a new secret but this also didn't help. Neither did updating caddy to the latest version.

Dec 11 08:45:02 mavenproxy caddy[2550265]: Error: loading initial config: loading new config: loading http app module: provision http: server srv0: setting up route handlers: route 1: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 3: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 0: loading handler modules: position 0: loading module 'authentication': provision http.handlers.authentication: loading authentication providers: module name 'authorizer': provision http.authentication.providers.authorizer: loading security app module: provision security: server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value

@lucasbaile How did you solve the issue?

@greenpau Any idea what might have caused this?

[lucasbaile]

Hi,

We are experiencing the same problem since this morning.

We did not change anything in our configuration, we did not restart caddy and also we didn't do any changes on the google side. We tried to issue a new secret but this also didn't help. Neither did updating caddy to the latest version.

Dec 11 08:45:02 mavenproxy caddy[2550265]: Error: loading initial config: loading new config: loading http app module: provision http: server srv0: setting up route handlers: route 1: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 3: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 0: loading handler modules: position 0: loading module 'authentication': provision http.handlers.authentication: loading authentication providers: module name 'authorizer': provision http.authentication.providers.authorizer: loading security app module: provision security: server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value

@lucasbaile How did you solve the issue?

At the time we had to disable the plugin and resort back to basic auth to restore access

Unfortunately haven't had time to look into it ever since so I can't give a better update on this

[greenpau]

@bluelu , enable debug and see what the response actually is.

[s-rwe]

@greenpau - we tried to restart again with debug enabled in Caddy config, though still can't make sense of it...

Here's the last output before startup fails:

Dec 11 15:22:50 mavenproxy caddy[1484]: {"level":"info","ts":1702304570.0068884,"logger":"security","msg":"provisioning app instance","app":"security"}
Dec 11 15:22:50 mavenproxy caddy[1484]: {"level":"debug","ts":1702304570.0621312,"logger":"security","msg":"fetchMetadataURL succeeded","identity_provider_name":"google","metadata":{"authorization_endpoint":"https://accounts.google.com/o/oauth2/v2/auth","claims_supported":["aud","email","email_verified","exp","family_name","given_name","iat","iss","locale","name","picture","sub"],"code_challenge_methods_supported":["plain","S256"],"device_authorization_endpoint":"https://oauth2.googleapis.com/device/code","grant_types_supported":["authorization_code","refresh_token","urn:ietf:params:oauth:grant-type:device_code","urn:ietf:params:oauth:grant-type:jwt-bearer"],"id_token_signing_alg_values_supported":["RS256"],"issuer":"https://accounts.google.com","jwks_uri":"https://www.googleapis.com/oauth2/v3/certs","response_types_supported":["code","token","id_token","code token","code id_token","token id_token","code token id_token","none"],"revocation_endpoint":"https://oauth2.googleapis.com/revoke","scopes_supported":["openid","email","profile"],"subject_types_supported":["public"],"token_endpoint":"https://oauth2.googleapis.com/token","token_endpoint_auth_methods_supported":["client_secret_post","client_secret_basic"],"userinfo_endpoint":"https://openidconnect.googleapis.com/v1/userinfo"},"userinfo_endpoint":"https://openidconnect.googleapis.com/v1/userinfo"}
Dec 11 15:22:50 mavenproxy caddy[1484]: {"level":"error","ts":1702304570.189998,"logger":"security","msg":"failed provisioning app server instance","app":"security","error":"server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value"}
Dec 11 15:22:50 mavenproxy caddy[1484]: {"level":"info","ts":1702304570.190457,"logger":"tls.cache.maintenance","msg":"stopped background certificate maintenance","cache":"0xc000eb9900"}
Dec 11 15:22:50 mavenproxy caddy[1484]: Error: loading initial config: loading new config: loading http app module: provision http: server srv0: setting up route handlers: route 1: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 3: loading handler modules: position 0: loading module 'subroute': provision http.handlers.subroute: setting up subroutes: route 0: loading handler modules: position 0: loading module 'authentication': provision http.handlers.authentication: loading authentication providers: module name 'authorizer': provision http.authentication.providers.authorizer: loading security app module: provision security: server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value
Dec 11 15:22:50 mavenproxy systemd[1]: caddy.service: Main process exited, code=exited, status=1/FAILURE
Dec 11 15:22:50 mavenproxy systemd[1]: caddy.service: Failed with result 'exit-code'.
Dec 11 15:22:50 mavenproxy systemd[1]: Failed to start Caddy.

[bluelu]

@greenpau @lucasbaile

We installed a fresh copy of caddy on another machine and we didn't have any problems. We then tried with a backup from 2 days ago (where it was still working) on the same machine and it still didn't work We copied over the install to another machine with a different ip and it worked without any issues.

So it seems that our IP got blacklisted or rate limited by Google. Also before there was a log entry about being rate limited in the log file before (we lost the log file now since we reinstalled). I will investigate with them

Our login portal is facing the internet but only allowing local domain logins.

[greenpau]

Dec 11 15:22:50 mavenproxy caddy[1484]: {"level":"error","ts":1702304570.189998,"logger":"security","msg":"failed provisioning app server instance","app":"security","error":"server initialization failed: failed configuring identity provider: failed to fetch jwt keys for OAuth 2.0 authorization server: invalid character '<' looking for beginning of value"}

@bluelu , @s-rwe , compile your own version of the portal following these instructions. https://github.com/greenpau/caddy-security/blob/main/CONTRIBUTING.md#development-environment

Modify the code to see what the server is responding with. The invalid character '<' looking for beginning of value tells me you receive some kind of HTML response back.

I will be working on updating the plugin this week and will add something that would output the server response fully.