Unable to login from subwikis with OIDC after update from 16.6.0 to 17.4.0

After updating our XWiki instance from 16.6.0 to 17.4.0 we are getting HTTP Status 500 – Internal Server Error when attempting to log in using OIDC (Extension version 2.18.1) from a subwiki. Login from the main wiki works fine. The stack trace of the error is:

Stack trace
Exception

jakarta.servlet.ServletException: Failed to handle Resource Reference [path = authenticator/callback, endpoint = authenticator, pathSegments = [callback]]
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.handleResourceReference(ResourceReferenceHandlerServlet.java:162)
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.service(ResourceReferenceHandlerServlet.java:90)
	jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
	org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:66)
	org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:148)
	org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:211)
	org.xwiki.container.servlet.filters.internal.SafeRedirectFilter.doFilter(SafeRedirectFilter.java:106)
	org.xwiki.container.servlet.filters.internal.ResolveRelativeRedirectFilter.doFilter(ResolveRelativeRedirectFilter.java:129)
	org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:120)

Root Cause

org.xwiki.resource.ResourceReferenceHandlerException: Failed to handle the OIDC endpoint
	org.xwiki.contrib.oidc.provider.internal.OIDCResourceReferenceHandler.handle(OIDCResourceReferenceHandler.java:114)
	org.xwiki.resource.internal.DefaultResourceReferenceHandlerChain.handleNext(DefaultResourceReferenceHandlerChain.java:79)
	org.xwiki.resource.internal.AbstractResourceReferenceHandlerManager.handle(AbstractResourceReferenceHandlerManager.java:82)
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.handleResourceReference(ResourceReferenceHandlerServlet.java:160)
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.service(ResourceReferenceHandlerServlet.java:90)
	jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
	org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:66)
	org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:148)
	org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:211)
	org.xwiki.container.servlet.filters.internal.SafeRedirectFilter.doFilter(SafeRedirectFilter.java:106)
	org.xwiki.container.servlet.filters.internal.ResolveRelativeRedirectFilter.doFilter(ResolveRelativeRedirectFilter.java:129)
	org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:120)

Root Cause

org.xwiki.contrib.oidc.provider.internal.OIDCException: Failed to get access token: invalid_grant
	org.xwiki.contrib.oidc.auth.internal.OIDCTokenRequestHelper.requestTokenHTTP(OIDCTokenRequestHelper.java:112)
	org.xwiki.contrib.oidc.auth.internal.endpoint.CallbackOIDCEndpoint.requestTokenFromAuthenticationResponse(CallbackOIDCEndpoint.java:354)
	org.xwiki.contrib.oidc.auth.internal.endpoint.CallbackOIDCEndpoint.handle(CallbackOIDCEndpoint.java:210)
	org.xwiki.contrib.oidc.provider.internal.OIDCResourceReferenceHandler.handle(OIDCResourceReferenceHandler.java:138)
	org.xwiki.contrib.oidc.provider.internal.OIDCResourceReferenceHandler.handle(OIDCResourceReferenceHandler.java:110)
	org.xwiki.resource.internal.DefaultResourceReferenceHandlerChain.handleNext(DefaultResourceReferenceHandlerChain.java:79)
	org.xwiki.resource.internal.AbstractResourceReferenceHandlerManager.handle(AbstractResourceReferenceHandlerManager.java:82)
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.handleResourceReference(ResourceReferenceHandlerServlet.java:160)
	org.xwiki.resource.servlet.ResourceReferenceHandlerServlet.service(ResourceReferenceHandlerServlet.java:90)
	jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
	org.xwiki.container.servlet.filters.internal.SetHTTPHeaderFilter.doFilter(SetHTTPHeaderFilter.java:66)
	org.xwiki.resource.servlet.RoutingFilter.doFilter(RoutingFilter.java:148)
	org.xwiki.container.servlet.filters.internal.SavedRequestRestorerFilter.doFilter(SavedRequestRestorerFilter.java:211)
	org.xwiki.container.servlet.filters.internal.SafeRedirectFilter.doFilter(SafeRedirectFilter.java:106)
	org.xwiki.container.servlet.filters.internal.ResolveRelativeRedirectFilter.doFilter(ResolveRelativeRedirectFilter.java:129)
	org.xwiki.container.servlet.filters.internal.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:120)

Keycloak returns the following log entry (internal details removed):

WARN  [org.keycloak.events] (executor-thread-#####) type="CODE_TO_TOKEN_ERROR", realmId="***", clientId="***", userId="***", sessionId="***", ipAddress="***", error="invalid_code", grant_type="authorization_code", code_id="***", client_auth_method="client-secret"

Enabling debug logging for the oidc packages gave us the actual error response:

DEBUG c.o.a.i.OIDCTokenRequestHelper - OIDC Token response ({"error":"invalid_grant","error_description":"Incorrect redirect_uri"}

This led us to inspecting the redirect URI passed in the request to the IdP (Keycloak). Using xwiki.example.com as a replacement for the actual address:

  • Main wiki (login successful): https://xwiki.example.com:443/oidc/authenticator/callback
  • Subwikis (login fails with error): https://xwiki.example.com/oidc/authenticator/callback

The Keycloak settings include both of these versions as valid redirect URIs. To be sure we temporarily set the valid redirect URIs to *, but the issue persisted.

We have an NginX proxy set up in front of XWiki. Our Tomcat config is modified in two places:

  • Added secure=true to the Connector on port 8080
  • Added <Valve className="org.apache.catalina.valves.RemoteIpValve" remoteIpHeader="x-forwarded-for" protocolHeader="x-forwarded-proto" /> inside the localhost host of the Catalina engine.

Our main wiki is configured with Secure: Yes and Port: 443. The subwikis are configured with Secure: (blank) and Port: -1. We have tried setting the subwiki settings to the same values as the main wiki settings, but the issue persists.

We have used the following groovy script to check the headers of the request and the base URL:

Groovy script
{{groovy wiki="false"}}
  println 'HTTP header "forwarded": ' + xcontext.request.getHeader('forwarded')
  println 'HTTP header "x-forwarded-host": ' + xcontext.request.getHeader('x-forwarded-host')
  println 'HTTP header "x-forwarded-for": ' + xcontext.request.getHeader('x-forwarded-for')
  println 'HTTP header "x-forwarded-proto": ' + xcontext.request.getHeader('x-forwarded-proto')
  println 'HTTP header "x-forwarded-port": ' + xcontext.request.getHeader('x-forwarded-port')
  println 'Application server port: ' + xcontext.request.getServerPort()

  println org.xwiki.container.servlet.HttpServletUtils.getSourceBaseURL(xcontext.request)
{{/groovy}}

Results are the same in main and subwikis:

Groovy results
HTTP header "forwarded": null
HTTP header "x-forwarded-host": xwiki.example.com
HTTP header "x-forwarded-for": null
HTTP header "x-forwarded-proto": https
HTTP header "x-forwarded-port": 443
Application server port: 443
https://xwiki.example.com

The following Velocity script returns different results between main and subwikis:

Velocity script
{{velocity}}
$xcontext.context.getURLFactory().getServerURL($xcontext.context)
{{/velocity}}
  • Main wiki: https://xwiki.example.com:443/
  • Subwikis: https://xwiki.example.com

Lastly, the debug log also contains the following line (the IP of the XWiki container in the internal Docker network is replaced with 1.2.3.4). I don’t know if the use of an IP here is related to the issue, but the logging code is using httpRequest.getURL() which makes me think it might:

DEBUG c.o.a.i.e.CallbackOIDCEndpoint - OIDC callback: starting with request [https://1.2.3.4:8080/oidc/authenticator/callback?state=...

I heavily assume the issue is related to the new application server request URL resolution. Are the inconsitencies in whether the port is attached a bug of the new resolution? Or does the OIDC extension miss some modifications required for the new resolution? Or do we have to change our Tomcat/NginX configuration to work with the new resolution?

Sorry for the very long post, but I wanted to include as much detail as possible.

Edit: Forgot to mention that our main wiki allows reading for unregistered users while our subwikis do not. So opening a link to a document in the main wiki will show the document and allow login by clicking the login button in the top bar (with the login succeeding). Opening a link to a document in a subwiki will immediately redirect to the IdP (with the error occuring on the redirect after authentication).

One thing I find a bit surprising is that Keycloak seems to be complaining about the token request having a wrong redirect_uri. But from what I can see, the OIDC authenticator does not send any redirect URI in the token request (and never did), only in the authorization request (the initial redirect) does.

Here is what happen from what I understand:

  • the user click login
  • the authenticator redirects the user to the provider (with the redirect_uri https://xwiki.example.com/oidc/authenticator/callback from what you are saying) and the user authenticate there
  • the provider sends the user back to the indicated redirect_uri (with an authorization code)
  • the authenticator sends a token request to the provider (with the authorization code) to get an access token → the provider respond with an error about an invalid request_uri

It’s true that in the OIDC protocol specification, there is the possibility to pass a redirect_uri in the token request (in which case the provider must make sure it’s identical to the one that was passed with the authorization request). But, as far as I know, the OIDC authenticator never did.

If the problem really was related to the format of redirect_uri (which seems fine to me, the one you indicate is sent for the subwiki actually looks cleaner than the main wiki one with the useless, but not invalid, :443) sent with the authorization request (for which you said you configured Keycloak to accept anything anyway) I would expect the error to be reported earlier and the provider to not return an authorization code.

The redirect_uri is actually set in the AuthorizationGrant sent with the token request, so it IS sent in the token request.

This is right as far as i can tell. Since https://xwiki.example.com/oidc/authenticator/callback is in the main wiki space, the redirect URI sent with the token request (last bullet point) will contain the :443 part. This is different from the URI without the port sent in the authentication request (second bullet point), thus causing the error.

Both the initial authentication request and the token request use URI callback = this.oidc.createEndPointURI(CallbackOIDCEndpoint.HINT); to create the callback URI. Any idea if the port being appended to the URI for the main wiki can be fixed by configuration on our side (so the port is not appended for the main wiki)? Or will it need a fix on your side?

Ha indeed, sorry, I forgot about this part.

Probably, since I don’t reproduce the extra 443 port on a subwiki of myxwiki.org (17.4.0) for example, but it’s not yet clear to me why you have this behavior.

You can use the following (it’s the standard API the OIDC authenticator is using) to compare the behavior for the main wiki with the behavior for the subwiki (try it from a page of the main wiki and from a page of the subwiki, you will need to do that with a user having programming right):

{{velocity}}
$xcontext.context.getURLFactory().getServerURL($xcontext.context)
{{/velocity}}

I would remove that explicit 443 port, since you want the default port here. But, in theory, in the case of an HTTP thread, I would expect it to reuse the URL from the browser and not the wiki descriptor configuration (which is mainly here when the target wiki does not match the input URL or in background services).

See the main post (in an expandable block):

I had to set that explicitly when we initially set up XWiki due to the reverse proxy. IIRC it would apply :80 otherwise. I’ll check if I can remove it now after I have made a backup.

AFAIK, if you don’t set anything, it’s supposed to consider it as the default for whatever protocol was chosen (in your case https).

I removed the explicit 443 port, but the results of the velocity script is the same. I also tested setting the port to 443 explicitly in a subwiki. Results are:

  • Main wiki (Port not set): https://xwiki.example.com:443/
  • Main wiki (Port set to 443): https://xwiki.example.com:443/
  • Subwikis (Port not set): https://xwiki.example.com
  • Subwikis (Port set to 443): https://xwiki.example.com

So it does not seem like this setting is the issue. I did not restart the XWiki instance after changing the value, would that be necessary for it to take effect?

EDIT: Just went through the documentation I wrote when setting up the instance and it contains an instruction to set the xwiki.home variable in xwiki.cfg to the full URL including schema, domain AND port (again because it was needed for the reverse proxy). So the variable is currently set to https://xwiki.example.com:443/. Maybe the port is not required here anymore?

Yes, that’s actually reassuring.

I don’t see anything that would require a restart (the wiki descriptor is cached, but any modification to the page is supposed to invalidate the cache).

Did you configure anything in xwiki.cfg or xwiki.properties related to URLs ? Stuff like xwiki.home in xwiki.cfg for example.

Yes, xwiki.home is most probably what is causing it. I would actually entirely get rid of it, it’s not supposed to be needed most of the time, and it’s here only for very last resort in theory.

Removing xwiki.home fixed the issue. The above velocity script now returns the URL without the port consistently. Thanks for digging through this with me.

I don’t know why xwiki.home was only applied for the main wiki. I guess it is an (intended?) effect of the new URL resolution.

Do you have xwiki.virtual.usepath=0 in xwiki.cfg (i.e. is each subwiki supposed to have its own domain name) ?

The “new resolution” does not really impact in any way how the resolution works in XWiki APIs, and definitely not the part related to xwiki.home.

That variable is commented out, so at the default of 1. All subwikis are available under the same domain name.

OK, that’s strange, then, since it should be used for both main and subwikis. Would need to debug it exactly, but there were various fixed/improvements in this area between 16.6.0 and 17.4.0. Don’t hesitate to create a BUG issue for this apparent ignore of the xwiki.home on subwikis (even if it’s not recommended to use it, it still looks like a regression).

Actually it looks like this is intended. No idea why it worked before, but maybe that was the bug which was fixed by the improvements you mentioned.