3

Version

  1. Spring Boot Version: 2.6.5
  2. Spring Cloud Version: 2021.0.0

The application built has the following characteristics:

  1. It is a reactive application (Reactor + WebFlux)
  2. It is an Oauth2 Client Application that uses Grant Type = Authorization Code.
  3. It uses Spring Cloud Gateway to proxy Oauth2 Resources.
  4. It uses Spring Session (Redis) to be able to accomplish transparent horizontal scaling.

Problem:

Requesting a resource that goes through the Spring Cloud Gateway to a downstream service returns a correct 200, but after the application is restarted while there is an active session saved in Redis it will return a 302. I find this to be a huge problem because it basically prevents horizontal scaling, which is my whole reason to implement Spring Session in Redis.

Steps to reproduce:

  1. Start Application.
  2. User requests loading application in the browser: https://localhost:9093/hello.html
  3. Session is successfully created in Redis.
  4. User redirected to the Oauth2 Server for Authentication
  5. User Authenticates
  6. User redirected to application after successful login.
  7. Application loads in browser without a problem.
  8. User requests a gateway resource: https://localhost:9093/entries
  9. Resources loads fine with a 200.
  10. Everything great so far.
  11. Restart the server.
  12. (Session still active, saved on Redis)
  13. User requests the gateway resource (https://localhost:9093/entries).
  14. Resources returns 302 and redirected to the Ouath Server (BAD)

Logs

The difference in logs when the resource loads vs does not load is the following:

Correct Loading 
2022-03-30 18:25:06.655 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [PathPatternParserServerWebExchangeMatcher PathPatternParserServerWebExchangeMatcher.java:95->matches] : Checking match of request : '/wasd/selfservice/api/ccbConfiguration'; against '/wasd/**' 
2022-03-30 18:25:06.655 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:60->lambda$matches$2] : matched 
2022-03-30 18:25:06.655 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [DelegatingReactiveAuthorizationManager DelegatingReactiveAuthorizationManager.java:55->lambda$check$1] : Checking authorization on '/wasd/selfservice/api/ccbConfiguration' using org.springframework.security.config.web.server.ServerHttpSecurity$AuthorizeExchangeSpec$Access$$Lambda$1069/0x0000000800995840@7ffc1fdb 
2022-03-30 18:25:06.656 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [AuthorizationWebFilter AuthorizationWebFilter.java:52->lambda$filter$2] : Authorization successful 
2022-03-30 18:25:06.656 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [RoutePredicateHandlerMapping RoutePredicateHandlerMapping.java:142->lambda$lookupRoute$6] : Route matched: ssa-resources 
2022-03-30 18:25:06.656 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [RoutePredicateHandlerMapping RoutePredicateHandlerMapping.java:90->lambda$getHandlerInternal$0] : Mapping [Exchange: GET https://localhost:9093/wasdservice/wasd/selfservice/api/ccbConfiguration] to Route{id='ssa-resources', uri=https://wasd-api-int.company.com:443, order=0, predicate=Paths: [/wasdservice/wasd/**], match trailing slash: true, gatewayFilters=[[gov.miamidade.wasd.client.gateway.StripBasePathGatewayFilterFactory$$Lambda$1563/0x0000000800b4f040@4d05f800, order = 1], [org.springframework.cloud.gateway.filter.factory.TokenRelayGatewayFilterFactory$$Lambda$1564/0x0000000800b4f440@46c35be4, order = 2]], metadata={}} 
2022-03-30 18:25:06.657 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [RoutePredicateHandlerMapping AbstractHandlerMapping.java:189->lambda$getHandler$1] : [cb1dc8d7-90] Mapped to org.springframework.cloud.gateway.handler.FilteringWebHandler@546da583 
2022-03-30 18:25:06.657 [lettuce-kqueueEventLoop-5-1] DEBUG 90299 --- [FilteringWebHandler FilteringWebHandler.java:85->handle] : Sorted gatewayFilterFactories: [[GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.RemoveCachedBodyFilter@86e7c7a}, order = -2147483648], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.AdaptCachedBodyGlobalFilter@29617475}, order = -2147482648], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyWriteResponseFilter@271df4c0}, order = -1], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardPathFilter@22edca96}, order = 0], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.GatewayMetricsFilter@6e1bd2b}, order = 0], [gov.miamidade.wasd.client.gateway.StripBasePathGatewayFilterFactory$$Lambda$1563/0x0000000800b4f040@4d05f800, order = 1], [org.springframework.cloud.gateway.filter.factory.TokenRelayGatewayFilterFactory$$Lambda$1564/0x0000000800b4f440@46c35be4, order = 2], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.RouteToRequestUrlFilter@6e863469}, order = 10000], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.config.GatewayNoLoadBalancerClientAutoConfiguration$NoLoadBalancerClientFilter@18a66406}, order = 10150], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.WebsocketRoutingFilter@591bff1d}, order = 2147483646], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyRoutingFilter@38379575}, order = 2147483647], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardRoutingFilter@6a9e88f1}, order = 2147483647]] 
.]]]' in WebSession: 'org.springframework.session.web.server.session.SpringSessionWebSessionStore$SpringSessionWebSession@118f2254' 
2022-03-30 18:25:06.658 [reactor-http-kqueue-2] DEBUG 90299 --- [PooledConnectionProvider Loggers.java:250->debug] : [1bea583a, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] Channel acquired, now: 1 active connections, 0 inactive connections and 0 pending acquire requests. 
2022-03-30 18:25:06.659 [reactor-http-kqueue-2] DEBUG 90299 --- [HttpClientConnect Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] Handler is being applied: {uri=https://wasd-api-int.company.com/wasd/selfservice/api/ccbConfiguration, method=GET} 
2022-03-30 18:25:06.659 [reactor-http-kqueue-2] DEBUG 90299 --- [DefaultPooledConnectionProvider Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] onStateChange(GET{uri=/wasd/selfservice/api/ccbConfiguration, connection=PooledConnection{channel=[id: 0x1bea583a, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443]}}, [request_prepared]) 
2022-03-30 18:25:06.659 [reactor-http-kqueue-4] DEBUG 90299 --- [FluxReceive Loggers.java:250->debug] : [cb1dc8d7-16, L:/0:0:0:0:0:0:0:1%0:9093 - R:/0:0:0:0:0:0:0:1%0:56346] FluxReceive{pending=0, cancelled=false, inboundDone=true, inboundError=null}: subscribing inbound receiver 
2022-03-30 18:25:06.660 [reactor-http-kqueue-2] DEBUG 90299 --- [DefaultPooledConnectionProvider Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] onStateChange(GET{uri=/wasd/selfservice/api/ccbConfiguration, connection=PooledConnection{channel=[id: 0x1bea583a, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443]}}, [request_sent]) 
2022-03-30 18:25:06.779 [reactor-http-kqueue-2] DEBUG 90299 --- [HttpClientOperations Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] Received response (auto-read:false) : [Cache-Control=no-cache, no-store, max-age=0, must-revalidate, Pragma=no-cache, Transfer-Encoding=chunked, Content-Type=application/json, Expires=0, Vary=Access-Control-Request-Headers, Request-Context=appId=e6c5278f-0ac3-4701-9647-f98e97152b1f, X-Content-Type-Options=nosniff, X-XSS-Protection=1; mode=block, Strict-Transport-Security=max-age=31536000 ; includeSubDomains, X-Frame-Options=DENY, Set-Cookie=ARRAffinity=64fcec8b11e29841b77fe53d1af49439c9f64a9de8bd5c352f6db54bf06a60d1;Path=/;HttpOnly;Secure;Domain=wasd-api-int.company.com, Set-Cookie=ARRAffinitySameSite=64fcec8b11e29841b77fe53d1af49439c9f64a9de8bd5c352f6db54bf06a60d1;Path=/;HttpOnly;SameSite=None;Secure;Domain=wasd-api-int.company.com, Date=Wed, 30 Mar 2022 22:25:05 GMT] 
2022-03-30 18:25:06.779 [reactor-http-kqueue-2] DEBUG 90299 --- [DefaultPooledConnectionProvider Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] onStateChange(GET{uri=/wasd/selfservice/api/ccbConfiguration, connection=PooledConnection{channel=[id: 0x1bea583a, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443]}}, [response_received]) 
2022-03-30 18:25:06.780 [reactor-http-kqueue-2] DEBUG 90299 --- [FluxReceive Loggers.java:250->debug] : [1bea583a-5, L:/192.168.1.11:56359 - R:wasd-api-int.company.com/10.82.52.4:443] FluxReceive{pending=0, cancelled=false, inboundDone=false, inboundError=null}: subscribing inbound receiver  
Incorrect Loading
2022-03-30 18:31:56.074 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [PathPatternParserServerWebExchangeMatcher PathPatternParserServerWebExchangeMatcher.java:95->matches] : Checking match of request : '/wasd/selfservice/api/ccbConfiguration'; against '/wasd/**' 
2022-03-30 18:31:56.075 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:60->lambda$matches$2] : matched 
2022-03-30 18:31:56.075 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [DelegatingReactiveAuthorizationManager DelegatingReactiveAuthorizationManager.java:55->lambda$check$1] : Checking authorization on '/wasd/selfservice/api/ccbConfiguration' using org.springframework.security.config.web.server.ServerHttpSecurity$AuthorizeExchangeSpec$Access$$Lambda$1070/0x000000080099e840@1107fca4 
2022-03-30 18:31:56.075 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [AuthorizationWebFilter AuthorizationWebFilter.java:52->lambda$filter$2] : Authorization successful 
2022-03-30 18:31:56.105 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [RoutePredicateHandlerMapping RoutePredicateHandlerMapping.java:142->lambda$lookupRoute$6] : Route matched: ssa-resources 
2022-03-30 18:31:56.105 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [RoutePredicateHandlerMapping RoutePredicateHandlerMapping.java:90->lambda$getHandlerInternal$0] : Mapping [Exchange: GET https://localhost:9093/wasdservice/wasd/selfservice/api/ccbConfiguration] to Route{id='ssa-resources', uri=https://wasd-api-int.company.com:443, order=0, predicate=Paths: [/wasdservice/wasd/**], match trailing slash: true, gatewayFilters=[[com.mycompany.wasd.client.gateway.StripBasePathGatewayFilterFactory$$Lambda$1543/0x0000000800b38440@2f286cb, order = 1], [org.springframework.cloud.gateway.filter.factory.TokenRelayGatewayFilterFactory$$Lambda$1544/0x0000000800b38840@19401a72, order = 2]], metadata={}} 
2022-03-30 18:31:56.106 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [RoutePredicateHandlerMapping AbstractHandlerMapping.java:189->lambda$getHandler$1] : [cc95c8f2-1] Mapped to org.springframework.cloud.gateway.handler.FilteringWebHandler@addc61b 
2022-03-30 18:31:56.107 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [FilteringWebHandler FilteringWebHandler.java:85->handle] : Sorted gatewayFilterFactories: [[GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.RemoveCachedBodyFilter@142f0ac1}, order = -2147483648], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.AdaptCachedBodyGlobalFilter@11544ddd}, order = -2147482648], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyWriteResponseFilter@3f7d20c5}, order = -1], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardPathFilter@f4a21cb}, order = 0], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.GatewayMetricsFilter@456d3914}, order = 0], [com.mycompany.wasd.client.gateway.StripBasePathGatewayFilterFactory$$Lambda$1543/0x0000000800b38440@2f286cb, order = 1], [org.springframework.cloud.gateway.filter.factory.TokenRelayGatewayFilterFactory$$Lambda$1544/0x0000000800b38840@19401a72, order = 2], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.RouteToRequestUrlFilter@1847da64}, order = 10000], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.config.GatewayNoLoadBalancerClientAutoConfiguration$NoLoadBalancerClientFilter@26a0068a}, order = 10150], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.WebsocketRoutingFilter@635f4be1}, order = 2147483646], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.NettyRoutingFilter@27acd9a7}, order = 2147483647], [GatewayFilterAdapter{delegate=org.springframework.cloud.gateway.filter.ForwardRoutingFilter@5967492a}, order = 2147483647]] 
.]]]' in WebSession: 'org.springframework.session.web.server.session.SpringSessionWebSessionStore$SpringSessionWebSession@3d103de5' 
2022-03-30 18:31:56.144 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [AndServerWebExchangeMatcher AndServerWebExchangeMatcher.java:61->lambda$matches$0] : Trying to match using OrServerWebExchangeMatcher{matchers=[PathMatcherServerWebExchangeMatcher{pattern='/**', method=GET}]} 
2022-03-30 18:31:56.144 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:57->lambda$matches$0] : Trying to match using PathMatcherServerWebExchangeMatcher{pattern='/**', method=GET} 
2022-03-30 18:31:56.145 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [PathPatternParserServerWebExchangeMatcher PathPatternParserServerWebExchangeMatcher.java:95->matches] : Checking match of request : '/wasd/selfservice/api/ccbConfiguration'; against '/**' 
2022-03-30 18:31:56.145 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:60->lambda$matches$2] : matched 
2022-03-30 18:31:56.146 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [AndServerWebExchangeMatcher AndServerWebExchangeMatcher.java:61->lambda$matches$0] : Trying to match using NegatedServerWebExchangeMatcher{matcher=OrServerWebExchangeMatcher{matchers=[PathMatcherServerWebExchangeMatcher{pattern='/favicon.*', method=null}]}} 
2022-03-30 18:31:56.147 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:57->lambda$matches$0] : Trying to match using PathMatcherServerWebExchangeMatcher{pattern='/favicon.*', method=null} 
2022-03-30 18:31:56.148 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [PathPatternParserServerWebExchangeMatcher PathPatternParserServerWebExchangeMatcher.java:87->lambda$matches$1] : Request 'GET /wasd/selfservice/api/ccbConfiguration' doesn't match 'null /favicon.*' 
2022-03-30 18:31:56.148 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [OrServerWebExchangeMatcher OrServerWebExchangeMatcher.java:60->lambda$matches$2] : No matches found 
2022-03-30 18:31:56.149 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [NegatedServerWebExchangeMatcher NegatedServerWebExchangeMatcher.java:49->lambda$matches$0] : matches = true 
2022-03-30 18:31:56.149 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [AndServerWebExchangeMatcher AndServerWebExchangeMatcher.java:61->lambda$matches$0] : Trying to match using MediaTypeRequestMatcher [matchingMediaTypes=[text/html], useEquals=false, ignoredMediaTypes=[*/*]] 
2022-03-30 18:31:56.150 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [MediaTypeServerWebExchangeMatcher MediaTypeServerWebExchangeMatcher.java:84->matches] : httpRequestMediaTypes=[text/html, application/xhtml+xml, image/avif, image/webp, image/apng, application/xml;q=0.9, application/signed-exchange;v=b3;q=0.9, */*;q=0.8] 
2022-03-30 18:31:56.150 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [MediaTypeServerWebExchangeMatcher MediaTypeServerWebExchangeMatcher.java:86->matches] : Processing text/html 
2022-03-30 18:31:56.151 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [MediaTypeServerWebExchangeMatcher MediaTypeServerWebExchangeMatcher.java:98->matches] : text/html .isCompatibleWith text/html = true 
2022-03-30 18:31:56.152 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [AndServerWebExchangeMatcher AndServerWebExchangeMatcher.java:66->lambda$matches$4] : All requestMatchers returned true 
2022-03-30 18:31:56.152 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [WebSessionServerRequestCache WebSessionServerRequestCache.java:76->lambda$saveRequest$1] : Request added to WebSession: '/wasd/selfservice/api/ccbConfiguration' 
2022-03-30 18:31:56.163 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [DefaultServerRedirectStrategy DefaultServerRedirectStrategy.java:54->lambda$sendRedirect$0] : Redirecting to 'https://s0144821.company.com:9999/uaa/oauth/authorize?response_type=code&client_id=wasdssa&state=CPaWn5UE9oBzjPm-efV2mlONTXbNrLz5i_DZAy9KrS4%3D&redirect_uri=https://localhost:9093/wasdservice/login/oauth2/code/mdc' 
2022-03-30 18:31:56.166 [lettuce-kqueueEventLoop-5-1] DEBUG 90357 --- [HttpWebHandlerAdapter LogFormatUtils.java:119->traceDebug] : [cc95c8f2-1] Completed 302 FOUND 

Sample Application

I created a minimalistic project where you can see all the details of the configuration and execute it so that you can verify for yourself that indeed this is happening. (you are going to need a Redis instance and an Oauth server)

https://github.com/fiallega/spring-session-oauth-gateway

Configuration

The WebSecurity Configuration is as follows:

    @Bean
    public SecurityWebFilterChain springSecurityFilterChain(ServerHttpSecurity http) {

        http.csrf().disable();

        http.headers()
                .referrerPolicy(ReferrerPolicyServerHttpHeadersWriter.ReferrerPolicy.NO_REFERRER_WHEN_DOWNGRADE);

        http.authorizeExchange()
                .pathMatchers("/login**","/entries/**").permitAll()
                .anyExchange()
                .authenticated()
                .and()
                .oauth2Login();

        return http.build();
    }

and the gateway configuration is

  cloud:
    gateway:
      routes:
      - id: ssa-resources
        uri: https://api.publicapis.org
        predicates:
        - Path=/entries
        filters:
        - TokenRelay=

What I see is that after reloading the application for some reason instead of making calls to the downstream servers, checks on mediatype happens and ends up with a 302 redirect when it should get a 200.

So why is it that a reload of an application that is using spring session is not able to "pickup" where it left, and this weird redirect happening after reloading the application if an active session exists in Redis?

Thanks

1 Answers1

2

The solution was found adding the authorizedClientRepository bean to the WebSecurityConfig


    @Bean
    public ServerOAuth2AuthorizedClientRepository authorizedClientRepository() {
        return new WebSessionServerOAuth2AuthorizedClientRepository();
    }


    @Bean
    public SecurityWebFilterChain springSecurityFilterChain(ServerHttpSecurity http) {

        http.csrf().disable();

        http.headers()
                .referrerPolicy(ReferrerPolicyServerHttpHeadersWriter.ReferrerPolicy.NO_REFERRER_WHEN_DOWNGRADE);

        http.authorizeExchange()
                .pathMatchers("/login**","/entries/**").permitAll()
                .anyExchange()
                .authenticated()
                .and()
                .oauth2Login(l -> l                      
                 .authorizedClientRepository(authorizedClientRepository()));

        return http.build();
    }

I want to give credit to the author of this article where I found the solution and the github repository he provided.

He provides the following comment to the solution: /Most of the spring security classes that store data are already implemented using WebSession. The only one that is not is {@link ServerOAuth2AuthorizedClientRepository} so we define that bean ourselves. @return ServerOAuth2AuthorizedClientRepository/