authservice fails to exchange authorization code for access token with keycloak

[snkshukla]

We are trying to setup an oidc provider for authZ and authN with istio in our k8s cluster. We followed this example here: Bookinfo with Authservice Example for the integration.
Below are the details on the setup:

OIDC provider: Keycloak
Grant type: authorization_code
Istio version: 1.5

Authentication flow:

1. On first request, since there is no authentication, authservice successfully redirects to Keycloak, where we're able to login successfully.
2. Keycloak then redirects the request to the application on the redirect_uri. The authorization code is present in this uri now.
3. The redirect_uri is intercepted by the authservice again and it detects the url to be the filter url for oidc as defined in the configmap
4. Now it tries to call keycloak for exchanging the authorization code for the access token.

This is the step where authservice fails and gives the error IdP connection error. The log for the request is as follows:

Check: processing request ://microservice.url.com/appservice/oauth/callback?state=LeCNEqfwA6EUFGNGLt7JALx8jCWkPxjn7qCELbqkKrk&session_state=18f0e3b0-bee2-44a5-b049-6e349dbeda49&code=ddea1ea6-5616-416d-8291-c00bce6f2e9b.18f0e3b0-bee2-44a5-b049-6e349dbeda49.af7e7c31-fd4b-4a66-9856-25d1ac305d3f with filter chain idp_filter_chain
20/03/2020 17:27:48 [2020-03-20 11:57:48.546] [console] [trace] New
20/03/2020 17:27:48 [2020-03-20 11:57:48.547] [console] [trace] OidcFilter
20/03/2020 17:27:48 [2020-03-20 11:57:48.548] [console] [trace] Process
20/03/2020 17:27:48 [2020-03-20 11:57:48.548] [console] [debug] Call from @10.42.5.53 to @10.42.5.58
20/03/2020 17:27:48 [2020-03-20 11:57:48.549] [console] [trace] MatchesCallbackRequest: checking handler for ://microservice.url.com/appservice/oauth/callback?state=LeCNEqfwA6EUFGNGLt7JALx8jCWkPxjn7qCELbqkKrk&session_state=18f0e3b0-bee2-44a5-b049-6e349dbeda49&code=ddea1ea6-5616-416d-8291-c00bce6f2e9b.18f0e3b0-bee2-44a5-b049-6e349dbeda49.af7e7c31-fd4b-4a66-9856-25d1ac305d3f
20/03/2020 17:27:48 [2020-03-20 11:57:48.549] [console] [trace] RetrieveToken
20/03/2020 17:27:48 [2020-03-20 11:57:48.550] [console] [trace] Post
20/03/2020 17:27:48 [2020-03-20 11:57:48.618] [console] [info] Post: HTTP error encountered: stream truncated
20/03/2020 17:27:48 [2020-03-20 11:57:48.618] [console] [info] RetrieveToken: HTTP error encountered: IdP connection error
20/03/2020 17:27:48 [2020-03-20 11:57:48.618] [console] [trace] Request processing complete
20/03/2020 17:27:48 [2020-03-20 11:57:48.619] [console] [trace] Processing completion and deleting state

On further checking the code, I found this error is triggered from here: Authservice oidc filter - Github

To rule out the issues with the configuration, I used OpenID Debugger to manually generate an authorization code and then called the api to exchange it for an api token. I was able to successfully retrieve it, there was no issue with that. But somehow it is failing with authservice.

Could there be something wrong on my end? Has anyone experienced this issue before? Any help appreciated. Let me know if any more details are needed.

[cfryanr]

Hi @snkshukla,

Thanks so much for your very detailed issue and your investigation.

Your log indicates that the request was successful right up until the end, when the Authservice tried to gracefully shutdown the TLS connection, and the server on the other side did not participate fully in the graceful shutdown. It sounds like the same problem as described in this issue: boostorg/beast#824

We ran into a similar situation when we were implementing the trusted_certificate_authority configuration option. As a result, when that option is set the Authservice will always ignore boost::asio::ssl::error::stream_truncated errors during stream shutdown.

A possible fix for your issue might be for Authservice to always ignore the specific error boost::asio::ssl::error::stream_truncated during stream shutdown (both when trusted_certificate_authority is set and when it is not set). We pushed this implementation of this potential fix to a branch called issue79_always_ignore_stream_truncated.

Would you mind helping us to confirm that such a fix would solve your issue? To build the Authservice on that branch, on either a Mac or linux machine:

1. git clone [email protected]:istio-ecosystem/authservice.git
2. git checkout issue79_always_ignore_stream_truncated
3. make docker-from-scratch
4. docker tag <image_id_which_was_just_built> <your_image_repository>/<image_name>:<tag_name>
5. docker push <your_image_repository>/<image_name>:<tag_name>
6. Redeploy the authservice container on your k8s cluster and try again.

Best,
Ryan and Andrew (@Changdrew)

[snkshukla]

Hi @cfryanr, thank you so much for your quick reply. As you suggested, I deployed the image created from branch issue79_always_ignore_stream_truncated and it has fixed the issue for me. I was able to successfully authenticate my application.