Gerrit SAML Plugin Issue With Google Cloud IDentity

330 views
Skip to first unread message

janne....@vincit.fi

unread,
Aug 28, 2020, 7:06:22 AM8/28/20
to Repo and Gerrit Discussion
Hi,

I've seen Gerrit just responding with "Server error" multiple times while testing SAML plugin with Google Cloud Identity.

This error seems to happen after a user has not visited Gerrit during some period of time. When the user enters Gerrit and is required to reauthenticate through SAML, Gerrit does not handle the response properly.

It might also be that after Gerrit has been down for some time (or no one has logged in), the first user logging in triggers this issue. After initial failure, logging in with different browser (on in incognito mode) fixes the issue to login. But this does not fix login on the original browser.

Below are logs from latest occurance:

#### Gerrit started after being down for couple of days
[2020-08-28T10:51:07.087+0000] [main] INFO  com.google.gerrit.pgm.Daemon : Gerrit Code Review 3.2.3 ready




#### User enters the site and is redirected to Google login page
[2020-08-28T10:51:12.343+0000] [HTTP-96] INFO  org.pac4j.saml.config.SAML2Configuration : Bootstrapped Blacklisted Algorithms
[2020-08-28T10:51:12.343+0000] [HTTP-96] INFO  org.pac4j.saml.config.SAML2Configuration : Bootstrapped Signature Algorithms
[2020-08-28T10:51:12.343+0000] [HTTP-96] INFO  org.pac4j.saml.config.SAML2Configuration : Bootstrapped Signature Reference Digest Methods
[2020-08-28T10:51:12.343+0000] [HTTP-96] INFO  org.pac4j.saml.config.SAML2Configuration : Bootstrapped Canonicalization Algorithm
[2020-08-28T10:51:12.437+0000] [HTTP-96] INFO  org.pac4j.saml.metadata.SAML2ServiceProviderMetadataResolver : Using SP entity ID gerrit.local.vincit.fi
[2020-08-28T10:51:12.502+0000] [HTTP-96] INFO  org.pac4j.saml.metadata.SAML2ServiceProviderMetadataResolver : Metadata file already exists at /site/data/saml/sp-metadata.xml.
[2020-08-28T10:51:12.527+0000] [HTTP-96] INFO  org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver : Metadata Resolver FilesystemMetadataResolver org.opensaml.saml.metadata.resolver.impl.FilesystemMetadataResolver: New metadata successfully loaded for '/site/data/saml/sp-metadata.xml'
[2020-08-28T10:51:12.528+0000] [HTTP-96] INFO  org.opensaml.saml.metadata.resolver.impl.AbstractReloadingMetadataResolver : Metadata Resolver FilesystemMetadataResolver org.opensaml.saml.metadata.resolver.impl.FilesystemMetadataResolver: Next refresh cycle for metadata provider '/site/data/saml/sp-metadata.xml' will occur on '2020-08-28T13:51:12.511Z' ('2020-08-28T13:51:12.511Z' local time)
[2020-08-28T10:51:12.636+0000] [HTTP-96] INFO  org.pac4j.saml.crypto.DefaultSignatureSigningParametersProvider : Created signature signing parameters.
Signature canonicalization algorithm: http://www.w3.org/2001/10/xml-exc-c14n#
Signature reference digest methods: http://www.w3.org/2001/04/xmlenc#sha256


#### User returns to Gerrit after succesful authentication
[2020-08-28T10:51:18.928+0000] [HTTP-95] WARN  org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator : interval=86400,before=2020-08-28T10:56:18.928Z,after=2020-08-27T10:46:18.928Z,issueInstant=2020-08-27T10:35:51.000Z
[2020-08-28T10:51:18.929+0000] [HTTP-95] ERROR org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator : Current assertion validation failed, continue with the next one
org.pac4j.saml.exceptions.SAMLAuthnInstantException: Authentication issue instant is too old or in the future
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAuthenticationStatements(SAML2AuthnResponseValidator.java:592)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAssertion(SAML2AuthnResponseValidator.java:369)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateSamlSSOResponse(SAML2AuthnResponseValidator.java:293)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validate(SAML2AuthnResponseValidator.java:140)
 at org.pac4j.saml.profile.impl.AbstractSAML2MessageReceiver.receiveMessage(AbstractSAML2MessageReceiver.java:83)
 at org.pac4j.saml.sso.impl.SAML2WebSSOProfileHandler.receive(SAML2WebSSOProfileHandler.java:35)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:74)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:26)
 at org.pac4j.core.client.BaseClient.retrieveCredentials(BaseClient.java:65)
 at org.pac4j.core.client.IndirectClient.getCredentials(IndirectClient.java:140)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.signin(SamlWebFilter.java:180)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.doFilter(SamlWebFilter.java:153)
 at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
 at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
 at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
 at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
 at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
 at org.eclipse.jetty.server.Server.handle(Server.java:501)
 at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
 at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
 at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
 at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
 at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
 at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
 at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
 at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
 at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
 at java.base/java.lang.Thread.run(Thread.java:834)
[2020-08-28T10:51:18.930+0000] [HTTP-95] WARN  org.eclipse.jetty.server.HttpChannel : /plugins/saml/callback
org.pac4j.saml.exceptions.SAMLAuthnInstantException: Authentication issue instant is too old or in the future
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAuthenticationStatements(SAML2AuthnResponseValidator.java:592)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAssertion(SAML2AuthnResponseValidator.java:369)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateSamlSSOResponse(SAML2AuthnResponseValidator.java:293)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validate(SAML2AuthnResponseValidator.java:140)
 at org.pac4j.saml.profile.impl.AbstractSAML2MessageReceiver.receiveMessage(AbstractSAML2MessageReceiver.java:83)
 at org.pac4j.saml.sso.impl.SAML2WebSSOProfileHandler.receive(SAML2WebSSOProfileHandler.java:35)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:74)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:26)
 at org.pac4j.core.client.BaseClient.retrieveCredentials(BaseClient.java:65)
 at org.pac4j.core.client.IndirectClient.getCredentials(IndirectClient.java:140)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.signin(SamlWebFilter.java:180)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.doFilter(SamlWebFilter.java:153)
 at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
 at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
 at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
 at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
 at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
 at org.eclipse.jetty.server.Server.handle(Server.java:501)
 at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
 at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
 at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
 at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
 at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
 at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
 at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
 at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
 at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
 at java.base/java.lang.Thread.run(Thread.java:834)
[2020-08-28T10:51:18.931+0000] [HTTP-95] ERROR com.google.gerrit.pgm.http.jetty.HiddenErrorHandler : Error in POST /plugins/saml/callback?client_name=SAML2Client
org.pac4j.saml.exceptions.SAMLAuthnInstantException: Authentication issue instant is too old or in the future
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAuthenticationStatements(SAML2AuthnResponseValidator.java:592)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateAssertion(SAML2AuthnResponseValidator.java:369)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validateSamlSSOResponse(SAML2AuthnResponseValidator.java:293)
 at org.pac4j.saml.sso.impl.SAML2AuthnResponseValidator.validate(SAML2AuthnResponseValidator.java:140)
 at org.pac4j.saml.profile.impl.AbstractSAML2MessageReceiver.receiveMessage(AbstractSAML2MessageReceiver.java:83)
 at org.pac4j.saml.sso.impl.SAML2WebSSOProfileHandler.receive(SAML2WebSSOProfileHandler.java:35)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:74)
 at org.pac4j.saml.credentials.extractor.SAML2CredentialsExtractor.extract(SAML2CredentialsExtractor.java:26)
 at org.pac4j.core.client.BaseClient.retrieveCredentials(BaseClient.java:65)
 at org.pac4j.core.client.IndirectClient.getCredentials(IndirectClient.java:140)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.signin(SamlWebFilter.java:180)
 at com.googlesource.gerrit.plugins.saml.SamlWebFilter.doFilter(SamlWebFilter.java:153)
 at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1618)
 at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:549)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
 at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1369)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
 at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:489)
 at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)
 at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
 at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1284)
 at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
 at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
 at org.eclipse.jetty.server.Server.handle(Server.java:501)
 at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
 at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
 at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
 at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:272)
 at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
 at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
 at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
 at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
 at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
 at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
 at java.base/java.lang.Thread.run(Thread.java:834)

gerrit.log

janne....@vincit.fi

unread,
Aug 28, 2020, 8:29:34 AM8/28/20
to Repo and Gerrit Discussion
Hi,

It seems that the browser does cache something. Even clearing the whole Gerrit site did ton clear the issue today, i.e. I can not login with the browser I used earlier even after clearing all data from Gerrit site directory. But I'm able to login with incognito mode on the same browser and the same account.

Any ideas what could be wrong? We are using SAML with Google Cloud Identity for other services and have not seen this kind of behaviour elsewhere.

janne....@vincit.fi

unread,
Aug 28, 2020, 9:55:29 AM8/28/20
to Repo and Gerrit Discussion
Hi,

Ok, this was due to me not configuring saml.maxAuthLifetime ....

janne....@vincit.fi

unread,
Aug 28, 2020, 10:05:25 AM8/28/20
to Repo and Gerrit Discussion
But anyway, you get HTTP 500 in this case which is not most likely desired behaviour. At least I was misguided by the HTTP 500; I thought Gerrit had some issue and it took some time to until I figured it might be because of misconfiguration.

Sachidanand Patil

unread,
Oct 18, 2022, 6:04:21 AM10/18/22
to Repo and Gerrit Discussion
Hi ,

Can you please help us with the setting/value that worked for you. We have the same issue even if we set it to 72 hours i.e. 259200
It does not ignore the validation even if we set it to 0 or -1 as per pac4j code.
Your response is much appreciated.

Thanks & Regards,
Sachi

janne....@vincit.fi

unread,
Oct 19, 2022, 3:26:11 AM10/19/22
to Repo and Gerrit Discussion
Hi,

Sorry for not adding the value in my original post saying I found configuration error

I've been using this:

maxAuthLifetime = 1209600 # 60 * 60 * 24 * 14

so basically 2 weeks. Unfortunetaly I don't remember (and my Ansible playbooks don't have comment) how I came up with this value.

I have vague memory that the issue was that Gerrit did not accept the old token and Cloud Identity consider the session to be valid, i.e. max auth lifetime on Gerrit side need to be as long as Could Identity has. I did not now find how long the lifetime is on Cloud Identity side.
Reply all
Reply to author
Forward
0 new messages