search

spring-attic / spring-security-oauth

Support for adding OAuth1(a) and OAuth2 features (consumer and provider) for Spring web applications.
http://github.com/spring-projects/spring-security-oauth
Apache License 2.0
4.7k stars 4.04k forks source link

/oauth/token is very slow or has performance issue #943

Open soyoeml opened 7 years ago

soyoeml commented 7 years ago

Hi All,

The /oauth/token interface is very slow or has performance issue. It takes more than 200+ms. If we use a 24 core server to handle concurrent requests, The concurrent numbers only can reach 120-144 on this machine. If we use a cluster which has 9 servers as same specs, it only has 1000 concurrency. Do you think it's acceptable?

I made a time analysis of /oauth/token interface time consuming. Please see there in google docs: https://drive.google.com/file/d/0B8LRQZLUvB5KaFA4eFh6UFNINW8/view?usp=sharing

From the analysis, we could see it's low performance. I hope somebody to tune up.

Thanks.

codemaker219 commented 7 years ago

If you use a password schema and you hash your passwords (it is a good idea), this can cause this latencies. Bcrypt for example is known to be slow (if it is configured nicely). This is also a big advantage of bcrypt since this „high“ latencies protects against dictionary attack. If the hashing in your case is the problem, you can change the hash-function. Sha256 is very fast. You can also configure Bcyrpt to be not so secure. This is ok from a security point of view if and only if the passwords are strong or generated.

jzampieron commented 6 years ago

I am also seeing performance issues with this end point. I understand BCrypt has a fixed-cost. We are also seeing a load based slow down. I'll post more here as I dig into the issue.

I've also noticed it makes approximately 11 database operations (round trips) per call to the end point.

More coming in the next few days as I pull this apart.

hanrw commented 6 years ago

+1 8 core server to handle concurrent requests, The concurrent numbers only can reach around 80

screen shot 2018-05-26 at 4 06 50 pm 
DOCKER 17.12.1-ce
SYSTEM Ubuntu 16.04.2 LTS (with KVM) (4.4.0)
CPU 8x4 GHz
RAM 62.8 GiB
HDD 2.85 TiB
jzampieron commented 6 years ago

I've done pretty extensive performance tuning of our SB 2.0 oauth server.

The rates/sec depend on the request type. e.g. a password grant against a bcrypted password is slow by design.

Beyond that look at places you can cache in ram.

hanrw commented 6 years ago

@jzampieron I had add cache there but seems not help with performance

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  xmlns:aop="http://www.springframework.org/schema/aop"
  xmlns:cache="http://www.springframework.org/schema/cache"
  xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
            http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop.xsd
            http://www.springframework.org/schema/cache http://www.springframework.org/schema/cache/spring-cache.xsd">

  <!-- define caching behavior -->
  <cache:advice id="clientById" cache-manager="ehCacheCacheManager">
    <cache:caching cache="OAuthClientDetailsServiceCache">
      <cache:cacheable method="loadClientByClientId" key="#clientId"/>
    </cache:caching>
  </cache:advice>

  <cache:advice id="evictClientById" cache-manager="ehCacheCacheManager">
    <cache:caching cache="OAuthClientDetailsServiceCache">
      <cache:cache-evict method="removeClientDetails" key="#clientId" before-invocation="false"/>
    </cache:caching>
  </cache:advice>

  <cache:advice id="authByTokenId" cache-manager="ehCacheCacheManager">
    <cache:caching cache="OAuthTokenStoreReadAuthenticationCache">
      <cache:cacheable method="readAuthentication" key="#token.toString()"/>
    </cache:caching>
  </cache:advice>

  <cache:advice id="tokenById" cache-manager="ehCacheCacheManager">
    <cache:caching cache="OAuthTokenByIdCache">
      <cache:cacheable method="readAccessToken" key="#tokenValue" unless="#result == null"/>
    </cache:caching>
  </cache:advice>

  <!-- apply the cacheable behavior to all interface methods -->
  <aop:config>
    <aop:advisor advice-ref="clientById"
      pointcut="execution(* org.springframework.security.oauth2.provider.ClientDetailsService.*(..))"/>
    <aop:advisor advice-ref="evictClientById"
      pointcut="execution(* org.springframework.security.oauth2.provider.ClientRegistrationService.*(..))"/>
    <aop:advisor advice-ref="authByTokenId"
      pointcut="execution(* org.springframework.security.oauth2.provider.token.TokenStore.*(..)) "/>
    <aop:advisor advice-ref="tokenById"
      pointcut="execution(* org.springframework.security.oauth2.provider.token.TokenStore.*(..))"/>
  </aop:config>
</beans>

@ImportResource({"classpath:oauth2-cache.xml"})
@Configuration
@EnableCaching
public class CacheConfiguration {

  @Bean
  public CacheManager ehCacheCacheManager() {
    EhCacheManagerFactoryBean bean = new EhCacheManagerFactoryBean();
    bean.setConfigLocation(new ClassPathResource("ehcache.xml"));
    EhCacheCacheManager ehCacheCacheManager = new EhCacheCacheManager();
    ehCacheCacheManager.setCacheManager(bean.getObject());
    return ehCacheCacheManager;
  }
}
hanrw commented 6 years ago

/oauth/token logs

2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/oauth/token']
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/oauth/token'; against '/oauth/token'
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : matched
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 1 of 11 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 2 of 11 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 3 of 11 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2018-05-27 05:07:36.317 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 4 of 11 in additional filter chain; firing Filter: 'LogoutFilter'
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', GET]
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /oauth/token' doesn't match 'GET /logout
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', POST]
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/oauth/token'; against '/logout'
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', PUT]
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /oauth/token' doesn't match 'PUT /logout
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', DELETE]
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /oauth/token' doesn't match 'DELETE /logout
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.web.util.matcher.OrRequestMatcher  : No matches found
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 5 of 11 in additional filter chain; firing Filter: 'BasicAuthenticationFilter'
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.www.BasicAuthenticationFilter  : Basic Authentication Authorization header found for user 'browser'
2018-05-27 05:07:36.318 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.authentication.ProviderManager     : Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
2018-05-27 05:07:36.322 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.www.BasicAuthenticationFilter  : Authentication success: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@f700a374: Principal: org.springframework.security.core.userdetails.User@8ff2b28: Username: browser; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Not granted any authorities; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@7798: RemoteIpAddress: 172.30.0.14; SessionId: null; Not granted any authorities
2018-05-27 05:07:36.322 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 6 of 11 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2018-05-27 05:07:36.322 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 7 of 11 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2018-05-27 05:07:36.322 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 8 of 11 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.AnonymousAuthenticationFilter  : SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@f700a374: Principal: org.springframework.security.core.userdetails.User@8ff2b28: Username: browser; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Not granted any authorities; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@7798: RemoteIpAddress: 172.30.0.14; SessionId: null; Not granted any authorities'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 9 of 11 in additional filter chain; firing Filter: 'SessionManagementFilter'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] s.CompositeSessionAuthenticationStrategy : Delegating to org.springframework.security.web.authentication.session.ChangeSessionIdAuthenticationStrategy@2783717b
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 10 of 11 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token at position 11 of 11 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/oauth/token'; against '/oauth/token'
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.i.FilterSecurityInterceptor    : Secure object: FilterInvocation: URL: /oauth/token; Attributes: [fullyAuthenticated]
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@f700a374: Principal: org.springframework.security.core.userdetails.User@8ff2b28: Username: browser; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Not granted any authorities; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@7798: RemoteIpAddress: 172.30.0.14; SessionId: null; Not granted any authorities
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@38297189, returned: 1
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.i.FilterSecurityInterceptor    : Authorization successful
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.i.FilterSecurityInterceptor    : RunAsManager did not change Authentication object
2018-05-27 05:07:36.323 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.security.web.FilterChainProxy        : /oauth/token reached end of additional filter chain; proceeding with original chain
2018-05-27 05:07:36.331 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] .s.o.p.e.FrameworkEndpointHandlerMapping : Looking up handler method for path /oauth/token
2018-05-27 05:07:36.331 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] .s.o.p.e.FrameworkEndpointHandlerMapping : Returning handler method [public org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken> org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.postAccessToken(java.security.Principal,java.util.Map<java.lang.String, java.lang.String>) throws org.springframework.web.HttpRequestMethodNotSupportedException]
2018-05-27 05:07:36.332 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] .s.o.p.e.FrameworkEndpointHandlerMapping : Looking up handler method for path /oauth/token
2018-05-27 05:07:36.332 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] .s.o.p.e.FrameworkEndpointHandlerMapping : Returning handler method [public org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken> org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.postAccessToken(java.security.Principal,java.util.Map<java.lang.String, java.lang.String>) throws org.springframework.web.HttpRequestMethodNotSupportedException]
2018-05-27 05:07:36.333 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] .o.p.p.ResourceOwnerPasswordTokenGranter : Getting access token for: browser
2018-05-27 05:07:36.333 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.authentication.ProviderManager     : Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
2018-05-27 05:07:36.417 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.header.writers.HstsHeaderWriter  : Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@3c16e254
2018-05-27 05:07:36.418 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2018-05-27 05:07:36.418 DEBUG [auth-service,c583cf7400721aca,c583cf7400721aca,true] 1 --- [io-5000-exec-24] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed
hanrw commented 6 years ago

@jzampieron could you share some information here?

duongvansang commented 6 years ago

I have the same issue, verify and create new token is very slow, even I use StandandPasswordEncoder (not Bcrypt). It seems issue from SpringSecurity Core, I am trying to find out where is issue these days. Benchmark with server 8 Cores, 16GB RAM Only reach 60 requests/second for creating token, and 80 requests/seconds for getting resource with token, so slow.

hanrw commented 6 years ago

@duongvansang StandandPasswordEncoder should much faster than Bcrypt.

armhart commented 5 years ago

My getToken turned out to be slow because of this issue: https://bugs.openjdk.java.net/browse/JDK-8022063

ajaydarshanala commented 5 years ago

I am also facing the same issue from my application spring boot docker container application.some time the /oauth/token response immediately but occasionally it takes more then 60 sec to generate token eventually get timeout exception

bronzewind commented 5 years ago

I have an API which is a client from a third party API that uses OAuth Authentication. The performance of the first call is always around 20 secs. In there a "good practice" to work around this issue?

RexG commented 4 years ago

it's true that BCrypt is slow, however "StandardPasswordEncoder" is deprecated, any other alternative?

jlarroque commented 3 years ago

Same question here, any other alternative ?

Darapu commented 2 years ago

it's true that BCrypt is slow, however "StandardPasswordEncoder" is deprecated, any other alternative?

one more option to use "Argon2PasswordEncoder".