Http: panic serving <IP>: runtime error: invalid memory address or nil pointer dereference after sync gateway upgrade to 3.1

Mobile Sync Gateway
1

Hi,

I have recently upgraded to Sync Gateway 3.1.
I have oidc configured and call the sync gateway API using a Bearer Token (the ID token).
If I call an endpoint, the socket hangs up and no response is received.
Tested with endpoint to get a document by id (Public REST API | Couchbase Docs).

Debug logs show the following output:

2023/06/06 16:22:03 http: panic serving 192.168.16.1:55856: runtime error: invalid memory address or nil pointer dereference
goroutine 487 [running]:
net/http.(*conn).serve.func1()
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:1850 +0xbf
panic({0x10f0140, 0x1e81250})
        /home/couchbase/cbdeps/go1.19.5/src/runtime/panic.go:890 +0x262
github.com/couchbase/sync_gateway/auth.(*OIDCProvider).initOIDCClient(0xc00032cf00, {0x15e9758, 0xc00003c038})
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:310 +0x172
github.com/couchbase/sync_gateway/auth.(*OIDCProvider).GetClient(0xc00032cf00, {0x15e9758, 0xc00003c038}, 0xc00d2de7d0)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:265 +0x1b8
github.com/couchbase/sync_gateway/auth.(*OIDCProvider).verifyToken(0x15e97c8?, {0x15e9758, 0xc00003c038}, {0xc00d412008, 0x482}, 0xc003b82a20?)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:621 +0x4e
github.com/couchbase/sync_gateway/auth.(*Authenticator).AuthenticateUntrustedJWT(0xc00d2d7420, {0xc00d412008, 0x482}, 0xc00d009770, 0xc00d0097a0, 0x0?)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/auth.go:747 +0x7ce
github.com/couchbase/sync_gateway/rest.(*handler).checkAuth(0xc00d2f6380, 0xc000554000)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:593 +0x4c9
github.com/couchbase/sync_gateway/rest.(*handler).invoke(0xc00d2f6380, 0x13045b8, {0xc00ce87d70?, 0x1, 0x1}, {0x0?, 0x0, 0x0})
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:345 +0x8f3
github.com/couchbase/sync_gateway/rest.makeHandler.func1({0x15e8a60, 0xc00d2f62a0}, 0xc00d2c1b30?)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:128 +0xd8
net/http.HandlerFunc.ServeHTTP(0xc00d220300?, {0x15e8a60?, 0xc00d2f62a0?}, 0xc00d427840?)
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2109 +0x2f
github.com/gorilla/mux.(*Router).ServeHTTP(0xc000576780, {0x15e8a60, 0xc00d2f62a0}, 0xc000679000)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/godeps/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1cf
github.com/couchbase/sync_gateway/rest.wrapRouter.func1({0x15e8a60, 0xc00d2f62a0}, 0xc000679000)
        /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/routing.go:374 +0x251
net/http.HandlerFunc.ServeHTTP(0x0?, {0x15e8a60?, 0xc00d2f62a0?}, 0x46b90e?)
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2109 +0x2f
net/http.serverHandler.ServeHTTP({0xc004448ba0?}, {0x15e8a60, 0xc00d2f62a0}, 0xc000679000)
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2947 +0x30c
net/http.(*conn).serve(0xc000001860, {0x15e97c8, 0xc00d1a6360})
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:1991 +0x607
created by net/http.(*Server).Serve
        /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:3102 +0x4db

Every request fails until one request using session cookies is received. Afterwards, requests including only the id token will succeed, until the sync gateway is restarted.

The oidc config is (points to a keycloak IdP):

{
    "oidc": {
        "providers": {
            "keycloak": {
                "issuer": "https://domain.com/auth/realms/name",
                "register": true,
                "client_id": "client_id",
                "username_claim": "",
                "roles_claim": "",
                "channels_claim": "",
                "allow_unsigned_provider_tokens": false,
                "IsDefault": false,
                "Name": "",
                "InsecureSkipVerify": false
            }
        }
    }
}

Happens in both Couchbase Sync Gateway/3.1.0(592;2a9837d) CE as well as Couchbase Sync Gateway/3.1.0(592;2a9837d) EE

Any help is greatly appreciated.

2

Outside the panic, do you see errors in the Sync Gateway logs for OIDC?

I am thinking: Can't calculate OIDC callback URL without DB in path. or Failed to add provider %q to OIDC callback URL.

3

Yes: [WRN] c:#9192 db:db Can't calculate OIDC callback URL without DB in path. -- rest.(*handler).getOIDCCallbackURL() at oidc_api.go:302

4

Can you provide more context from the SG logs (showing the request being made with the bearer token), as well as the config for the SG database?

5

I’ve now tried it with a fresh install, still the same problem.

These are the sync gateway console logs with log_level: trace, when making an api request:

couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:23.448Z [TRC] gocb+: CCCPPOLL: Got Block: {"rev":70,"revEpoch":1,"name":"my-bucket","nodeLocator":"vbucket","bucketType":"membase","uuid":"f4f927413f0fcab1bb16cdf726e2a42f","uri":"/pools/default/buckets/my-bucket?bucket_uuid=f4f927413f0fcab1bb16cdf726e2a42f","streamingUri":"/pools/default/bucketsStreaming/my-bucket?bucket_uuid=f4f927413f0fcab1bb16cdf726e2a42f","bucketCapabilitiesVer":"","bucketCapabilities":["collections","durableWrite","tombstonedUserXAttrs","couchapi","subdoc.ReplaceBodyWithXattr","subdoc.DocumentMacroSupport","dcp","cbhello","touch","cccp","xdcrCheckpointing","nodesExt","xattr"],"collectionsManifestUid":"0","ddocs":{"uri":"/pools/default/buckets/my-bucket/ddocs"},"vBucketServerMap":{"hashAlgorithm":"CRC","numReplicas":1,"serverList":["$HOST:11210"],"vBucketMap":[[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1],[0,-1]]},"nodes":[{"couchApiBase":"http://$HOST:8092/my-bucket%2Bf4f927413f0fcab1bb16cdf726e2a42f","hostname":"$HOST:8091","ports":{"direct":11210}}],"nodesExt":[{"services":{"capi":8092,"fts":8094,"ftsGRPC":9130,"indexAdmin":9100,"indexHttp":9102,"indexScan":9101,"indexStreamCatchup":9104,"indexStreamInit":9103,"indexStreamMaint":9105,"kv":11210,"mgmt":8091,"n1ql":8093,"projector":9999},"thisNode":true}],"clusterCapabilitiesVer":[1,0],"clusterCapabilities":{"n1ql":["enhancedPreparedStatements"]}} -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:23.450Z [TRC] gocb+: CCCPPOLL: Received new config -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:23.450Z [TRC] gocb+: Ignoring configuration with identical revision number -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023/06/12 23:09:24 http: panic serving 192.168.16.1:59702: runtime error: invalid memory address or nil pointer dereference
couchbase-sgw-sync-gateway-1  | goroutine 599 [running]:
couchbase-sgw-sync-gateway-1  | net/http.(*conn).serve.func1()
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:1850 +0xbf
couchbase-sgw-sync-gateway-1  | panic({0x10f0140, 0x1e81250})
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/runtime/panic.go:890 +0x262
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/auth.(*OIDCProvider).initOIDCClient(0xc0008f50e0, {0x15e9758, 0xc0000cc008})
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:310 +0x172
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/auth.(*OIDCProvider).GetClient(0xc0008f50e0, {0x15e9758, 0xc0000cc008}, 0xc00bbd6b30)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:265 +0x1b8
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/auth.(*OIDCProvider).verifyToken(0x15e97c8?, {0x15e9758, 0xc0000cc008}, {0xc00a05ef08, 0x47e}, 0xc009d74a20?)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/oidc.go:621 +0x4e
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/auth.(*Authenticator).AuthenticateUntrustedJWT(0xc009b37ab0, {0xc00a05ef08, 0x47e}, 0xc0086988d0, 0xc008698900, 0x0?)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/auth/auth.go:747 +0x7ce
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/rest.(*handler).checkAuth(0xc00ab25420, 0xc0086c5200)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:593 +0x4c9
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/rest.(*handler).invoke(0xc00ab25420, 0x13045b8, {0xc00066b038?, 0x1, 0x1}, {0x0?, 0x0, 0x0})
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:345 +0x8f3
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/rest.makeHandler.func1({0x15e8a60, 0xc00ab25340}, 0xc00bda8480?)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/handler.go:128 +0xd8
couchbase-sgw-sync-gateway-1  | net/http.HandlerFunc.ServeHTTP(0xc000489100?, {0x15e8a60?, 0xc00ab25340?}, 0xc003b15840?)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2109 +0x2f
couchbase-sgw-sync-gateway-1  | github.com/gorilla/mux.(*Router).ServeHTTP(0xc00045c300, {0x15e8a60, 0xc00ab25340}, 0xc000489000)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/godeps/pkg/mod/github.com/gorilla/mux@v1.8.0/mux.go:210 +0x1cf
couchbase-sgw-sync-gateway-1  | github.com/couchbase/sync_gateway/rest.wrapRouter.func1({0x15e8a60, 0xc00ab25340}, 0xc000489000)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/jenkins/workspace/sgw-unix-build/3.1.0/community/sync_gateway/rest/routing.go:374 +0x251
couchbase-sgw-sync-gateway-1  | net/http.HandlerFunc.ServeHTTP(0x0?, {0x15e8a60?, 0xc00ab25340?}, 0x46b90e?)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2109 +0x2f
couchbase-sgw-sync-gateway-1  | net/http.serverHandler.ServeHTTP({0xc00bda82d0?}, {0x15e8a60, 0xc00ab25340}, 0xc000489000)
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:2947 +0x30c
couchbase-sgw-sync-gateway-1  | net/http.(*conn).serve(0xc009b38820, {0x15e97c8, 0xc009b06de0})
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:1991 +0x607
couchbase-sgw-sync-gateway-1  | created by net/http.(*Server).Serve
couchbase-sgw-sync-gateway-1  |         /home/couchbase/cbdeps/go1.19.5/src/net/http/server.go:3102 +0x4db
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.003Z [TRC] Auth+: c:#003 db:db Using OIDC provider <ud>https://url/auth/realms/master</ud> -- auth.(*Authenticator).AuthenticateUntrustedJWT() at auth.go:726
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.003Z [WRN] c:#003 db:db Can't calculate OIDC callback URL without DB in path. -- rest.(*handler).getOIDCCallbackURL() at oidc_api.go:302
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.003Z [INF] HTTP: c:#003 db:db GET /db/<ud>4febf50d-9063-4810-8a33-374387dc02bc</ud>
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.512Z [TRC] gocb+: Writing request. 192.168.16.6:43994 to couchbase-server:11210 OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: couchbase-server:11210/0xc0001582a0 memdclient resolving response OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: Handling response data. OP=0  xb5. Opaque=36. Status:0 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: Dispatching response callback. OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: CCCPPOLL: Got Block: {"rev":70,"nodesExt":[{"services":{"capi":8092,"fts":8094,"ftsGRPC":9130,"indexAdmin":9100,"indexHttp":9102,"indexScan":9101,"indexStreamCatchup":9104,"indexStreamInit":9103,"indexStreamMaint":9105,"kv":11210,"mgmt":8091,"n1ql":8093,"projector":9999},"thisNode":true}],"clusterCapabilitiesVer":[1,0],"clusterCapabilities":{"n1ql":["enhancedPreparedStatements"]},"revEpoch":1} -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: CCCPPOLL: Received new config -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.514Z [TRC] gocb+: Ignoring configuration with identical revision number -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.764Z [TRC] gocb+: Writing request. 192.168.16.6:44010 to couchbase-server:11210 OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.765Z [TRC] gocb+: couchbase-server:11210/0xc0004fe000 memdclient resolving response OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.765Z [TRC] gocb+: Handling response data. OP=0xb5. Opaque=36. Status:0 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.765Z [TRC] gocb+: Dispatching response callback. OP=0xb5. Opaque=36 -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.765Z [TRC] gocb+: CCCPPOLL: Got Block: {"rev":70,"nodesExt":[{"services":{"capi":8092,"fts":8094,"ftsGRPC":9130,"indexAdmin":9100,"indexHttp":9102,"indexScan":9101,"indexStreamCatchup":9104,"indexStreamInit":9103,"indexStreamMaint":9105,"kv":11210,"mgmt":8091,"n1ql":8093,"projector":9999},"thisNode":true}],"clusterCapabilitiesVer":[1,0],"clusterCapabilities":{"n1ql":["enhancedPreparedStatements"]},"revEpoch":1} -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.766Z [TRC] gocb+: CCCPPOLL: Received new config -- base.GoCBCoreLogger.Log() at logger_external.go:70
couchbase-sgw-sync-gateway-1  | 2023-06-12T23:09:24.766Z [TRC] gocb+: Ignoring configuration with identical revision number -- base.GoCBCoreLogger.Log() at logger_external.go:70

Request made:

curl --location --request GET 'localhost:4984/db/4febf50d-9063-4810-8a33-374387dc02bc' \
--header 'Authorization: Bearer token'

When then creating a cookie session, this is the output (I sent an expired token):

2023-06-12T23:24:22.257Z [INF] Auth: Fetching provider config from standard issuer-based discovery endpoint: <ud>https://url.com/auth/realms/master/.well-known/openid-configuration</ud>
2023-06-12T23:24:22.386Z [INF] Auth: Found algorithms not supported by underlying OpenID Connect library: [HS256 HS512 HS384]
2023-06-12T23:24:22.386Z [DBG] Auth+: Fetching custom provider config from <ud>https://url.com/auth/realms/master/.well-known/openid-configuration</ud>
2023-06-12T23:24:22.414Z [DBG] Auth+: No change in discovery config detected at this time, next sync will be after 24h0m0s
2023-06-12T23:24:22.414Z [DBG] Auth+: Client <ud>&{mutex:{w:{state:0 sema:0} writerSem:0 readerSem:0 readerCount:0 readerWait:0} config:0xc00d0a8cb0 verifier:0xc00dad64e0}</ud> could not verify JWT. Error: oidc: token is expired (Token Expiry: 2023-06-10 07:58:21 +0000 UTC)
2023-06-12T23:24:22.414Z [DBG] Auth+: c:#002 db:db JWT invalid: oidc: token is expired (Token Expiry: 2023-06-10 07:58:21 +0000 UTC)
2023-06-12T23:24:22.414Z [INF] HTTP: c:#002 db:db POST /db/_session
2023-06-12T23:24:22.414Z [INF] HTTP: c:#002 db:db #002:     --> 401 Invalid login  (157.9 ms)

I noticed, with trace log level enabled, there is a lot of logging output, for a fresh local installation without any clients connecting. I have attached a file containing a couple seconds of output.
sg_logs.zip (5.2 KB)

Here’s the config:
Output of {db}/_config:

{
    "bucket": "my-bucket",
    "name": "db",
    "import_docs": true,
    "oidc": {
        "providers": {
            "keycloakatu": {
                "issuer": "https://url/auth/realms/master",
                "register": true,
                "client_id": "automated-testing",
                "username_claim": "",
                "roles_claim": "",
                "channels_claim": "",
                "allow_unsigned_provider_tokens": false,
                "IsDefault": false,
                "Name": "",
                "InsecureSkipVerify": false
            },
            "keycloakimplicit": {
                "issuer": "https://url/auth/realms/master",
                "register": true,
                "client_id": "mobile_apps",
                "username_claim": "",
                "roles_claim": "",
                "channels_claim": "",
                "allow_unsigned_provider_tokens": false,
                "IsDefault": false,
                "Name": "",
                "InsecureSkipVerify": false
            }
        }
    },
    "enable_shared_bucket_access": true,
    "num_index_replicas": 0
}

output of /{db}/

{
    "db_name": "db",
    "update_seq": 9,
    "committed_update_seq": 9,
    "instance_start_time": 1686612218699950,
    "compact_running": false,
    "purge_seq": 0,
    "disk_format_version": 0,
    "state": "Online",
    "server_uuid": "66f9b1cc34f7dd149a6928a6b01b3a67"
}

server config, output of /_config:

{
    "bootstrap": {
        "server": "couchbase://couchbase-server",
        "username": "sync-gateway",
        "password": "xxxxx",
        "use_tls_server": false
    },
    "api": {
        "admin_interface": ":4985",
        "admin_interface_authentication": false,
        "https": {},
        "cors": {
            "origin": [
                "http://localhost:8080",
                "http://localhost:4984"
            ],
            "login_origin": [
                "http://localhost:8080",
                "http://localhost:4984"
            ],
            "headers": [
                "Content-Type",
                "Authorization",
                "Set-Cookie",
                "sentry-trace"
            ],
            "max_age": 1728000
        }
    },
    "logging": {
        "console": {
            "rotation": {},
            "log_level": "trace",
            "log_keys": [
                "*"
            ]
        },
        "error": {
            "rotation": {}
        },
        "warn": {
            "rotation": {}
        },
        "info": {
            "rotation": {}
        },
        "debug": {
            "enabled": true,
            "rotation": {}
        },
        "trace": {
            "rotation": {}
        },
        "stats": {
            "rotation": {}
        }
    },
    "auth": {},
    "replicator": {},
    "unsupported": {
        "serverless": {},
        "http2": {}
    }
}

Server information:

{
    "ADMIN": true,
    "couchdb": "Welcome",
    "vendor": {
        "name": "Couchbase Sync Gateway",
        "version": "3.1"
    },
    "version": "Couchbase Sync Gateway/3.1.0(592;2a9837d) CE",
    "persistent_config": true
}
6

Thanks for the detailed information. We’ve identified the issue and are working on a fix.

https://issues.couchbase.com/browse/CBG-3102

In the meantime, a workaround would be to allow the OIDC provider to be initialized from a /db/ scoped API endpoint using a Bearer token, before any keyspace-scoped requests are made.

E.g: GET /db/ returns db status, or /db/_session, before any document API requests are made (/db/docID or /db.scope.collection/docID)

7

Thanks for the help!

Is there any public information we can follow when 3.1.1 will be approximately released? This would help us asses how much time we spent integrating the workaround.

And may I ask if this issue (Every REST API call with oidc Bearer Token increases sequence number since sync gateway 3.1, leading to spamming changes feed) is related? We encounter this also after having initialized the OIDC provider.

Thanks again for the quick help!

8

Just coming back to this thread - that issue is separate but has also been fixed in 3.1.1 which was recently released: Release Notes | Couchbase Docs

1 Like