This repository was archived by the owner on May 31, 2022. It is now read-only.
-
Couldn't load subscription status.
- Fork 4k
This repository was archived by the owner on May 31, 2022. It is now read-only.
Failed to find access token for token #846
Copy link
Copy link
Closed
Labels
Description
Hi, could you please help me to understand what is wrong with my setup. With InMemoryTokenStore everything works fine (I'm able to receive the tokens) but as I want the refresh tokens to be persisted, I switched to JdbcTokenStore (spring-security-jwt v1.0.5.RELEASE, spring-security-oauth2 v2.0.11.RELEASE). Now when I send access token request like follows:
curl -X POST -vu myapp12:TBe6G9W1t7Uv http://localhost:8080/oauth/token -H "Accept: application/json" -d "password=papidakos&username=cpapidas&grant_type=password&scope=read%20write&client_secret=TBe6G9W1t7Uv&client_id=myapp12"
I get:
{"error":"server_error","error_description":"java.io.NotSerializableException: Unmentionable.model.Role"}
OAuth2Configuration
public class OAuth2Configuration {
private static final String RESOURCE_ID = "restservice";
@Configuration
@EnableResourceServer
protected static class ResourceServerConfiguration extends ResourceServerConfigurerAdapter {
@Autowired
private JwtAccessTokenConverter jwtAccessTokenConverter;
@Override
public void configure(final ResourceServerSecurityConfigurer resources) {
resources.resourceId(RESOURCE_ID).tokenStore(new JwtTokenStore(jwtAccessTokenConverter));
}
@Override
public void configure(final HttpSecurity http) throws Exception {
http
.csrf().disable()
.authorizeRequests()
.antMatchers("/user/**").authenticated();
}
}
@Configuration
@EnableAuthorizationServer
protected static class AuthorizationServerConfiguration extends AuthorizationServerConfigurerAdapter {
@Autowired
private DataSource dataSource;
@Autowired
private JwtAccessTokenConverter jwtAccessTokenConverter;
@Autowired
@Qualifier("authenticationManagerBean")
private AuthenticationManager authenticationManager;
@Autowired
private CustomUserDetailsService userDetailsService;
@Override
public void configure(final AuthorizationServerEndpointsConfigurer endpoints) throws Exception {
endpoints
.tokenStore(tokenStore())
.authenticationManager(authenticationManager)
.accessTokenConverter(jwtAccessTokenConverter)
.userDetailsService(userDetailsService);
}
@Override
public void configure(final ClientDetailsServiceConfigurer clients) throws Exception {
clients
.jdbc(dataSource);
}
@Bean
public DefaultTokenServices tokenServices() {
final DefaultTokenServices tokenServices = new DefaultTokenServices();
tokenServices.setSupportRefreshToken(true);
tokenServices.setTokenStore(tokenStore());
return tokenServices;
}
@Bean
public TokenStore tokenStore() {
return new JdbcTokenStore(dataSource);
}
}
}
WebSecurityConfiguration
@Configuration
@EnableWebSecurity
public class WebSecurityConfiguration extends WebSecurityConfigurerAdapter {
@Autowired
private CustomUserDetailsService userDetailsService;
@Autowired
private AccountAuthenticationProvider accountAuthenticationProvider;
@Override
protected void configure(final AuthenticationManagerBuilder auth) throws Exception {
auth.userDetailsService(userDetailsService);
auth.authenticationProvider(accountAuthenticationProvider);
}
@Bean
public PasswordEncoder passwordEncoder() {
return new BCryptPasswordEncoder();
}
@Bean
@Override
public AuthenticationManager authenticationManagerBean() throws Exception {
return super.authenticationManagerBean();
}
@Bean
public JwtAccessTokenConverter jwtAccessTokenConverter() {
final JwtAccessTokenConverter jwtAccessTokenConverter = new JwtAccessTokenConverter();
jwtAccessTokenConverter.setSigningKey("qeFz6P80cloLtue19ecVPQWVJ1UUA1oE98k");
return jwtAccessTokenConverter;
}
}
Database tables
+-------------------------+
| Tables_in_unmentionable |
+-------------------------+
| account |
| account_role |
| oauth_access_token | <-- empty
| oauth_client_details |
| oauth_client_token | <-- empty
| oauth_code | <-- empty
| oauth_refresh_token | <-- empty
| role |
| user_group |
+-------------------------+
> select * from oauth_client_details;
+-----------+--------------+---------------+------------+------------------------+-------------------------+-------------+-----------------------+------------------------+------------------------+-------------+
| client_id | resource_ids | client_secret | scope | authorized_grant_types | web_server_redirect_uri | authorities | access_token_validity | refresh_token_validity | additional_information | autoapprove |
+-----------+--------------+---------------+------------+------------------------+-------------------------+-------------+-----------------------+------------------------+------------------------+-------------+
| myapp12 | restservice | TBe6G9W1t7Uv | read,write | password,refresh_token | | USER | 9999 | 99999 | {} | |
+-----------+--------------+---------------+------------+------------------------+-------------------------+-------------+-----------------------+------------------------+------------------------+-------------+
> select * from account;
+----+---------------------+--------------------+-------------------------+---------+-----------+----------+--------------------+---------+--------+
| id | account_non_expired | account_non_locked | credentials_non_expired | enabled | password | username | credentialsexpired | expired | locked |
+----+---------------------+--------------------+-------------------------+---------+-----------+----------+--------------------+---------+--------+
| 3 | | | | | papidakos | cpapidas | | | |
+----+---------------------+--------------------+-------------------------+---------+-----------+----------+--------------------+---------+--------+
Logs
o.s.web.servlet.DispatcherServlet : Initializing servlet 'dispatcherServlet'
o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring FrameworkServlet 'dispatcherServlet'
o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization started
o.s.web.servlet.DispatcherServlet : Using MultipartResolver [org.springframework.web.multipart.support.StandardServletMultipartResolver@db800cf]
o.s.web.servlet.DispatcherServlet : Unable to locate LocaleResolver with name 'localeResolver': using default [org.springframework.web.servlet.i18n.AcceptHeaderLocaleResolver@7a0961a0]
o.s.web.servlet.DispatcherServlet : Unable to locate ThemeResolver with name 'themeResolver': using default [org.springframework.web.servlet.theme.FixedThemeResolver@6956d575]
o.s.web.servlet.DispatcherServlet : Unable to locate RequestToViewNameTranslator with name 'viewNameTranslator': using default [org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@1a52f2d]
o.s.web.servlet.DispatcherServlet : Unable to locate FlashMapManager with name 'flashMapManager': using default [org.springframework.web.servlet.support.SessionFlashMapManager@2ed511b0]
o.s.web.servlet.DispatcherServlet : Published WebApplicationContext of servlet 'dispatcherServlet' as ServletContext attribute with name [org.springframework.web.servlet.FrameworkServlet.CONTEXT.dispatcherServlet]
o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 17 ms
o.s.web.servlet.DispatcherServlet : Servlet 'dispatcherServlet' configured successfully
o.s.web.servlet.DispatcherServlet : Bound request context to thread: SecurityContextHolderAwareRequestWrapper[ FirewalledRequest[ org.apache.catalina.connector.RequestFacade@1aa1f516]]
o.s.web.servlet.DispatcherServlet : DispatcherServlet with name 'dispatcherServlet' processing POST request for [/oauth/token]
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping@563016ff] in DispatcherServlet with name 'dispatcherServlet'
o.s.w.s.handler.SimpleUrlHandlerMapping : No handler mapping found for [/oauth/token]
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.boot.actuate.endpoint.mvc.EndpointHandlerMapping@7070ece6] in DispatcherServlet with name 'dispatcherServlet'
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping@1fcdbd28] in DispatcherServlet with name 'dispatcherServlet'
s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /oauth/token
s.w.s.m.m.a.RequestMappingHandlerMapping : Did not find handler method for [/oauth/token]
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping@1d277f4e] in DispatcherServlet with name 'dispatcherServlet'
o.s.w.s.handler.SimpleUrlHandlerMapping : No handler mapping found for [/oauth/token]
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.web.servlet.handler.BeanNameUrlHandlerMapping@24f3f8cb] in DispatcherServlet with name 'dispatcherServlet'
o.s.w.s.h.BeanNameUrlHandlerMapping : No handler mapping found for [/oauth/token]
o.s.web.servlet.DispatcherServlet : Testing handler map [org.springframework.security.oauth2.provider.endpoint.FrameworkEndpointHandlerMapping@6ccbdae5] in DispatcherServlet with name 'dispatcherServlet'
o.s.web.servlet.DispatcherServlet : Testing handler adapter [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter@ac44b55]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestParamMethodArgumentResolver@765b7919] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestParamMapMethodArgumentResolver@28457933] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.PathVariableMethodArgumentResolver@7b68251] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.PathVariableMapMethodArgumentResolver@585d3fd1] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.MatrixVariableMethodArgumentResolver@6bca9a81] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.MatrixVariableMapMethodArgumentResolver@6b1bcf7] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.ServletModelAttributeMethodProcessor@39903032] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor@5eceaf62] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.RequestPartMethodArgumentResolver@47408052] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestHeaderMethodArgumentResolver@6c5e8267] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestHeaderMapMethodArgumentResolver@4e0011ea] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.ServletCookieValueMethodArgumentResolver@5655fff7] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.ExpressionValueMethodArgumentResolver@5c327043] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.servlet.mvc.method.annotation.ServletRequestMethodArgumentResolver@25e18675] supports [interface java.security.Principal]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestParamMethodArgumentResolver@765b7919] supports [java.util.Map<java.lang.String, java.lang.String>]
s.HandlerMethodArgumentResolverComposite : Testing if argument resolver [org.springframework.web.method.annotation.RequestParamMapMethodArgumentResolver@28457933] supports [java.util.Map<java.lang.String, java.lang.String>]
.w.s.m.m.a.ServletInvocableHandlerMethod : Invoking [TokenEndpoint.postAccessToken] method with arguments [org.springframework.security.authentication.UsernamePasswordAuthenticationToken@fb9e7a4e: Principal: org.springframework.security.core.userdetails.User@446d525: Username: myapp12; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: USER, {password=papidakos, username=cpapidas, grant_type=password, scope=read write, client_secret=TBe6G9W1t7Uv, client_id=myapp12}]
.i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session. tenant=null, owner=org.hibernate.jpa.internal.EntityManagerImpl@2ef52232
org.hibernate.internal.SessionImpl : Opened session at timestamp: 14744863400
org.hibernate.internal.SessionImpl : Setting flush mode to: AUTO
org.hibernate.internal.SessionImpl : Setting cache mode to: NORMAL
o.h.engine.query.spi.QueryPlanCache : Located HQL query plan in cache (SELECT a FROM Account a WHERE a.username = :username)
o.h.engine.query.spi.QueryPlanCache : Located HQL query plan in cache (SELECT a FROM Account a WHERE a.username = :username)
o.h.engine.query.spi.HQLQueryPlan : Find: SELECT a FROM Account a WHERE a.username = :username
o.hibernate.engine.spi.QueryParameters : Named parameters: {username=cpapidas}
org.hibernate.SQL : select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=?
Hibernate: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=?
o.h.e.j.internal.LogicalConnectionImpl : Obtaining JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Obtained JDBC connection
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering statement [com.mysql.jdbc.JDBC42PreparedStatement@c7c09e9: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=** NOT SPECIFIED **]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering last query statement [com.mysql.jdbc.JDBC42PreparedStatement@c7c09e9: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=** NOT SPECIFIED **]
o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [VARCHAR] - [cpapidas]
org.hibernate.loader.Loader : Bound [2] parameters total
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering result set [com.mysql.jdbc.JDBC42ResultSet@6ebae603]
org.hibernate.loader.Loader : Processing result set
org.hibernate.loader.Loader : Result set row: 0
o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_0_] : [BIGINT]) - [3]
org.hibernate.loader.Loader : Result row: EntityKey[Unmentionable.model.Account#3]
org.hibernate.loader.Loader : Initializing object from ResultSet: [Unmentionable.model.Account#3]
o.h.p.entity.AbstractEntityPersister : Hydrating entity: [Unmentionable.model.Account#3]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_2_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_3_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([credenti4_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([enabled5_0_] : [BOOLEAN]) - [true]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([password6_0_] : [VARCHAR]) - [papidakos]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([username7_0_] : [VARCHAR]) - [cpapidas]
org.hibernate.loader.Loader : Done processing result set (1 rows)
org.hibernate.loader.Loader : Total objects hydrated: 1
o.h.engine.internal.TwoPhaseLoad : Resolving associations for [Unmentionable.model.Account#3]
org.hibernate.type.CollectionType : Created collection wrapper: [Unmentionable.model.Account.roles#3]
o.h.engine.internal.TwoPhaseLoad : Done materializing entity [Unmentionable.model.Account#3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing statement [com.mysql.jdbc.JDBC42PreparedStatement@c7c09e9: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username='cpapidas']
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing result set [com.mysql.jdbc.JDBC42ResultSet@6ebae603]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing prepared statement [com.mysql.jdbc.JDBC42PreparedStatement@c7c09e9: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username='cpapidas']
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Starting after statement execution processing [ON_CLOSE]
o.h.e.i.StatefulPersistenceContext : Initializing non-lazy collections
DefaultInitializeCollectionEventListener : Initializing collection [Unmentionable.model.Account.roles#3]
DefaultInitializeCollectionEventListener : Checking second-level cache
DefaultInitializeCollectionEventListener : Collection not cached
stractLoadPlanBasedCollectionInitializer : Loading collection: [Unmentionable.model.Account.roles#3]
org.hibernate.SQL : select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=?
Hibernate: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=?
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering statement [com.mysql.jdbc.JDBC42PreparedStatement@3f06c90: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=** NOT SPECIFIED **]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering last query statement [com.mysql.jdbc.JDBC42PreparedStatement@3f06c90: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=** NOT SPECIFIED **]
o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [3]
o.h.l.p.e.i.AbstractLoadPlanBasedLoader : Bound [2] parameters total
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering result set [com.mysql.jdbc.JDBC42ResultSet@50c0e128]
o.h.l.p.e.p.i.ResultSetProcessorImpl : Preparing collection intializer : [Unmentionable.model.Account.roles#3]
o.h.e.loading.internal.LoadContexts : Constructing collection load context for result set [com.mysql.jdbc.JDBC42ResultSet@50c0e128]
o.h.e.l.internal.CollectionLoadContext : Starting attempt to find loading collection [[Unmentionable.model.Account.roles#3]]
o.h.e.l.internal.CollectionLoadContext : Collection not yet initialized; initializing
o.h.l.p.e.p.i.ResultSetProcessorImpl : Processing result set
o.h.l.p.e.p.i.ResultSetProcessorImpl : Starting ResultSet row #0
o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_2_1_] : [BIGINT]) - [1]
l.p.e.p.i.EntityReferenceInitializerImpl : hydrating entity state
l.p.e.p.i.EntityReferenceInitializerImpl : Initializing object from ResultSet: [Unmentionable.model.Role#1]
o.h.p.entity.AbstractEntityPersister : Hydrating entity: [Unmentionable.model.Role#1]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([code2_2_1_] : [VARCHAR]) - [ROLE_USER]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([label3_2_1_] : [VARCHAR]) - [User]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_1_0_0_] : [BIGINT]) - [3]
e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [Unmentionable.model.Account.roles#3]
o.h.e.l.internal.CollectionLoadContext : Starting attempt to find loading collection [[Unmentionable.model.Account.roles#3]]
o.h.e.loading.internal.LoadContexts : Attempting to locate loading collection entry [CollectionKey[Unmentionable.model.Account.roles#3]] in any result-set context
o.h.e.loading.internal.LoadContexts : Collection [CollectionKey[Unmentionable.model.Account.roles#3]] located in load context
o.h.e.l.internal.CollectionLoadContext : Found loading collection bound to current result set processing; reading row
o.h.type.descriptor.sql.BasicExtractor : extracted value ([role_id2_1_0_] : [BIGINT]) - [1]
o.h.e.internal.DefaultLoadEventListener : Loading entity: [Unmentionable.model.Role#1]
o.h.e.internal.DefaultLoadEventListener : Attempting to resolve: [Unmentionable.model.Role#1]
o.h.e.internal.DefaultLoadEventListener : Resolved object in session cache: [Unmentionable.model.Role#1]
o.h.l.p.e.p.i.ResultSetProcessorImpl : Done processing result set (1 rows)
o.h.l.p.e.p.internal.AbstractRowReader : Total objects hydrated: 1
o.h.engine.internal.TwoPhaseLoad : Resolving associations for [Unmentionable.model.Role#1]
o.h.engine.internal.TwoPhaseLoad : Done materializing entity [Unmentionable.model.Role#1]
o.h.e.loading.internal.LoadContexts : Attempting to locate loading collection entry [CollectionKey[Unmentionable.model.Account.roles#3]] in any result-set context
o.h.e.loading.internal.LoadContexts : Collection [CollectionKey[Unmentionable.model.Account.roles#3]] located in load context
o.h.e.l.internal.CollectionLoadContext : Removing collection load entry [org.hibernate.engine.loading.internal.LoadingCollectionEntry<rs=com.mysql.jdbc.JDBC42ResultSet@50c0e128, coll=[Unmentionable.model.Account.roles#3]>@6284e068]
o.h.e.l.internal.CollectionLoadContext : 1 collections were found in result set for role: Unmentionable.model.Account.roles
o.h.e.l.internal.CollectionLoadContext : Ending loading collection [org.hibernate.engine.loading.internal.LoadingCollectionEntry<rs=com.mysql.jdbc.JDBC42ResultSet@50c0e128, coll=[Unmentionable.model.Account.roles#3]>@6284e068]
o.h.e.l.internal.CollectionLoadContext : Collection fully initialized: [Unmentionable.model.Account.roles#3]
o.h.e.l.internal.CollectionLoadContext : 1 collections initialized for role: Unmentionable.model.Account.roles
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing result set [com.mysql.jdbc.JDBC42ResultSet@50c0e128]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing result set [com.mysql.jdbc.JDBC42ResultSet@50c0e128]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing statement [com.mysql.jdbc.JDBC42PreparedStatement@3f06c90: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing prepared statement [com.mysql.jdbc.JDBC42PreparedStatement@3f06c90: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Starting after statement execution processing [ON_CLOSE]
stractLoadPlanBasedCollectionInitializer : Done loading collection
DefaultInitializeCollectionEventListener : Collection initialized
org.hibernate.internal.SessionImpl : Closing session
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@43ee9e0e]
o.h.e.j.internal.LogicalConnectionImpl : Closing logical connection
o.h.e.j.internal.LogicalConnectionImpl : Releasing JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Released JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Logical connection closed
o.s.s.c.bcrypt.BCryptPasswordEncoder : Encoded password does not look like BCrypt
.i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session. tenant=null, owner=org.hibernate.jpa.internal.EntityManagerImpl@629b3abd
org.hibernate.internal.SessionImpl : Opened session at timestamp: 14744863401
org.hibernate.internal.SessionImpl : Setting flush mode to: AUTO
org.hibernate.internal.SessionImpl : Setting cache mode to: NORMAL
o.h.engine.query.spi.QueryPlanCache : Located HQL query plan in cache (SELECT a FROM Account a WHERE a.username = :username)
o.h.engine.query.spi.QueryPlanCache : Located HQL query plan in cache (SELECT a FROM Account a WHERE a.username = :username)
o.h.engine.query.spi.HQLQueryPlan : Find: SELECT a FROM Account a WHERE a.username = :username
o.hibernate.engine.spi.QueryParameters : Named parameters: {username=cpapidas}
org.hibernate.SQL : select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=?
Hibernate: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=?
o.h.e.j.internal.LogicalConnectionImpl : Obtaining JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Obtained JDBC connection
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering statement [com.mysql.jdbc.JDBC42PreparedStatement@3bda22f1: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=** NOT SPECIFIED **]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering last query statement [com.mysql.jdbc.JDBC42PreparedStatement@3bda22f1: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username=** NOT SPECIFIED **]
o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [VARCHAR] - [cpapidas]
org.hibernate.loader.Loader : Bound [2] parameters total
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering result set [com.mysql.jdbc.JDBC42ResultSet@76ece61f]
org.hibernate.loader.Loader : Processing result set
org.hibernate.loader.Loader : Result set row: 0
o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_0_] : [BIGINT]) - [3]
org.hibernate.loader.Loader : Result row: EntityKey[Unmentionable.model.Account#3]
org.hibernate.loader.Loader : Initializing object from ResultSet: [Unmentionable.model.Account#3]
o.h.p.entity.AbstractEntityPersister : Hydrating entity: [Unmentionable.model.Account#3]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_2_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_3_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([credenti4_0_] : [BOOLEAN]) - [false]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([enabled5_0_] : [BOOLEAN]) - [true]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([password6_0_] : [VARCHAR]) - [papidakos]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([username7_0_] : [VARCHAR]) - [cpapidas]
org.hibernate.loader.Loader : Done processing result set (1 rows)
org.hibernate.loader.Loader : Total objects hydrated: 1
o.h.engine.internal.TwoPhaseLoad : Resolving associations for [Unmentionable.model.Account#3]
org.hibernate.type.CollectionType : Created collection wrapper: [Unmentionable.model.Account.roles#3]
o.h.engine.internal.TwoPhaseLoad : Done materializing entity [Unmentionable.model.Account#3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing statement [com.mysql.jdbc.JDBC42PreparedStatement@3bda22f1: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username='cpapidas']
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing result set [com.mysql.jdbc.JDBC42ResultSet@76ece61f]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing prepared statement [com.mysql.jdbc.JDBC42PreparedStatement@3bda22f1: select account0_.id as id1_0_, account0_.account_non_expired as account_2_0_, account0_.account_non_locked as account_3_0_, account0_.credentials_non_expired as credenti4_0_, account0_.enabled as enabled5_0_, account0_.password as password6_0_, account0_.username as username7_0_ from account account0_ where account0_.username='cpapidas']
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Starting after statement execution processing [ON_CLOSE]
o.h.e.i.StatefulPersistenceContext : Initializing non-lazy collections
DefaultInitializeCollectionEventListener : Initializing collection [Unmentionable.model.Account.roles#3]
DefaultInitializeCollectionEventListener : Checking second-level cache
DefaultInitializeCollectionEventListener : Collection not cached
stractLoadPlanBasedCollectionInitializer : Loading collection: [Unmentionable.model.Account.roles#3]
org.hibernate.SQL : select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=?
Hibernate: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=?
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering statement [com.mysql.jdbc.JDBC42PreparedStatement@3fc33225: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=** NOT SPECIFIED **]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering last query statement [com.mysql.jdbc.JDBC42PreparedStatement@3fc33225: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=** NOT SPECIFIED **]
o.h.type.descriptor.sql.BasicBinder : binding parameter [1] as [BIGINT] - [3]
o.h.l.p.e.i.AbstractLoadPlanBasedLoader : Bound [2] parameters total
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Registering result set [com.mysql.jdbc.JDBC42ResultSet@6062deed]
o.h.l.p.e.p.i.ResultSetProcessorImpl : Preparing collection intializer : [Unmentionable.model.Account.roles#3]
o.h.e.loading.internal.LoadContexts : Constructing collection load context for result set [com.mysql.jdbc.JDBC42ResultSet@6062deed]
o.h.e.l.internal.CollectionLoadContext : Starting attempt to find loading collection [[Unmentionable.model.Account.roles#3]]
o.h.e.l.internal.CollectionLoadContext : Collection not yet initialized; initializing
o.h.l.p.e.p.i.ResultSetProcessorImpl : Processing result set
o.h.l.p.e.p.i.ResultSetProcessorImpl : Starting ResultSet row #0
o.h.type.descriptor.sql.BasicExtractor : extracted value ([id1_2_1_] : [BIGINT]) - [1]
l.p.e.p.i.EntityReferenceInitializerImpl : hydrating entity state
l.p.e.p.i.EntityReferenceInitializerImpl : Initializing object from ResultSet: [Unmentionable.model.Role#1]
o.h.p.entity.AbstractEntityPersister : Hydrating entity: [Unmentionable.model.Role#1]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([code2_2_1_] : [VARCHAR]) - [ROLE_USER]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([label3_2_1_] : [VARCHAR]) - [User]
o.h.type.descriptor.sql.BasicExtractor : extracted value ([account_1_0_0_] : [BIGINT]) - [3]
e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [Unmentionable.model.Account.roles#3]
o.h.e.l.internal.CollectionLoadContext : Starting attempt to find loading collection [[Unmentionable.model.Account.roles#3]]
o.h.e.loading.internal.LoadContexts : Attempting to locate loading collection entry [CollectionKey[Unmentionable.model.Account.roles#3]] in any result-set context
o.h.e.loading.internal.LoadContexts : Collection [CollectionKey[Unmentionable.model.Account.roles#3]] located in load context
o.h.e.l.internal.CollectionLoadContext : Found loading collection bound to current result set processing; reading row
o.h.type.descriptor.sql.BasicExtractor : extracted value ([role_id2_1_0_] : [BIGINT]) - [1]
o.h.e.internal.DefaultLoadEventListener : Loading entity: [Unmentionable.model.Role#1]
o.h.e.internal.DefaultLoadEventListener : Attempting to resolve: [Unmentionable.model.Role#1]
o.h.e.internal.DefaultLoadEventListener : Resolved object in session cache: [Unmentionable.model.Role#1]
o.h.l.p.e.p.i.ResultSetProcessorImpl : Done processing result set (1 rows)
o.h.l.p.e.p.internal.AbstractRowReader : Total objects hydrated: 1
o.h.engine.internal.TwoPhaseLoad : Resolving associations for [Unmentionable.model.Role#1]
o.h.engine.internal.TwoPhaseLoad : Done materializing entity [Unmentionable.model.Role#1]
o.h.e.loading.internal.LoadContexts : Attempting to locate loading collection entry [CollectionKey[Unmentionable.model.Account.roles#3]] in any result-set context
o.h.e.loading.internal.LoadContexts : Collection [CollectionKey[Unmentionable.model.Account.roles#3]] located in load context
o.h.e.l.internal.CollectionLoadContext : Removing collection load entry [org.hibernate.engine.loading.internal.LoadingCollectionEntry<rs=com.mysql.jdbc.JDBC42ResultSet@6062deed, coll=[Unmentionable.model.Account.roles#3]>@1fe845d0]
o.h.e.l.internal.CollectionLoadContext : 1 collections were found in result set for role: Unmentionable.model.Account.roles
o.h.e.l.internal.CollectionLoadContext : Ending loading collection [org.hibernate.engine.loading.internal.LoadingCollectionEntry<rs=com.mysql.jdbc.JDBC42ResultSet@6062deed, coll=[Unmentionable.model.Account.roles#3]>@1fe845d0]
o.h.e.l.internal.CollectionLoadContext : Collection fully initialized: [Unmentionable.model.Account.roles#3]
o.h.e.l.internal.CollectionLoadContext : 1 collections initialized for role: Unmentionable.model.Account.roles
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing result set [com.mysql.jdbc.JDBC42ResultSet@6062deed]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing result set [com.mysql.jdbc.JDBC42ResultSet@6062deed]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Releasing statement [com.mysql.jdbc.JDBC42PreparedStatement@3fc33225: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing prepared statement [com.mysql.jdbc.JDBC42PreparedStatement@3fc33225: select roles0_.account_id as account_1_0_0_, roles0_.role_id as role_id2_1_0_, role1_.id as id1_2_1_, role1_.code as code2_2_1_, role1_.label as label3_2_1_ from account_role roles0_ inner join role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=3]
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Starting after statement execution processing [ON_CLOSE]
stractLoadPlanBasedCollectionInitializer : Done loading collection
DefaultInitializeCollectionEventListener : Collection initialized
org.hibernate.internal.SessionImpl : Closing session
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@4f3dd853]
o.h.e.j.internal.LogicalConnectionImpl : Closing logical connection
o.h.e.j.internal.LogicalConnectionImpl : Releasing JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Released JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Logical connection closed
.i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session. tenant=null, owner=org.hibernate.jpa.internal.EntityManagerImpl@1155d7ca
org.hibernate.internal.SessionImpl : Opened session at timestamp: 14744863401
org.hibernate.internal.SessionImpl : Setting flush mode to: AUTO
org.hibernate.internal.SessionImpl : Setting cache mode to: NORMAL
o.h.e.t.spi.AbstractTransactionImpl : begin
o.h.e.j.internal.LogicalConnectionImpl : Obtaining JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Obtained JDBC connection
o.h.e.t.internal.jdbc.JdbcTransaction : initial autocommit status: true
o.h.e.t.internal.jdbc.JdbcTransaction : disabling autocommit
o.s.s.o.p.token.store.JdbcTokenStore : Failed to find access token for token eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOlsicmVzdHNlcnZpY2UiXSwidXNlcl9uYW1lIjoiY3BhcGlkYXMiLCJzY29wZSI6WyJyZWFkIiwid3JpdGUiXSwiZXhwIjoxNDc0NDg2MzcwLCJhdXRob3JpdGllcyI6WyJST0xFX1VTRVIiXSwianRpIjoiYmY1MmYyZDEtMjFiNy00MDhhLWJiYTItZjdkZDVhMjIyODUxIiwiY2xpZW50X2lkIjoibGV4aWtvcyJ9.eCUPhamX9glWkX6znCyrhkV9Q3VekiP6g3GM_c-eKAg
o.h.e.t.spi.AbstractTransactionImpl : rolling back
o.h.e.t.internal.jdbc.JdbcTransaction : rolled JDBC Connection
o.h.e.t.internal.jdbc.JdbcTransaction : re-enabling autocommit
o.h.e.t.i.TransactionCoordinatorImpl : after transaction completion
org.hibernate.internal.SessionImpl : after transaction completion
org.hibernate.internal.SessionImpl : Closing session
o.h.e.jdbc.internal.JdbcCoordinatorImpl : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@2ea02942]
o.h.e.j.internal.LogicalConnectionImpl : Closing logical connection
o.h.e.j.internal.LogicalConnectionImpl : Releasing JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Released JDBC connection
o.h.e.j.internal.LogicalConnectionImpl : Logical connection closed
.m.m.a.ExceptionHandlerExceptionResolver : Resolving exception from handler [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]: java.lang.IllegalArgumentException: java.io.NotSerializableException: Unmentionable.model.Role
.m.m.a.ExceptionHandlerExceptionResolver : Invoking @ExceptionHandler method: public org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.exceptions.OAuth2Exception> org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.handleException(java.lang.Exception) throws java.lang.Exception
.w.s.m.m.a.ServletInvocableHandlerMethod : Invoking [TokenEndpoint.handleException] method with arguments [java.lang.IllegalArgumentException: java.io.NotSerializableException: Unmentionable.model.Role]
o.s.s.o.provider.endpoint.TokenEndpoint : Handling error: IllegalArgumentException, java.io.NotSerializableException: Unmentionable.model.Role
.w.s.m.m.a.ServletInvocableHandlerMethod : Method [handleException] returned [<500 Internal Server Error,error="server_error", error_description="java.io.NotSerializableException: Unmentionable.model.Role",{Cache-Control=[no-store], Pragma=[no-cache]}>]
o.s.w.s.m.m.a.HttpEntityMethodProcessor : Written [error="server_error", error_description="java.io.NotSerializableException: Unmentionable.model.Role"] as "application/json;charset=UTF-8" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@340c15b]
o.s.web.servlet.DispatcherServlet : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
o.s.web.servlet.DispatcherServlet : Cleared thread-bound request context: SecurityContextHolderAwareRequestWrapper[ FirewalledRequest[ org.apache.catalina.connector.RequestFacade@1aa1f516]]
o.s.web.servlet.DispatcherServlet : Successfully completed request
vithubati