Hello,
I have been trying to set up a Gerrit instance (latest version, running
in a local VM) with OAuth2 authentication using Keycloak (also running
at the same VM), and I'm seeing some strange errors.
First, some information about my setup. I'm running Debian 10 (buster)
with OpenJDK 11 installed. It took me a bit but I managed to make
Gerrit start with it, and it has been running without problems. Here's
my gerrit.config:
[gerrit]
basePath = git
canonicalWebUrl =
http://192.168.122.32/gerrit/
serverId = c505cc81-e662-4c48-9dd3-7617f7c6d525
[container]
javaOptions = "-Dflogger.backend_factory=com.google.common.flogger.backend.log4j.Log4jBackendFactory#getInstance"
javaOptions = "-Dflogger.logging_context=com.google.gerrit.server.logging.LoggingContext#getInstance"
javaOptions = --add-opens=jdk.management/com.sun.management.internal=ALL-UNNAMED
user = gerrit
javaHome = /usr/lib/jvm/java-11-openjdk-amd64
[index]
type = LUCENE
[auth]
type = OAUTH
gitBasicAuthPolicy = HTTP
[receive]
enableSignedPush = false
[sendemail]
smtpServer = localhost
[sshd]
listenAddress = *:29418
[httpd]
listenUrl = proxy-
http://127.0.0.1:8081/gerrit/
[cache]
directory = cache
[plugins]
allowRemoteAdmin = true
[plugin "gerrit-oauth-provider-keycloak-oauth"]
root-url =
http://192.168.122.32:8877
realm = gerrit
client-id = gerrit
The main problem I'm facing has to do with a "Server Error" I'm getting
after I authenticate on Keycloak. The redirect_uri parameter is
"
http://192.168.122.32/gerrit/oauth", and Keycloak is indeed redirecting
me to (after I successfully enter my user/password):
<
http://192.168.122.32/gerrit/oauth?state=1w8zlPoyB6MKV0d3b1oxlVoZQSR2wdBYzoyRMhf0pkU&session_state=0cace963-06fb-4537-8ee5-81d015f644ed&code=fe554d1b-e667-400d-a657-b236e0e246c1.0cace963-06fb-4537-8ee5-81d015f644ed.6966edc3-701b-4c24-85c3-e36e04099dee>
However, that URL gives me the "Server Error" I mentioned. When I look
at Gerrit's logs, I see:
[2019-10-08 23:41:09,126] [HTTP-92] ERROR com.google.gerrit.pgm.http.jetty.HiddenErrorHandler : Error in GET /gerrit/oauth?state=1w8zlPoyB6MKV0d3b1oxlVoZQSR2wdBYzoyRMhf0pkU&session_state=0cace963-06fb-4537-8ee5-81d015f644ed&code=fe554d1b-e667-400d-a657-b236e0e246c1.0cace963-06fb-4537-8ee5-81d015f644ed.6966edc3-701b-4c24-85c3-e36e04099dee
java.lang.StringIndexOutOfBoundsException: String index out of range: -1
at java.base/java.lang.String.substring(String.java:1841)
at com.google.gerrit.httpd.auth.oauth.OAuthSession.authenticateAndRedirect(OAuthSession.java:156)
at com.google.gerrit.httpd.auth.oauth.OAuthSession.login(OAuthSession.java:109)
at com.google.gerrit.httpd.auth.oauth.OAuthWebFilter.doFilter(OAuthWebFilter.java:105)
at com.google.gerrit.httpd.RunAsFilter.doFilter(RunAsFilter.java:120)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:133)
at com.gerritforge.gerrit.plugins.account.XAuthFilter.doFilter(XAuthFilter.java:73)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:129)
at com.gerritforge.gerrit.plugins.account.AccountLoginRedirectFilter.doFilter(AccountLoginRedirectFilter.java:82)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:129)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy.doFilter(AllRequestFilter.java:135)
at com.google.gerrit.httpd.RequestMetricsFilter.doFilter(RequestMetricsFilter.java:57)
at com.google.gerrit.httpd.RequestContextFilter.doFilter(RequestContextFilter.java:69)
at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:121)
at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.Server.handle(Server.java:502)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
at java.base/java.lang.Thread.run(Thread.java:834)
The interesting thing is that if I then go to the main page, I see
myself authenticated there.
The other problem happens when I try to logout. If I click on "Sign
out", Gerrit shows me that the sign out happened successfully. However,
when I try logging in again, I am redirected to the exact same
"/gerrit/oauth?state=..." URL I posted above, but now I see a different
error in the logs:
[2019-10-08 23:50:33,046] [HTTP-77] ERROR com.google.gerrit.pgm.http.jetty.HiddenErrorHandler : Error in GET /gerrit/oauth?state=1w8zlPoyB6MKV0d3b1oxlVoZQSR2wdBYzoyRMhf0pkU&session_state=0cace963-06fb-4537-8ee5-81d015f644ed&code=fc1becf8-6b8b-4689-ae8a-e6d62d00f477.0cace963-06fb-4537-8ee5-81d015f644ed.6966edc3-701b-4c24-85c3-e36e04099dee
org.scribe.exceptions.OAuthException: Cannot extract an access token. Response was: {"error":"invalid_grant","error_description":"Code not valid"}
at org.scribe.extractors.JsonTokenExtractor.extract(JsonTokenExtractor.java:23)
at com.googlesource.gerrit.plugins.oauth.OAuth20ServiceImpl.getAccessToken(OAuth20ServiceImpl.java:70)
at com.googlesource.gerrit.plugins.oauth.KeycloakOAuthService.getAccessToken(KeycloakOAuthService.java:120)
at com.google.gerrit.httpd.auth.oauth.OAuthSession.login(OAuthSession.java:104)
at com.google.gerrit.httpd.auth.oauth.OAuthWebFilter.doFilter(OAuthWebFilter.java:105)
at com.google.gerrit.httpd.RunAsFilter.doFilter(RunAsFilter.java:120)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:133)
at com.gerritforge.gerrit.plugins.account.XAuthFilter.doFilter(XAuthFilter.java:73)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:129)
at com.gerritforge.gerrit.plugins.account.AccountLoginRedirectFilter.doFilter(AccountLoginRedirectFilter.java:82)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:129)
at com.google.gerrit.httpd.AllRequestFilter$FilterProxy.doFilter(AllRequestFilter.java:135)
at com.google.gerrit.httpd.RequestMetricsFilter.doFilter(RequestMetricsFilter.java:57)
at com.google.gerrit.httpd.RequestContextFilter.doFilter(RequestContextFilter.java:69)
at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:121)
at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.Server.handle(Server.java:502)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
at java.base/java.lang.Thread.run(Thread.java:834)
When I look at Keycloak's logs, I see:
23:50:33,044 WARN [org.keycloak.protocol.oidc.utils.OAuth2CodeParser] (default task-82) Code 'fc1becf8-6b8b-4689-ae8a-e6d62d00f477' already used for userSession '0cace963-06fb-4537-8ee5-81d015f644ed' and client '6966edc3-701b-4c24-85c3-e36e04099dee'.
23:50:33,044 WARN [org.keycloak.events] (default task-82) type=CODE_TO_TOKEN_ERROR, realmId=gerrit, clientId=gerrit, userId=null, ipAddress=192.168.122.32, error=invalid_code, grant_type=authorization_code, code_id=0cace963-06fb-4537-8ee5-81d015f644ed, client_auth_method=client-secret
IIUC, this is telling that the sign out process happened on Gerrit, but
wasn't "replicated" to Keycloak (i.e., I'm still logged in on Keycloak).
Has anyone here experience these problems when using OAuth2 with Gerrit
and Keycloak? Any suggestions on what to try? I've already tried
changing a lot of settings on Keycloak, without success.
Thanks in advance.
--
Sergio
GPG key ID: 237A 54B1 0287 28BF 00EF 31F4 D0EB 7628 65FC 5E36
Please send encrypted e-mail if possible
http://sergiodj.net/