mitreid-connect / OpenID-Connect-Java-Spring-Server

An OpenID Connect reference implementation in Java on the Spring platform.
Other
1.48k stars 766 forks source link

Using separate authentication and authorization servers #1037

Closed mobilars closed 8 years ago

mobilars commented 8 years ago

Hi. We are required to use an OAuth server that is only used for authentication, issuing openid id_tokens. That particular server is OpenAM based, and the owner only allows code flow (not implicit/hybrid flows).

We would like to set up a second oauth server that authorizes applications, but reusing the external oauth authentication server for the authentication itself. We really like MittreID and how it's easy to set up scopes, applications etc, and we are wondering if it's possible to combine with the second server for authentication. I've spent some time looking at the examples, and I have some questions.

1) Is it possible to use MitreID in this configuration? The initial authorization request would come in to the MitreID authorization server, which would redirect the user to the OpenAM AM server for authentication, which would send back an auth-code, which MitreId-server would use to fetch an id-token from the OpenAM token-endpoint. The MitreID server would then show a consent page and issue an access token via code/implicit/hybrid flow as configured. Is this possible? 2) If possible, is there example code? I've seen some examples, but I am confused if this is code for an authorization server or just a web app wanting to use an external server for authorization. 3) If that example is the one, I don't quite understand how to link the beans defining the authorization to the actual login process/web page. Could you give a hint as to how to do it?

Thank you!

jricher commented 8 years ago

What you're describing is probably doable. You just need to set the primary authentication of the MITREid Connect server as an OpenID Connect client from OpenAM. The page you linked is the client configuration, and you need to replace the user configuration in the server with that.

However, MITREid Connect doesn't support the hybrid flow, nor does it support the "idtoken" or "token idtoken" response types. We do support the "token" response type for implicit clients, and will send back an idtoken if you request the "openid" scope, but this is off-label use for OIDC.

mobilars commented 8 years ago

Thanks. I'll pursue that then. I've started it and I'm now able to get it to redirect to the external authentication server and soft of getting redirected back to my authorization server. I'm getting an exception when arriving back to my MitreID server, but I'll try to figure it out.

Caused by: javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:138) at org.eclipse.persistence.mappings.DirectCollectionMapping.postInsert(DirectCollectionMapping.java:2216) at org.eclipse.persistence.descriptors.DescriptorQueryManager.postInsert(DescriptorQueryManager.java:999) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:498) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899)

mobilars commented 8 years ago

OK, I need help. I've added what I think is the right configuration to authenticate towards an external site, using the client example. I can log in to the admin/user panel fine, by being redirected to the external site (I'm using the mitreid org site for testnig), and coming back to my server. But when I try to authorize a client, using the following URL, it fails with an exception. Most of the flow works fine. Its after the concent page, as I'm expecting the final redirect that it works. I*ve tried removing my code and then it works, so it's clearly something with my config that's wrong Here is my link: http://localhost:8080/authorize?client_id=client&redirect_uri=http://apps.ehelselab.com/&response_type=code&scope=profile+openid&nonce=6130755535249629&state=14578213732110.3184424809526636

Here is the exception log:

DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/openid_connect_login' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/token' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/jwk' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/.well-known/' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/resources/' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/register/' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/resource/' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/userinfo' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/api/' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/introspect' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/revoke**' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 1 of 13 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' DEBUG: org.springframework.security.web.context.HttpSessionSecurityContextRepository - Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@b6a365b5: Authentication: org.mitre.openid.connect.model.OIDCAuthenticationToken@b6a365b5: Principal: {sub=90342.ASDFJWFA, iss=https://mitreid.org/}; Credentials: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: OIDC_90342.ASDFJWFA_https://mitreid.org/, ROLE_USER, ROLE_ADMIN' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 2 of 13 in additional filter chain; firing Filter: 'AuthorizationRequestFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 3 of 13 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 4 of 13 in additional filter chain; firing Filter: 'HeaderWriterFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 5 of 13 in additional filter chain; firing Filter: 'CsrfFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 6 of 13 in additional filter chain; firing Filter: 'LogoutFilter' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/logout' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 7 of 13 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 8 of 13 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 9 of 13 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 10 of 13 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter' DEBUG: org.springframework.security.web.authentication.AnonymousAuthenticationFilter - SecurityContextHolder not populated with anonymous token, as it already contained: 'org.mitre.openid.connect.model.OIDCAuthenticationToken@b6a365b5: Principal: {sub=90342.ASDFJWFA, iss=https://mitreid.org/}; Credentials: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: OIDC_90342.ASDFJWFA_https://mitreid.org/, ROLE_USER, ROLE_ADMIN' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 11 of 13 in additional filter chain; firing Filter: 'SessionManagementFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 12 of 13 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' DEBUG: org.springframework.security.web.FilterChainProxy - /authorize at position 13 of 13 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' DEBUG: org.springframework.security.web.util.matcher.AntPathRequestMatcher - Checking match of request : '/authorize'; against '/authorize' DEBUG: org.springframework.security.web.access.intercept.FilterSecurityInterceptor - Secure object: FilterInvocation: URL: /authorize; Attributes: [#oauth2.throwOnError(hasRole('ROLE_USER'))] DEBUG: org.springframework.security.web.access.intercept.FilterSecurityInterceptor - Previously Authenticated: org.mitre.openid.connect.model.OIDCAuthenticationToken@b6a365b5: Principal: {sub=90342.ASDFJWFA, iss=https://mitreid.org/}; Credentials: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: OIDC_90342.ASDFJWFA_https://mitreid.org/, ROLE_USER, ROLE_ADMIN DEBUG: org.springframework.security.access.vote.AffirmativeBased - Voter: org.springframework.security.web.access.expression.WebExpressionVoter@7cbfbcd1, returned: 1 DEBUG: org.springframework.security.web.access.intercept.FilterSecurityInterceptor - Authorization successful DEBUG: org.springframework.security.web.access.intercept.FilterSecurityInterceptor - RunAsManager did not change Authentication object DEBUG: org.springframework.security.web.FilterChainProxy - /authorize reached end of additional filter chain; proceeding with original chain DEBUG: org.springframework.web.servlet.DispatcherServlet - DispatcherServlet with name 'spring' processing POST request for [/authorize] DEBUG: org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping - Looking up handler method for path /authorize DEBUG: org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping - Did not find handler method for [/authorize] DEBUG: org.springframework.security.oauth2.provider.endpoint.FrameworkEndpointHandlerMapping - Looking up handler method for path /authorize DEBUG: org.springframework.security.oauth2.provider.endpoint.FrameworkEndpointHandlerMapping - Returning handler method [public org.springframework.web.servlet.View org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(java.util.Map<java.lang.String, java.lang.String>,java.util.Map<java.lang.String, ?>,org.springframework.web.bind.support.SessionStatus,java.security.Principal)] DEBUG: org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'oauth2AuthorizationEndpoint' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaOAuth2ClientRepository.getClientByClientId]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@55ec67d0] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.666--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 557507414 [EL Finer]: transaction: 2016-03-14 21:54:48.667--ClientSession(557507414)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 15552151 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@4900f73b] [EL Finer]: transaction: 2016-03-14 21:54:48.667--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.667--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.667--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="ClientDetailsEntity.getByClientId" referenceClass=ClientDetailsEntity sql="SELECT id, access_token_validity_seconds, allow_introspection, application_type, clear_access_tokens_on_refresh, client_description, client_id, client_name, client_secret, client_uri, created_at, default_max_age, dynamically_registered, id_token_encrypted_response_alg, id_token_encrypted_response_enc, id_token_signed_response_alg, id_token_validity_seconds, initiate_login_uri, jwks, jwks_uri, logo_uri, policy_uri, refresh_token_validity_seconds, request_object_signing_alg, require_auth_time, reuse_refresh_tokens, sector_identifier_uri, subject_type, token_endpoint_auth_method, token_endpoint_auth_signing_alg, tos_uri, user_info_encrypted_response_alg, user_info_encrypted_response_enc, user_info_signed_response_alg FROM client_details WHERE (client_id = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.667--ServerSession(917847816)--Connection(2145704748)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.667--ClientSession(557507414)--Connection(2145704748)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.667--ClientSession(557507414)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.667--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, access_token_validity_seconds, allow_introspection, application_type, clear_access_tokens_on_refresh, client_description, client_id, client_name, client_secret, client_uri, created_at, default_max_age, dynamically_registered, id_token_encrypted_response_alg, id_token_encrypted_response_enc, id_token_signed_response_alg, id_token_validity_seconds, initiate_login_uri, jwks, jwks_uri, logo_uri, policy_uri, refresh_token_validity_seconds, request_object_signing_alg, require_auth_time, reuse_refresh_tokens, sector_identifier_uri, subject_type, token_endpoint_auth_method, token_endpoint_auth_signing_alg, tos_uri, user_info_encrypted_response_alg, user_info_encrypted_response_enc, user_info_signed_response_alg FROM client_details WHERE (client_id = ?) bind => [client] [EL Finest]: query: 2016-03-14 21:54:48.668--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="authorities" sql="SELECT t0.authority FROM client_authority t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.668--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.authority FROM client_authority t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.669--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="claimsRedirectUris" sql="SELECT t0.redirect_uri FROM client_claims_redirect_uri t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.669--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.redirect_uri FROM client_claims_redirect_uri t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.669--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="contacts" sql="SELECT t0.contact FROM client_contact t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.669--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.contact FROM client_contact t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.67--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="defaultACRvalues" sql="SELECT t0.default_acr_value FROM client_default_acr_value t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.67--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.default_acr_value FROM client_default_acr_value t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.67--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="grantTypes" sql="SELECT t0.grant_type FROM client_grant_type t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.67--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.grant_type FROM client_grant_type t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.67--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="postLogoutRedirectUris" sql="SELECT t0.post_logout_redirect_uri FROM client_post_logout_redirect_uri t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.671--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.post_logout_redirect_uri FROM client_post_logout_redirect_uri t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.671--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="redirectUris" sql="SELECT t0.redirect_uri FROM client_redirect_uri t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.671--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.redirect_uri FROM client_redirect_uri t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.671--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="requestUris" sql="SELECT t0.request_uri FROM client_request_uri t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.671--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.request_uri FROM client_request_uri t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.672--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="resourceIds" sql="SELECT t0.resource_id FROM client_resource t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.672--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.resource_id FROM client_resource t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.672--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="responseTypes" sql="SELECT t0.response_type FROM client_response_type t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.672--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.response_type FROM client_response_type t0 WHERE (t0.owner_id = ?) bind => [3] [EL Finest]: query: 2016-03-14 21:54:48.672--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DirectReadQuery(name="scope" sql="SELECT t0.scope FROM client_scope t0 WHERE (t0.owner_id = ?)") [EL Fine]: sql: 2016-03-14 21:54:48.673--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--SELECT t0.scope FROM client_scope t0 WHERE (t0.owner_id = ?) bind => [3] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@55ec67d0] [EL Finer]: transaction: 2016-03-14 21:54:48.673--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.673--ClientSession(557507414)--Connection(154318805)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.673--ServerSession(917847816)--Connection(2145704748)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.673--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.673--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@55ec67d0] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.674--UnitOfWork(15552151)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.674--ClientSession(557507414)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7452d0df] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.674--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1749175711 [EL Finer]: transaction: 2016-03-14 21:54:48.674--ClientSession(1749175711)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 86119500 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@1a941ea5] [EL Finer]: transaction: 2016-03-14 21:54:48.674--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.674--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.674--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.674--ServerSession(917847816)--Connection(2023944448)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.674--ClientSession(1749175711)--Connection(2023944448)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.674--ClientSession(1749175711)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.674--ClientSession(1749175711)--Connection(41313598)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [address] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7452d0df] [EL Finer]: transaction: 2016-03-14 21:54:48.675--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.675--ClientSession(1749175711)--Connection(41313598)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.676--ServerSession(917847816)--Connection(2023944448)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.676--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.676--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7452d0df] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.676--UnitOfWork(86119500)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.676--ClientSession(1749175711)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@427d0a61] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.676--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1930676357 [EL Finer]: transaction: 2016-03-14 21:54:48.676--ClientSession(1930676357)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 2020699758 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@1303943b] [EL Finer]: transaction: 2016-03-14 21:54:48.676--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.676--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.676--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.677--ServerSession(917847816)--Connection(965192248)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.677--ClientSession(1930676357)--Connection(965192248)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.677--ClientSession(1930676357)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.677--ClientSession(1930676357)--Connection(1413290605)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [phone] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@427d0a61] [EL Finer]: transaction: 2016-03-14 21:54:48.678--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.678--ClientSession(1930676357)--Connection(1413290605)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.678--ServerSession(917847816)--Connection(965192248)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.678--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.678--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@427d0a61] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.678--UnitOfWork(2020699758)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.678--ClientSession(1930676357)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2c335f5a] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.679--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 283236035 [EL Finer]: transaction: 2016-03-14 21:54:48.679--ClientSession(283236035)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1468932233 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@70783d3a] [EL Finer]: transaction: 2016-03-14 21:54:48.679--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.679--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.679--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.679--ServerSession(917847816)--Connection(1183282656)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.679--ClientSession(283236035)--Connection(1183282656)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.679--ClientSession(283236035)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.679--ClientSession(283236035)--Connection(1481565245)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2c335f5a] [EL Finer]: transaction: 2016-03-14 21:54:48.68--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.68--ClientSession(283236035)--Connection(1481565245)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.68--ServerSession(917847816)--Connection(1183282656)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.68--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.68--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2c335f5a] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.681--UnitOfWork(1468932233)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.681--ClientSession(283236035)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@32172ab3] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.681--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 500654016 [EL Finer]: transaction: 2016-03-14 21:54:48.681--ClientSession(500654016)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1932879130 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2fdd41ac] [EL Finer]: transaction: 2016-03-14 21:54:48.681--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.681--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.681--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.681--ServerSession(917847816)--Connection(613721174)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.681--ClientSession(500654016)--Connection(613721174)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.681--ClientSession(500654016)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.681--ClientSession(500654016)--Connection(52086363)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [email] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@32172ab3] [EL Finer]: transaction: 2016-03-14 21:54:48.682--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.682--ClientSession(500654016)--Connection(52086363)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.682--ServerSession(917847816)--Connection(613721174)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.682--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.682--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@32172ab3] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.682--UnitOfWork(1932879130)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.683--ClientSession(500654016)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@1ffd35ea] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.683--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1241518160 [EL Finer]: transaction: 2016-03-14 21:54:48.683--ClientSession(1241518160)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1787520081 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@20288ced] [EL Finer]: transaction: 2016-03-14 21:54:48.683--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.683--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.683--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.683--ServerSession(917847816)--Connection(1443671911)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.683--ClientSession(1241518160)--Connection(1443671911)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.683--ClientSession(1241518160)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.683--ClientSession(1241518160)--Connection(482649958)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@1ffd35ea] [EL Finer]: transaction: 2016-03-14 21:54:48.684--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.685--ClientSession(1241518160)--Connection(482649958)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.685--ServerSession(917847816)--Connection(1443671911)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.685--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.685--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@1ffd35ea] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.685--UnitOfWork(1787520081)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.685--ClientSession(1241518160)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a33a62f] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.685--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1131794840 [EL Finer]: transaction: 2016-03-14 21:54:48.685--ClientSession(1131794840)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 166323804 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@7a9228c7] [EL Finer]: transaction: 2016-03-14 21:54:48.685--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.685--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.685--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.686--ServerSession(917847816)--Connection(502786916)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.686--ClientSession(1131794840)--Connection(502786916)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.686--ClientSession(1131794840)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.686--ClientSession(1131794840)--Connection(1893929043)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [offline_access] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a33a62f] [EL Finer]: transaction: 2016-03-14 21:54:48.686--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.687--ClientSession(1131794840)--Connection(1893929043)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.687--ServerSession(917847816)--Connection(502786916)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.687--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.687--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a33a62f] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.687--UnitOfWork(166323804)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.687--ClientSession(1131794840)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7f4f6d1a] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.687--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 390499112 [EL Finer]: transaction: 2016-03-14 21:54:48.687--ClientSession(390499112)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1474331838 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@27c3e26] [EL Finer]: transaction: 2016-03-14 21:54:48.687--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.687--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.687--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.687--ServerSession(917847816)--Connection(106935502)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.687--ClientSession(390499112)--Connection(106935502)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.687--ClientSession(390499112)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.687--ClientSession(390499112)--Connection(627273958)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [address] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7f4f6d1a] [EL Finer]: transaction: 2016-03-14 21:54:48.688--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.688--ClientSession(390499112)--Connection(627273958)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.688--ServerSession(917847816)--Connection(106935502)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.688--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.688--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7f4f6d1a] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.688--UnitOfWork(1474331838)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.688--ClientSession(390499112)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6e1967df] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.688--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1346621114 [EL Finer]: transaction: 2016-03-14 21:54:48.689--ClientSession(1346621114)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 138598631 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@47d5e9e1] [EL Finer]: transaction: 2016-03-14 21:54:48.689--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.689--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.689--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.689--ServerSession(917847816)--Connection(1649887579)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.689--ClientSession(1346621114)--Connection(1649887579)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.689--ClientSession(1346621114)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.689--ClientSession(1346621114)--Connection(749694389)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [phone] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6e1967df] [EL Finer]: transaction: 2016-03-14 21:54:48.689--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.69--ClientSession(1346621114)--Connection(749694389)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.69--ServerSession(917847816)--Connection(1649887579)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.69--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.69--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6e1967df] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.69--UnitOfWork(138598631)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.69--ClientSession(1346621114)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@203e7f3] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.69--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1427562691 [EL Finer]: transaction: 2016-03-14 21:54:48.69--ClientSession(1427562691)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1205404259 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2e752781] [EL Finer]: transaction: 2016-03-14 21:54:48.69--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.69--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.69--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.69--ServerSession(917847816)--Connection(861168067)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.69--ClientSession(1427562691)--Connection(861168067)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.69--ClientSession(1427562691)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.69--ClientSession(1427562691)--Connection(1361481618)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@203e7f3] [EL Finer]: transaction: 2016-03-14 21:54:48.691--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.691--ClientSession(1427562691)--Connection(1361481618)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.691--ServerSession(917847816)--Connection(861168067)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.691--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.691--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@203e7f3] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.691--UnitOfWork(1205404259)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.691--ClientSession(1427562691)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@49e70022] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.692--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 752372883 [EL Finer]: transaction: 2016-03-14 21:54:48.692--ClientSession(752372883)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1758538218 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@58891c9d] [EL Finer]: transaction: 2016-03-14 21:54:48.692--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.692--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.692--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.692--ServerSession(917847816)--Connection(689893822)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.692--ClientSession(752372883)--Connection(689893822)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.692--ClientSession(752372883)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.692--ClientSession(752372883)--Connection(1196199130)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [email] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@49e70022] [EL Finer]: transaction: 2016-03-14 21:54:48.693--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.693--ClientSession(752372883)--Connection(1196199130)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.694--ServerSession(917847816)--Connection(689893822)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.694--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.694--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@49e70022] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.694--UnitOfWork(1758538218)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.694--ClientSession(752372883)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@68037a69] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.695--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1258947055 [EL Finer]: transaction: 2016-03-14 21:54:48.695--ClientSession(1258947055)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1981367629 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@37e66317] [EL Finer]: transaction: 2016-03-14 21:54:48.695--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.695--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.695--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.695--ServerSession(917847816)--Connection(1145407408)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.695--ClientSession(1258947055)--Connection(1145407408)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.695--ClientSession(1258947055)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.695--ClientSession(1258947055)--Connection(1599861678)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@68037a69] [EL Finer]: transaction: 2016-03-14 21:54:48.696--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.696--ClientSession(1258947055)--Connection(1599861678)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.697--ServerSession(917847816)--Connection(1145407408)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.697--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.697--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@68037a69] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.697--UnitOfWork(1981367629)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.697--ClientSession(1258947055)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@f3ebcc1] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.697--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 259581963 [EL Finer]: transaction: 2016-03-14 21:54:48.697--ClientSession(259581963)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1272562191 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@5a9a5ea0] [EL Finer]: transaction: 2016-03-14 21:54:48.697--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.697--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.697--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.697--ServerSession(917847816)--Connection(540551558)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.697--ClientSession(259581963)--Connection(540551558)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.697--ClientSession(259581963)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.697--ClientSession(259581963)--Connection(1757984058)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [offline_access] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@f3ebcc1] [EL Finer]: transaction: 2016-03-14 21:54:48.698--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.699--ClientSession(259581963)--Connection(1757984058)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.699--ServerSession(917847816)--Connection(540551558)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.699--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.699--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@f3ebcc1] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.699--UnitOfWork(1272562191)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.699--ClientSession(259581963)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4f696fb] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.699--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 700088890 [EL Finer]: transaction: 2016-03-14 21:54:48.699--ClientSession(700088890)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1655256288 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@188ec24a] [EL Finer]: transaction: 2016-03-14 21:54:48.699--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.699--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.699--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.7--ServerSession(917847816)--Connection(687857390)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.7--ClientSession(700088890)--Connection(687857390)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.7--ClientSession(700088890)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.7--ClientSession(700088890)--Connection(1428763289)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4f696fb] [EL Finer]: transaction: 2016-03-14 21:54:48.7--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.7--ClientSession(700088890)--Connection(1428763289)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.7--ServerSession(917847816)--Connection(687857390)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.7--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.7--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4f696fb] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.7--UnitOfWork(1655256288)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.7--ClientSession(700088890)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4620a7be] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.7--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1510074393 [EL Finer]: transaction: 2016-03-14 21:54:48.701--ClientSession(1510074393)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1141127907 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2485d819] [EL Finer]: transaction: 2016-03-14 21:54:48.701--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.701--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.701--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.701--ServerSession(917847816)--Connection(1742440032)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.701--ClientSession(1510074393)--Connection(1742440032)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.701--ClientSession(1510074393)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.701--ClientSession(1510074393)--Connection(844102562)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4620a7be] [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.702--ClientSession(1510074393)--Connection(844102562)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.702--ServerSession(917847816)--Connection(1742440032)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4620a7be] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(1141127907)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.702--ClientSession(1510074393)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@66e5269c] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.702--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 725238537 [EL Finer]: transaction: 2016-03-14 21:54:48.702--ClientSession(725238537)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 876450328 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@5bfa8ff0] [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.702--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.703--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.703--ServerSession(917847816)--Connection(350524373)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.703--ClientSession(725238537)--Connection(350524373)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.703--ClientSession(725238537)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.703--ClientSession(725238537)--Connection(1841277003)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@66e5269c] [EL Finer]: transaction: 2016-03-14 21:54:48.703--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.703--ClientSession(725238537)--Connection(1841277003)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.704--ServerSession(917847816)--Connection(350524373)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.704--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.704--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@66e5269c] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.704--UnitOfWork(876450328)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.704--ClientSession(725238537)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@a0a9046] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.704--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 451386556 [EL Finer]: transaction: 2016-03-14 21:54:48.704--ClientSession(451386556)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 2099247788 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@415444b9] [EL Finer]: transaction: 2016-03-14 21:54:48.704--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.704--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.704--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.704--ServerSession(917847816)--Connection(528643189)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.704--ClientSession(451386556)--Connection(528643189)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.704--ClientSession(451386556)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.704--ClientSession(451386556)--Connection(967186757)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [address] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@a0a9046] [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.705--ClientSession(451386556)--Connection(967186757)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.705--ServerSession(917847816)--Connection(528643189)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@a0a9046] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(2099247788)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.705--ClientSession(451386556)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@545152b9] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.705--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1572083015 [EL Finer]: transaction: 2016-03-14 21:54:48.705--ClientSession(1572083015)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 350315728 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2980669f] [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.705--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.705--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.705--ServerSession(917847816)--Connection(1998204300)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.705--ClientSession(1572083015)--Connection(1998204300)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.705--ClientSession(1572083015)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.706--ClientSession(1572083015)--Connection(184090629)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [phone] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@545152b9] [EL Finer]: transaction: 2016-03-14 21:54:48.706--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.706--ClientSession(1572083015)--Connection(184090629)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.707--ServerSession(917847816)--Connection(1998204300)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.707--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.707--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@545152b9] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.707--UnitOfWork(350315728)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.707--ClientSession(1572083015)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@196f26ed] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.707--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1532290285 [EL Finer]: transaction: 2016-03-14 21:54:48.707--ClientSession(1532290285)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1199214523 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@54bccd] [EL Finer]: transaction: 2016-03-14 21:54:48.707--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.707--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.707--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.707--ServerSession(917847816)--Connection(1626122852)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.707--ClientSession(1532290285)--Connection(1626122852)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.707--ClientSession(1532290285)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.707--ClientSession(1532290285)--Connection(476268824)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@196f26ed] [EL Finer]: transaction: 2016-03-14 21:54:48.708--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.708--ClientSession(1532290285)--Connection(476268824)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.708--ServerSession(917847816)--Connection(1626122852)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.708--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.708--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@196f26ed] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.708--UnitOfWork(1199214523)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.708--ClientSession(1532290285)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2fda5d2d] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.709--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 704113223 [EL Finer]: transaction: 2016-03-14 21:54:48.709--ClientSession(704113223)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 518259163 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@37410b0d] [EL Finer]: transaction: 2016-03-14 21:54:48.709--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.709--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.709--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.709--ServerSession(917847816)--Connection(1242504189)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.709--ClientSession(704113223)--Connection(1242504189)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.709--ClientSession(704113223)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.709--ClientSession(704113223)--Connection(1555854633)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [email] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2fda5d2d] [EL Finer]: transaction: 2016-03-14 21:54:48.711--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.711--ClientSession(704113223)--Connection(1555854633)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.711--ServerSession(917847816)--Connection(1242504189)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.711--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.711--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@2fda5d2d] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.711--UnitOfWork(518259163)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.712--ClientSession(704113223)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6f2c1328] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.712--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1342584537 [EL Finer]: transaction: 2016-03-14 21:54:48.712--ClientSession(1342584537)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1881375960 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@5c9dcb00] [EL Finer]: transaction: 2016-03-14 21:54:48.712--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.712--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.712--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.712--ServerSession(917847816)--Connection(1395078888)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.712--ClientSession(1342584537)--Connection(1395078888)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.712--ClientSession(1342584537)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.712--ClientSession(1342584537)--Connection(855007915)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6f2c1328] [EL Finer]: transaction: 2016-03-14 21:54:48.713--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.714--ClientSession(1342584537)--Connection(855007915)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.714--ServerSession(917847816)--Connection(1395078888)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.714--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.714--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6f2c1328] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.714--UnitOfWork(1881375960)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.714--ClientSession(1342584537)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@612db62] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.714--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 133169713 [EL Finer]: transaction: 2016-03-14 21:54:48.714--ClientSession(133169713)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 551767003 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@d258c1e] [EL Finer]: transaction: 2016-03-14 21:54:48.714--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.714--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.714--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.715--ServerSession(917847816)--Connection(494706451)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.715--ClientSession(133169713)--Connection(494706451)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.715--ClientSession(133169713)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.715--ClientSession(133169713)--Connection(437974791)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [offline_access] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@612db62] [EL Finer]: transaction: 2016-03-14 21:54:48.715--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.715--ClientSession(133169713)--Connection(437974791)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.716--ServerSession(917847816)--Connection(494706451)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.716--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.716--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@612db62] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.716--UnitOfWork(551767003)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.716--ClientSession(133169713)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@78046446] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.716--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 904599182 [EL Finer]: transaction: 2016-03-14 21:54:48.716--ClientSession(904599182)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 2070439829 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@35e4358a] [EL Finer]: transaction: 2016-03-14 21:54:48.716--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.716--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.716--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.716--ServerSession(917847816)--Connection(1847148836)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.716--ClientSession(904599182)--Connection(1847148836)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.716--ClientSession(904599182)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.716--ClientSession(904599182)--Connection(61564175)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [address] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@78046446] [EL Finer]: transaction: 2016-03-14 21:54:48.717--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.717--ClientSession(904599182)--Connection(61564175)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.717--ServerSession(917847816)--Connection(1847148836)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.717--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.717--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@78046446] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.717--UnitOfWork(2070439829)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.717--ClientSession(904599182)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@b2fa001] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.717--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1408511862 [EL Finer]: transaction: 2016-03-14 21:54:48.718--ClientSession(1408511862)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1472626134 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2689b575] [EL Finer]: transaction: 2016-03-14 21:54:48.718--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.718--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.718--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.718--ServerSession(917847816)--Connection(1347433997)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.718--ClientSession(1408511862)--Connection(1347433997)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.718--ClientSession(1408511862)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.718--ClientSession(1408511862)--Connection(581778670)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [phone] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@b2fa001] [EL Finer]: transaction: 2016-03-14 21:54:48.718--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.718--ClientSession(1408511862)--Connection(581778670)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.719--ServerSession(917847816)--Connection(1347433997)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.719--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.719--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@b2fa001] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.719--UnitOfWork(1472626134)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.719--ClientSession(1408511862)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7c1941f2] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.719--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 932731091 [EL Finer]: transaction: 2016-03-14 21:54:48.719--ClientSession(932731091)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 2145132365 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@15ceb2e8] [EL Finer]: transaction: 2016-03-14 21:54:48.719--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.719--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.719--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.719--ServerSession(917847816)--Connection(602830706)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.719--ClientSession(932731091)--Connection(602830706)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.719--ClientSession(932731091)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.719--ClientSession(932731091)--Connection(1447423260)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [openid] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7c1941f2] [EL Finer]: transaction: 2016-03-14 21:54:48.72--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.72--ClientSession(932731091)--Connection(1447423260)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.72--ServerSession(917847816)--Connection(602830706)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.72--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.72--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7c1941f2] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.721--UnitOfWork(2145132365)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.721--ClientSession(932731091)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7940b366] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.721--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 9735263 [EL Finer]: transaction: 2016-03-14 21:54:48.721--ClientSession(9735263)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 754127221 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2d913bfc] [EL Finer]: transaction: 2016-03-14 21:54:48.721--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.721--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.721--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.721--ServerSession(917847816)--Connection(1370912427)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.721--ClientSession(9735263)--Connection(1370912427)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.721--ClientSession(9735263)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.721--ClientSession(9735263)--Connection(1977941686)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [email] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7940b366] [EL Finer]: transaction: 2016-03-14 21:54:48.722--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.722--ClientSession(9735263)--Connection(1977941686)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.722--ServerSession(917847816)--Connection(1370912427)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.722--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.722--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7940b366] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.722--UnitOfWork(754127221)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.722--ClientSession(9735263)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a39de9] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.723--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1432408805 [EL Finer]: transaction: 2016-03-14 21:54:48.723--ClientSession(1432408805)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1430712222 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2592dd6e] [EL Finer]: transaction: 2016-03-14 21:54:48.723--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.723--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.723--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.723--ServerSession(917847816)--Connection(1044725984)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.723--ClientSession(1432408805)--Connection(1044725984)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.723--ClientSession(1432408805)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.723--ClientSession(1432408805)--Connection(1843485239)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a39de9] [EL Finer]: transaction: 2016-03-14 21:54:48.724--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.724--ClientSession(1432408805)--Connection(1843485239)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.724--ServerSession(917847816)--Connection(1044725984)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.724--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.724--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@7a39de9] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.724--UnitOfWork(1430712222)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.724--ClientSession(1432408805)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@28a5a210] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.724--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1332897233 [EL Finer]: transaction: 2016-03-14 21:54:48.724--ClientSession(1332897233)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 195032839 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@2a74eb1d] [EL Finer]: transaction: 2016-03-14 21:54:48.725--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.725--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.725--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.725--ServerSession(917847816)--Connection(793012577)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.725--ClientSession(1332897233)--Connection(793012577)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.725--ClientSession(1332897233)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.725--ClientSession(1332897233)--Connection(1942281653)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [offline_access] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@28a5a210] [EL Finer]: transaction: 2016-03-14 21:54:48.726--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.726--ClientSession(1332897233)--Connection(1942281653)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.726--ServerSession(917847816)--Connection(793012577)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.727--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.727--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@28a5a210] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.727--UnitOfWork(195032839)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.727--ClientSession(1332897233)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6356bbf] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.727--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1405695929 [EL Finer]: transaction: 2016-03-14 21:54:48.727--ClientSession(1405695929)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1832411590 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@5793b154] [EL Finer]: transaction: 2016-03-14 21:54:48.727--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.727--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.727--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.727--ServerSession(917847816)--Connection(2052477066)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.727--ClientSession(1405695929)--Connection(2052477066)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.727--ClientSession(1405695929)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.727--ClientSession(1405695929)--Connection(1622725766)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6356bbf] [EL Finer]: transaction: 2016-03-14 21:54:48.728--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.729--ClientSession(1405695929)--Connection(1622725766)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.729--ServerSession(917847816)--Connection(2052477066)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.729--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.729--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@6356bbf] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.729--UnitOfWork(1832411590)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.729--ClientSession(1405695929)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4c697c83] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.729--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1783864684 [EL Finer]: transaction: 2016-03-14 21:54:48.729--ClientSession(1783864684)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 557860799 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@38dec286] [EL Finer]: transaction: 2016-03-14 21:54:48.729--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.73--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.73--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.73--ServerSession(917847816)--Connection(1070869626)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.73--ClientSession(1783864684)--Connection(1070869626)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.73--ClientSession(1783864684)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.73--ClientSession(1783864684)--Connection(1226472977)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4c697c83] [EL Finer]: transaction: 2016-03-14 21:54:48.73--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.731--ClientSession(1783864684)--Connection(1226472977)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.731--ServerSession(917847816)--Connection(1070869626)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.731--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.731--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@4c697c83] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.731--UnitOfWork(557860799)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.731--ClientSession(1783864684)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaSystemScopeRepository.getByValue]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3a69cf00] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.731--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 546948266 [EL Finer]: transaction: 2016-03-14 21:54:48.731--ClientSession(546948266)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1866139838 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@4fdb3527] [EL Finer]: transaction: 2016-03-14 21:54:48.731--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.731--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.731--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ReadAllQuery(name="SystemScope.getByValue" referenceClass=SystemScope sql="SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?)") [EL Finest]: connection: 2016-03-14 21:54:48.731--ServerSession(917847816)--Connection(993976851)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.731--ClientSession(546948266)--Connection(993976851)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.731--ClientSession(546948266)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.732--ClientSession(546948266)--Connection(1441586506)--Thread(Thread[qtp1465126864-14,5,main])--SELECT id, default_scope, description, icon, restricted, structured, structured_param_description, scope FROM system_scope WHERE (scope = ?) bind => [profile] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3a69cf00] [EL Finer]: transaction: 2016-03-14 21:54:48.733--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.733--ClientSession(546948266)--Connection(1441586506)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.733--ServerSession(917847816)--Connection(993976851)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.733--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.733--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3a69cf00] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.733--UnitOfWork(1866139838)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.733--ClientSession(546948266)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.openid.connect.service.impl.DefaultApprovedSiteService.createApprovedSite]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3823782e] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.733--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 194442477 [EL Finer]: transaction: 2016-03-14 21:54:48.733--ClientSession(194442477)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 1140229351 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@3edc810c] DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3823782e] for JPA transaction DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Participating in existing transaction [EL Finest]: transaction: 2016-03-14 21:54:48.733--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Merge clone with references org.mitre.openid.connect.model.ApprovedSite@1d1d6cf1 [EL Finer]: transaction: 2016-03-14 21:54:48.735--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.735--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Execute query InsertObjectQuery(org.mitre.openid.connect.model.ApprovedSite@5636ab5a) [EL Finest]: connection: 2016-03-14 21:54:48.735--ServerSession(917847816)--Connection(754951496)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.735--ClientSession(194442477)--Connection(754951496)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.735--ClientSession(194442477)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.735--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--INSERT INTO approved_site (access_date, client_id, creation_date, timeout_date, user_id) VALUES (?, ?, ?, ?, ?) bind => [null, null, null, null, null] [EL Finest]: query: 2016-03-14 21:54:48.736--ClientSession(194442477)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ValueReadQuery(name="SEQ_GEN_IDENTITY" sql="select lastval()") [EL Fine]: sql: 2016-03-14 21:54:48.736--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--select lastval() [EL Finest]: sequencing: 2016-03-14 21:54:48.736--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--assign sequence to the object (2 -> org.mitre.openid.connect.model.ApprovedSite@5636ab5a) [EL Finer]: transaction: 2016-03-14 21:54:48.737--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.737--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Found thread-bound EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3823782e] for JPA transaction DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Participating in existing transaction [EL Finest]: transaction: 2016-03-14 21:54:48.737--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Merge clone with references org.mitre.openid.connect.model.ApprovedSite@5636ab5a [EL Finer]: transaction: 2016-03-14 21:54:48.737--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.738--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Execute query UpdateObjectQuery(org.mitre.openid.connect.model.ApprovedSite@5636ab5a) [EL Fine]: sql: 2016-03-14 21:54:48.738--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--UPDATE approved_site SET access_date = ?, client_id = ?, creation_date = ?, user_id = ? WHERE (id = ?) bind => [2016-03-14 21:54:48.737, client, 2016-03-14 21:54:48.737, {sub=90342.ASDFJWFA, iss=https://mitreid.org/}, 2] [EL Finest]: query: 2016-03-14 21:54:48.739--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DataModifyQuery(sql="INSERT INTO approved_site_scope (owner_id, scope) VALUES (?, ?)") [EL Fine]: sql: 2016-03-14 21:54:48.739--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--INSERT INTO approved_site_scope (owner_id, scope) VALUES (?, ?) bind => [2, openid] [EL Finest]: query: 2016-03-14 21:54:48.739--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--Execute query DataModifyQuery(sql="INSERT INTO approved_site_scope (owner_id, scope) VALUES (?, ?)") [EL Fine]: sql: 2016-03-14 21:54:48.739--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--INSERT INTO approved_site_scope (owner_id, scope) VALUES (?, ?) bind => [2, profile] [EL Finer]: transaction: 2016-03-14 21:54:48.74--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work flush [EL Finer]: transaction: 2016-03-14 21:54:48.74--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction commit DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Committing JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3823782e] [EL Finer]: transaction: 2016-03-14 21:54:48.74--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.74--ClientSession(194442477)--Connection(1742530340)--Thread(Thread[qtp1465126864-14,5,main])--commit transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.747--ServerSession(917847816)--Connection(754951496)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.747--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--end unit of work commit [EL Finer]: transaction: 2016-03-14 21:54:48.747--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--resume unit of work DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@3823782e] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager [EL Finer]: transaction: 2016-03-14 21:54:48.747--UnitOfWork(1140229351)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: connection: 2016-03-14 21:54:48.747--ClientSession(194442477)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Creating new transaction with name [org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; 'defaultTransactionManager' DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Opened new EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@67bd71dc] for JPA transaction [EL Finer]: connection: 2016-03-14 21:54:48.748--ServerSession(917847816)--Thread(Thread[qtp1465126864-14,5,main])--client acquired: 1785181260 [EL Finer]: transaction: 2016-03-14 21:54:48.748--ClientSession(1785181260)--Thread(Thread[qtp1465126864-14,5,main])--acquire unit of work: 610310615 DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.EclipseLinkJpaDialect$EclipseLinkConnectionHandle@6cda2d0c] [EL Finest]: transaction: 2016-03-14 21:54:48.748--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--Merge clone with references org.mitre.oauth2.model.AuthenticationHolderEntity@606592da [EL Finer]: transaction: 2016-03-14 21:54:48.748--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--begin unit of work flush [EL Finest]: query: 2016-03-14 21:54:48.749--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--Execute query InsertObjectQuery(org.mitre.oauth2.model.SavedUserAuthentication@66c94f2e) [EL Finest]: connection: 2016-03-14 21:54:48.749--ServerSession(917847816)--Connection(396532690)--Thread(Thread[qtp1465126864-14,5,main])--Connection acquired from connection pool [default]. [EL Finer]: transaction: 2016-03-14 21:54:48.749--ClientSession(1785181260)--Connection(396532690)--Thread(Thread[qtp1465126864-14,5,main])--begin transaction [EL Finest]: connection: 2016-03-14 21:54:48.749--ClientSession(1785181260)--Thread(Thread[qtp1465126864-14,5,main])--reconnecting to external connection pool [EL Fine]: sql: 2016-03-14 21:54:48.749--ClientSession(1785181260)--Connection(2073687808)--Thread(Thread[qtp1465126864-14,5,main])--INSERT INTO saved_user_auth (authenticated, name, source_class) VALUES (?, ?, ?) bind => [true, {sub=90342.ASDFJWFA, iss=https://mitreid.org/}, org.mitre.openid.connect.model.OIDCAuthenticationToken] [EL Finest]: query: 2016-03-14 21:54:48.75--ClientSession(1785181260)--Thread(Thread[qtp1465126864-14,5,main])--Execute query ValueReadQuery(name="SEQ_GEN_IDENTITY" sql="select lastval()") [EL Fine]: sql: 2016-03-14 21:54:48.75--ClientSession(1785181260)--Connection(2073687808)--Thread(Thread[qtp1465126864-14,5,main])--select lastval() [EL Finest]: sequencing: 2016-03-14 21:54:48.75--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--assign sequence to the object (2 -> org.mitre.oauth2.model.SavedUserAuthentication@66c94f2e) [EL Warning]: 2016-03-14 21:54:48.751--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:138) at org.eclipse.persistence.mappings.DirectCollectionMapping.postInsert(DirectCollectionMapping.java:2216) at org.eclipse.persistence.descriptors.DescriptorQueryManager.postInsert(DescriptorQueryManager.java:999) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:498) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:798) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1793) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1775) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1726) at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsForClassWithChangeSet(CommitManager.java:193) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:138) at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4196) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1441) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1587) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:452) at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:863) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:291) at com.sun.proxy.$Proxy44.flush(Unknown Source) at org.mitre.util.jpa.JpaUtil.saveOrUpdate(JpaUtil.java:42) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository.save(JpaAuthenticationHolderRepository.java:65) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$FastClassBySpringCGLIB$$b0f655b9.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$EnhancerBySpringCGLIB$$97847c7d.save() at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService.createAuthorizationCode(DefaultOAuth2AuthorizationCodeService.java:75) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$FastClassBySpringCGLIB$$d4e7d2fc.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:649) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$EnhancerBySpringCGLIB$$62984c60.createAuthorizationCode() at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.generateCode(AuthorizationEndpoint.java:345) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.getAuthorizationCodeResponse(AuthorizationEndpoint.java:279) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(AuthorizationEndpoint.java:232) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:869) at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:835) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1685) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:105) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:57) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.mitre.openid.connect.filter.AuthorizationRequestFilter.doFilter(AuthorizationRequestFilter.java:223) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:517) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.ClassCastException: org.mitre.openid.connect.client.SubjectIssuerGrantedAuthority cannot be cast to org.springframework.security.core.authority.SimpleGrantedAuthority at org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter.convertToDatabaseColumn(SimpleGrantedAuthorityStringConverter.java:29) at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:136) ... 127 more

[EL Warning]: 2016-03-14 21:54:48.752--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:138) at org.eclipse.persistence.mappings.DirectCollectionMapping.postInsert(DirectCollectionMapping.java:2216) at org.eclipse.persistence.descriptors.DescriptorQueryManager.postInsert(DescriptorQueryManager.java:999) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:498) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:798) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1793) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1775) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1726) at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsForClassWithChangeSet(CommitManager.java:193) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:138) at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4196) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1441) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1587) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:452) at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:863) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:291) at com.sun.proxy.$Proxy44.flush(Unknown Source) at org.mitre.util.jpa.JpaUtil.saveOrUpdate(JpaUtil.java:42) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository.save(JpaAuthenticationHolderRepository.java:65) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$FastClassBySpringCGLIB$$b0f655b9.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$EnhancerBySpringCGLIB$$97847c7d.save() at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService.createAuthorizationCode(DefaultOAuth2AuthorizationCodeService.java:75) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$FastClassBySpringCGLIB$$d4e7d2fc.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:649) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$EnhancerBySpringCGLIB$$62984c60.createAuthorizationCode() at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.generateCode(AuthorizationEndpoint.java:345) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.getAuthorizationCodeResponse(AuthorizationEndpoint.java:279) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(AuthorizationEndpoint.java:232) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:869) at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:835) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1685) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:105) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:57) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.mitre.openid.connect.filter.AuthorizationRequestFilter.doFilter(AuthorizationRequestFilter.java:223) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:517) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.ClassCastException: org.mitre.openid.connect.client.SubjectIssuerGrantedAuthority cannot be cast to org.springframework.security.core.authority.SimpleGrantedAuthority at org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter.convertToDatabaseColumn(SimpleGrantedAuthorityStringConverter.java:29) at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:136) ... 127 more

DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Initiating transaction rollback DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Rolling back JPA transaction on EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@67bd71dc] [EL Finer]: transaction: 2016-03-14 21:54:48.752--UnitOfWork(610310615)--Thread(Thread[qtp1465126864-14,5,main])--release unit of work [EL Finer]: transaction: 2016-03-14 21:54:48.752--ClientSession(1785181260)--Connection(2073687808)--Thread(Thread[qtp1465126864-14,5,main])--rollback transaction DEBUG: com.zaxxer.hikari.pool.PoolElf - HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@559a3d95 [EL Finest]: connection: 2016-03-14 21:54:48.752--ServerSession(917847816)--Connection(396532690)--Thread(Thread[qtp1465126864-14,5,main])--Connection released to connection pool [default]. [EL Finer]: connection: 2016-03-14 21:54:48.752--ClientSession(1785181260)--Thread(Thread[qtp1465126864-14,5,main])--client released DEBUG: org.springframework.orm.jpa.JpaTransactionManager - Closing JPA EntityManager [org.eclipse.persistence.internal.jpa.EntityManagerImpl@67bd71dc] after transaction DEBUG: org.springframework.orm.jpa.EntityManagerFactoryUtils - Closing JPA EntityManager DEBUG: org.springframework.web.servlet.mvc.method.annotation.ExceptionHandlerExceptionResolver - Resolving exception from handler [public org.springframework.web.servlet.View org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(java.util.Map<java.lang.String, java.lang.String>,java.util.Map<java.lang.String, ?>,org.springframework.web.bind.support.SessionStatus,java.security.Principal)]: javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ DEBUG: org.springframework.web.servlet.mvc.annotation.ResponseStatusExceptionResolver - Resolving exception from handler [public org.springframework.web.servlet.View org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(java.util.Map<java.lang.String, java.lang.String>,java.util.Map<java.lang.String, ?>,org.springframework.web.bind.support.SessionStatus,java.security.Principal)]: javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ DEBUG: org.springframework.web.servlet.mvc.support.DefaultHandlerExceptionResolver - Resolving exception from handler [public org.springframework.web.servlet.View org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(java.util.Map<java.lang.String, java.lang.String>,java.util.Map<java.lang.String, ?>,org.springframework.web.bind.support.SessionStatus,java.security.Principal)]: javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ DEBUG: org.springframework.web.servlet.DispatcherServlet - Could not complete request javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:138) at org.eclipse.persistence.mappings.DirectCollectionMapping.postInsert(DirectCollectionMapping.java:2216) at org.eclipse.persistence.descriptors.DescriptorQueryManager.postInsert(DescriptorQueryManager.java:999) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:498) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:798) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1793) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1775) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1726) at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsForClassWithChangeSet(CommitManager.java:193) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:138) at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4196) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1441) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1587) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:452) at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:863) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:291) at com.sun.proxy.$Proxy44.flush(Unknown Source) at org.mitre.util.jpa.JpaUtil.saveOrUpdate(JpaUtil.java:42) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository.save(JpaAuthenticationHolderRepository.java:65) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$FastClassBySpringCGLIB$$b0f655b9.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$EnhancerBySpringCGLIB$$97847c7d.save() at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService.createAuthorizationCode(DefaultOAuth2AuthorizationCodeService.java:75) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$FastClassBySpringCGLIB$$d4e7d2fc.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:649) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$EnhancerBySpringCGLIB$$62984c60.createAuthorizationCode() at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.generateCode(AuthorizationEndpoint.java:345) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.getAuthorizationCodeResponse(AuthorizationEndpoint.java:279) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(AuthorizationEndpoint.java:232) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:869) at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:835) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1685) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:105) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:57) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.mitre.openid.connect.filter.AuthorizationRequestFilter.doFilter(AuthorizationRequestFilter.java:223) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:517) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.ClassCastException: org.mitre.openid.connect.client.SubjectIssuerGrantedAuthority cannot be cast to org.springframework.security.core.authority.SimpleGrantedAuthority at org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter.convertToDatabaseColumn(SimpleGrantedAuthorityStringConverter.java:29) at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:136) ... 127 more DEBUG: org.springframework.security.web.context.SecurityContextPersistenceFilter - SecurityContextHolder now cleared, as request processing completed [WARNING] org.springframework.web.util.NestedServletException: Request processing failed; nested exception is javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:979) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:869) at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:835) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1685) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:105) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:57) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.mitre.openid.connect.filter.AuthorizationRequestFilter.doFilter(AuthorizationRequestFilter.java:223) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:517) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) at java.lang.Thread.run(Thread.java:745) Caused by: javax.persistence.PersistenceException: An exception occurred while calling convertToDatabaseColumn on converter class org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter with value OIDC_90342.ASDFJWFA_https://mitreid.org/ at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:138) at org.eclipse.persistence.mappings.DirectCollectionMapping.postInsert(DirectCollectionMapping.java:2216) at org.eclipse.persistence.descriptors.DescriptorQueryManager.postInsert(DescriptorQueryManager.java:999) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:498) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:80) at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:90) at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:301) at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:58) at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899) at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:798) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:108) at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:85) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2896) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1793) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1775) at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1726) at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:226) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsForClassWithChangeSet(CommitManager.java:193) at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:138) at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4196) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1441) at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithPreBuiltChangeSet(UnitOfWorkImpl.java:1587) at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.writeChanges(RepeatableWriteUnitOfWork.java:452) at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:863) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:291) at com.sun.proxy.$Proxy44.flush(Unknown Source) at org.mitre.util.jpa.JpaUtil.saveOrUpdate(JpaUtil.java:42) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository.save(JpaAuthenticationHolderRepository.java:65) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$FastClassBySpringCGLIB$$b0f655b9.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) at org.mitre.oauth2.repository.impl.JpaAuthenticationHolderRepository$$EnhancerBySpringCGLIB$$97847c7d.save() at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService.createAuthorizationCode(DefaultOAuth2AuthorizationCodeService.java:75) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$FastClassBySpringCGLIB$$d4e7d2fc.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:649) at org.mitre.oauth2.service.impl.DefaultOAuth2AuthorizationCodeService$$EnhancerBySpringCGLIB$$62984c60.createAuthorizationCode() at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.generateCode(AuthorizationEndpoint.java:345) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.getAuthorizationCodeResponse(AuthorizationEndpoint.java:279) at org.springframework.security.oauth2.provider.endpoint.AuthorizationEndpoint.approveOrDeny(AuthorizationEndpoint.java:232) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967) ... 65 more Caused by: java.lang.ClassCastException: org.mitre.openid.connect.client.SubjectIssuerGrantedAuthority cannot be cast to org.springframework.security.core.authority.SimpleGrantedAuthority at org.mitre.oauth2.model.convert.SimpleGrantedAuthorityStringConverter.convertToDatabaseColumn(SimpleGrantedAuthorityStringConverter.java:29) at org.eclipse.persistence.mappings.converters.ConverterClass.convertObjectValueToDataValue(ConverterClass.java:136) ... 127 more

mobilars commented 8 years ago

And here is the spring file that I guess is wrong somehow:

<?xml version="1.0" encoding="UTF-8"?>