By: Jay Kumar user 07 Nov 2017 at 11:55 a.m. CST

5 Responses
Jay Kumar gravatar
Hi I've setup oxd_server on my localhost and trying to get token by code using the oxd-php-api protocolTest/Get_tokens_by_code_test.php I'm getting an error i.e. "internal_error : Unknown internal server error occurs." Below is the **oxauth.log** 2017-11-07 11:14:58,318 INFO [qtp2008017533-14] [org.xdi.oxauth.service.ApplicationFactory] (ApplicationFactory.java:59) - Cache configuration: CacheConfiguration{cacheProviderType=IN_MEMORY, memcachedConfiguration=MemcachedConfiguration{servers='localhost:11211', maxOperationQueueLength=100000, bufferSize=32768, defaultPutExpiration=60, connectionFactoryType=DEFAULT}, redisConfiguration=RedisConfiguration{servers='localhost:6379', defaultPutExpiration=60, redisProviderType=STANDALONE}, inMemoryConfiguration=InMemoryConfiguration{defaultPutExpiration=60}} 2017-11-07 11:15:16,000 ERROR [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:409) - Failed to update oxLastLogonTime of user 'admin' 2017-11-07 11:15:16,002 INFO [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:514) - Attempting to redirect user: SessionUser: SessionState {dn='oxAuthSessionId=d31943aa-49f3-4f3f-8975-b672839aaa4e,ou=session,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', id='d31943aa-49f3-4f3f-8975-b672839aaa4e', lastUsedAt=Tue Nov 07 11:15:16 UTC 2017, userDn='inum=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0000!A8F2.DE1E.D7FB,ou=people,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', authenticationTime=Tue Nov 07 11:15:16 UTC 2017, state=authenticated, sessionState='bff86549-68b0-4808-930d-0f043841be75', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@5b9c57c, involvedClients=null, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=182.156.245.130, 172.23.65.80, scope=openid profile email user_name, acr_values=auth_ldap_server, response_type=code id_token, redirect_uri=https://dev-sso.taoconnect.org/identity/authentication/authcode, nonce=8cc0aecd-5f12-4c83-9444-449a1c1c84a8, client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443}, persisted=true} 2017-11-07 11:15:16,004 INFO [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:522) - Attempting to redirect user: User: org.xdi.oxauth.model.common.User@30410a25 2017-11-07 11:15:16,006 INFO [qtp2008017533-12] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:342) - Authentication success for User: 'admin' 2017-11-07 11:15:18,780 INFO [qtp2008017533-10] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443' 2017-11-07 11:58:53,541 ERROR [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:409) - Failed to update oxLastLogonTime of user 'jayK' 2017-11-07 11:58:53,547 INFO [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:514) - Attempting to redirect user: SessionUser: SessionState {dn='oxAuthSessionId=1a3d1b90-518f-42bc-8aec-2854eb21f71d,ou=session,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', id='1a3d1b90-518f-42bc-8aec-2854eb21f71d', lastUsedAt=Tue Nov 07 11:58:53 UTC 2017, userDn='inum=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0000!515E.C8CF.5A1A.1905,ou=people,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', authenticationTime=Tue Nov 07 11:58:53 UTC 2017, state=authenticated, sessionState='8be2a054-ddc7-43c5-9e36-3c2cce6cd8f0', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@58184e72, involvedClients=null, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=182.156.245.130, 172.23.65.80, scope=openid profile email uma_protection uma_authorization, response_type=code, redirect_uri=https://client.local/logged_in.php, state=uhc1u46q9m4qiqnmho0bs1eu71, nonce=75me4m95b7l5q7inhac0tpnr9q, client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9}, persisted=true} 2017-11-07 11:58:53,550 INFO [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:522) - Attempting to redirect user: User: org.xdi.oxauth.model.common.User@c2ad0c9 2017-11-07 11:58:53,551 INFO [qtp2008017533-10] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:342) - Authentication success for User: 'jayk' 2017-11-07 12:24:25,112 INFO [qtp2008017533-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9' 2017-11-07 12:45:40,060 INFO [qtp2008017533-12] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443' 2017-11-07 12:49:15,753 INFO [qtp2008017533-11] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:222) - Basic authentication failed java.lang.Exception: The Token Authentication Method is not valid. at org.xdi.oxauth.auth.AuthenticationFilter.processBasicAuth(AuthenticationFilter.java:199) [classes/:?] at org.xdi.oxauth.auth.AuthenticationFilter.doFilter(AuthenticationFilter.java:102) [classes/:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.gluu.oxserver.filters.AbstractCorsFilter.handleNonCORS(AbstractCorsFilter.java:343) [oxcore-server-3.1.1.Final.jar:?] at org.gluu.oxserver.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:120) [oxcore-server-3.1.1.Final.jar:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [jetty-security-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.Server.handle(Server.java:534) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112] 2017-11-07 13:13:07,050 ERROR [qtp2008017533-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:308) - Failed to authenticate dn: inum=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0000!515E.C8CF.5A1A.1905,ou=people,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu 2017-11-07 13:13:07,051 INFO [qtp2008017533-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:152) - Authentication failed for 'jayk' 2017-11-07 13:13:18,758 ERROR [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:409) - Failed to update oxLastLogonTime of user 'jayK' 2017-11-07 13:13:18,759 INFO [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:514) - Attempting to redirect user: SessionUser: SessionState {dn='oxAuthSessionId=f9808b99-9ed8-4bf3-8cd0-bdf56bfe97c2,ou=session,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', id='f9808b99-9ed8-4bf3-8cd0-bdf56bfe97c2', lastUsedAt=Tue Nov 07 13:13:18 UTC 2017, userDn='inum=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0000!515E.C8CF.5A1A.1905,ou=people,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', authenticationTime=Tue Nov 07 13:13:18 UTC 2017, state=authenticated, sessionState='0c3e9a12-875f-4fb4-8923-83ac928feeee', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@196f4147, involvedClients=null, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=182.156.245.130, 172.23.65.80, scope=openid profile email uma_protection uma_authorization, response_type=code, redirect_uri=https://client.local/logged_in.php, state=u0o6enpnq9qa3fg5dke9acm5f4, nonce=mgse9g0vucbro8stiapaeg312m, client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9}, persisted=true} 2017-11-07 13:13:18,760 INFO [qtp2008017533-12] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:522) - Attempting to redirect user: User: org.xdi.oxauth.model.common.User@118abfc6 2017-11-07 13:13:18,761 INFO [qtp2008017533-12] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:342) - Authentication success for User: 'jayk' 2017-11-07 13:14:07,506 INFO [qtp2008017533-13] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:222) - Basic authentication failed java.lang.Exception: The Token Authentication Method is not valid. at org.xdi.oxauth.auth.AuthenticationFilter.processBasicAuth(AuthenticationFilter.java:199) [classes/:?] at org.xdi.oxauth.auth.AuthenticationFilter.doFilter(AuthenticationFilter.java:102) [classes/:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.gluu.oxserver.filters.AbstractCorsFilter.handleNonCORS(AbstractCorsFilter.java:343) [oxcore-server-3.1.1.Final.jar:?] at org.gluu.oxserver.filters.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:120) [oxcore-server-3.1.1.Final.jar:?] at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [jetty-security-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [jetty-servlet-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.Server.handle(Server.java:534) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [jetty-server-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [jetty-io-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [jetty-util-9.3.15.v20161220.jar:9.3.15.v20161220] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_112] 2017-11-07 13:18:45,279 INFO [qtp2008017533-10] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443' 2017-11-07 16:28:10,248 INFO [qtp2008017533-10] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443' 2017-11-07 16:58:28,314 INFO [qtp2008017533-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!0245.3443' 2017-11-07 17:00:01,166 ERROR [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:409) - Failed to update oxLastLogonTime of user 'jayK' 2017-11-07 17:00:01,166 INFO [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:514) - Attempting to redirect user: SessionUser: SessionState {dn='oxAuthSessionId=2e966912-e388-4175-b58f-f1b7a16a95a2,ou=session,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', id='2e966912-e388-4175-b58f-f1b7a16a95a2', lastUsedAt=Tue Nov 07 17:00:01 UTC 2017, userDn='inum=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0000!515E.C8CF.5A1A.1905,ou=people,o=@!2C74.3037.CC47.59B1!0001!39EA.4A64,o=gluu', authenticationTime=Tue Nov 07 17:00:01 UTC 2017, state=authenticated, sessionState='49010ecb-0ef7-4846-9ddf-2c00d7379067', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@5102f0dc, involvedClients=null, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=182.156.245.130, 172.23.65.80, scope=openid profile email uma_protection uma_authorization, response_type=code, redirect_uri=https://client.local/logged_in.php, state=qifn42s6kitrft9nh2h8j7hvas, nonce=jh42e85o8d46mk0700v1ln34en, client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9}, persisted=true} 2017-11-07 17:00:01,167 INFO [qtp2008017533-10] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:522) - Attempting to redirect user: User: org.xdi.oxauth.model.common.User@1a874a7d 2017-11-07 17:00:01,168 INFO [qtp2008017533-10] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:342) - Authentication success for User: 'jayk' 2017-11-07 17:02:01,214 INFO [qtp2008017533-11] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication success for Client: '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9' 2017-11-07 17:06:04,872 INFO [qtp2008017533-19] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:152) - Authentication failed for '@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9' Please help me on this.

By William Lowe user 07 Nov 2017 at 11:56 a.m. CST

William Lowe gravatar
Which version of oxd?

By Jay Kumar user 07 Nov 2017 at 12:04 p.m. CST

Jay Kumar gravatar
It is oxd-server-3.0.1-distribution

By Jajati Badu Account Admin 07 Nov 2017 at 12:45 p.m. CST

Jajati Badu gravatar
Hi Jay, The logs you have shared are oxAuth log. Please share oxd-server log. Thanks, Jajati

By Jay Kumar user 08 Nov 2017 at 5:24 a.m. CST

Jay Kumar gravatar
Hey Jajati, oxd-server log is here. Please look into this. 2017-11-08 16:48:50,296 INFO [org.xdi.oxd.server.ServerLauncher] Starting... 2017-11-08 16:48:50,298 INFO [org.xdi.oxd.server.ServerLauncher] commit: 0eda70e831db6c16919ee7cbee4aa90a5fbeb6fa, branch: origin/version_3.0.1, build time:24.02.2017 @ 08:50:18 EST 2017-11-08 16:48:50,673 TRACE [org.xdi.oxd.server.service.ConfigurationService] Try to load configuration from system property: oxd.server.config, value: ../conf/oxd-conf.json 2017-11-08 16:48:50,895 TRACE [org.xdi.oxd.server.service.ConfigurationService] Configuration loaded successfully from system property: oxd.server.config. 2017-11-08 16:48:50,896 TRACE [org.xdi.oxd.server.service.ConfigurationService] Configuration: Configuration{port=8099, timeOutInSeconds=0, jettyPort=0, startJetty=false, localhostOnly=true, useClientAuthenticationForPat=true, useClientAuthenticationForAat=true, trustAllCerts=true, keyStorePath='', keyStorePassword='', licenseId='3602e5a9-cbfa-40dd-9684-714f4fde28db', publicKey='bmSRjhSP5gDnurmCj6gRBjXJi4Z+rYev99JYluidPePArj4Ai7duacjUwLCpYzQcOfvSc30CLudmGwX4BAl/I/XnW+oEHN9gbn7ogXPhdMAL7tXHsSv1E2iylnfYlFW9SnUoJFnVvTmcyuTt8a9radaXACtSKGYnXt7j2zLddNr+VuUL3p4OkwKTYQ7W1lh5Uru6PYRckkO/MOg3CiWjQweTljCsQIu+S4kv/mi/+eBBmOK8rYxZF7BhEhZJXQ39YU0P/rgTf+1Q4lz4200FN4znNOq2BRU1W2ziA5UfZX2UTApAa+IN52izHxTRsbcHlZxC1Xjf1BMPVntG8wjXvFRbQuavf+IX8i90fzopQr4gn59h+CFqKR9fYg+CmNZR9oI4trOz6S0YteH2CUNGqA==', publicPassword='i4YuEYhwrHHnInkIBzT3', licensePassword='cCrZa6GQ6ZtHdCunp595', supportGoogleLogout='true', stateExpirationInMinutes='5', nonceExpirationInMinutes='5'} 2017-11-08 16:48:51,060 ERROR [org.xdi.oxd.server.service.ConfigurationService] String index out of range: -1 java.lang.StringIndexOutOfBoundsException: String index out of range: -1 at java.lang.String.substring(Unknown Source) at org.xdi.oxd.server.service.ConfigurationService.getConfDirectoryPath(ConfigurationService.java:57) at org.xdi.oxd.server.service.ConfigurationService.getConfDirectoryFile(ConfigurationService.java:44) at org.xdi.oxd.server.service.SiteConfigurationService.load(SiteConfigurationService.java:61) at org.xdi.oxd.server.ServerLauncher.startOxd(ServerLauncher.java:84) at org.xdi.oxd.server.ServerLauncher.start(ServerLauncher.java:62) at org.xdi.oxd.server.ServerLauncher.main(ServerLauncher.java:51) 2017-11-08 16:48:51,064 INFO [org.xdi.oxd.server.service.ConfigurationService] Configuration directory: D:\xampp\htdocs\oxd_server\bin\..\conf 2017-11-08 16:48:51,069 TRACE [org.xdi.oxd.server.service.SiteConfigurationService] Loading site file name: 1937b567-3cdd-4cd2-9aa3-be9e73aadaa8.json 2017-11-08 16:48:51,196 TRACE [org.xdi.oxd.server.service.SiteConfigurationService] Loading site file name: 2dbf8e11-044e-41a3-8b24-85c99ac2c548.json 2017-11-08 16:48:51,207 TRACE [org.xdi.oxd.server.service.SiteConfigurationService] Loading site file name: 55ea476c-0af4-410c-80e6-e122cb5dfc59.json 2017-11-08 16:48:51,211 TRACE [org.xdi.oxd.server.service.SiteConfigurationService] Loading site file name: 7fa5fd9b-5473-4b10-9797-9c21cc69b034.json 2017-11-08 16:48:51,217 TRACE [org.xdi.oxd.server.service.SiteConfigurationService] Loading site file name: oxd-default-site-config.json 2017-11-08 16:48:51,221 DEBUG [org.xdi.oxd.server.license.LicenseFile] License file location: D:\xampp\htdocs\oxd_server\bin\.oxd-license 2017-11-08 16:48:51,230 TRACE [org.xdi.oxd.server.license.LicenseFile] MAC ADDRESS set to : 70-71-BC-5B-A1-52 2017-11-08 16:48:51,231 TRACE [org.xdi.oxd.server.license.LicenseService] Validating license ... 2017-11-08 16:48:51,231 DEBUG [org.xdi.oxd.server.license.LicenseFile] License file location: D:\xampp\htdocs\oxd_server\bin\.oxd-license 2017-11-08 16:48:51,234 TRACE [org.xdi.oxd.server.license.LicenseFile] MAC ADDRESS set to : 70-71-BC-5B-A1-52 2017-11-08 16:48:51,266 TRACE [org.xdi.oxd.server.service.HttpService] Created TRUST_ALL client. 2017-11-08 16:48:55,228 TRACE [org.xdi.oxd.server.license.LicenseService] License is validated successfully. 2017-11-08 16:48:55,235 TRACE [org.xdi.oxd.server.license.LicenseService] License data: LicenseMetadata{creationDate=Tue Oct 31 20:13:21 IST 2017, licenseId=null, autoupdate=true, active=true, product=oxd, licenseName='Jay Kumar', expirationDate=Wed Oct 31 20:13:21 IST 2018, licenseCountLimit=9999, customerName=Jay Kumar, emails=[]} 2017-11-08 16:48:55,239 TRACE [org.xdi.oxd.server.license.LicenseService] Validating license ... 2017-11-08 16:48:55,239 DEBUG [org.xdi.oxd.server.license.LicenseFile] License file location: D:\xampp\htdocs\oxd_server\bin\.oxd-license 2017-11-08 16:48:55,240 TRACE [org.xdi.oxd.server.license.LicenseFile] MAC ADDRESS set to : 70-71-BC-5B-A1-52 2017-11-08 16:48:55,240 TRACE [org.xdi.oxd.server.service.HttpService] Created TRUST_ALL client. 2017-11-08 16:48:56,485 TRACE [org.xdi.oxd.server.license.LicenseService] License is validated successfully. 2017-11-08 16:48:56,485 TRACE [org.xdi.oxd.server.license.LicenseService] License data: LicenseMetadata{creationDate=Tue Oct 31 20:13:21 IST 2017, licenseId=null, autoupdate=true, active=true, product=oxd, licenseName='Jay Kumar', expirationDate=Wed Oct 31 20:13:21 IST 2018, licenseCountLimit=9999, customerName=Jay Kumar, emails=[]} 2017-11-08 16:48:56,488 ERROR [org.xdi.oxd.server.service.SocketService] Could not listen on port: 8099. 2017-11-08 16:48:56,488 ERROR [org.xdi.oxd.server.ServerLauncher] Failed to start oxd server. java.net.BindException: Address already in use: JVM_Bind at java.net.DualStackPlainSocketImpl.bind0(Native Method) at java.net.DualStackPlainSocketImpl.socketBind(Unknown Source) at java.net.AbstractPlainSocketImpl.bind(Unknown Source) at java.net.PlainSocketImpl.bind(Unknown Source) at java.net.ServerSocket.bind(Unknown Source) at java.net.ServerSocket.<init>(Unknown Source) at org.xdi.oxd.server.service.SocketService.listenSocket(SocketService.java:71) at org.xdi.oxd.server.ServerLauncher.startOxd(ServerLauncher.java:85) at org.xdi.oxd.server.ServerLauncher.start(ServerLauncher.java:62) at org.xdi.oxd.server.ServerLauncher.main(ServerLauncher.java:51) 2017-11-08 16:48:59,821 DEBUG [org.xdi.oxd.server.service.SocketService] Start new SocketProcessor... 2017-11-08 16:48:59,828 TRACE [org.xdi.oxd.server.SocketProcessor] Socket processor handling... 2017-11-08 16:48:59,828 TRACE [org.xdi.oxd.common.CoreUtils] commandSize: -1, stringStorage: 2017-11-08 16:48:59,832 TRACE [org.xdi.oxd.common.CoreUtils] Parsed sizeString: 0299, commandSize: 299 2017-11-08 16:48:59,832 TRACE [org.xdi.oxd.common.CoreUtils] Read result: ReadResult{m_command='{"command":"get_authorization_url","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","scope":["openid","profile","email","uma_protection","uma_authorization"],"acr_values":[""],"prompt":null,"hd":null,"custom_parameters":{"param1":"value1","param2":"value2"},"protection_access_token":null}}', m_leftString=''} 2017-11-08 16:48:59,832 TRACE [org.xdi.oxd.server.Processor] Command: {"command":"get_authorization_url","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","scope":["openid","profile","email","uma_protection","uma_authorization"],"acr_values":[""],"prompt":null,"hd":null,"custom_parameters":{"param1":"value1","param2":"value2"},"protection_access_token":null}} 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.server.Processor] Send back response: {"status":"ok","data":{"authorization_url":"https://dev-sso.taoconnect.org/oxauth/restv1/authorize?response_type=code&client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9&redirect_uri=https://client.local/logged_in.php&scope=openid+profile+email+uma_protection+uma_authorization&state=moh579mhnd5kbmi5c20l72922i&nonce=ntkdr9afuk7l1v8knfb0jtlgl8"}} 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.server.SocketProcessor] Socket processor handling... 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.common.CoreUtils] commandSize: -1, stringStorage: 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.common.CoreUtils] Parsed sizeString: 0299, commandSize: 299 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.common.CoreUtils] Read result: ReadResult{m_command='{"command":"get_authorization_url","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","scope":["openid","profile","email","uma_protection","uma_authorization"],"acr_values":[""],"prompt":null,"hd":null,"custom_parameters":{"param1":"value1","param2":"value2"},"protection_access_token":null}}', m_leftString=''} 2017-11-08 16:48:59,834 TRACE [org.xdi.oxd.server.Processor] Command: {"command":"get_authorization_url","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","scope":["openid","profile","email","uma_protection","uma_authorization"],"acr_values":[""],"prompt":null,"hd":null,"custom_parameters":{"param1":"value1","param2":"value2"},"protection_access_token":null}} 2017-11-08 16:48:59,836 TRACE [org.xdi.oxd.server.Processor] Send back response: {"status":"ok","data":{"authorization_url":"https://dev-sso.taoconnect.org/oxauth/restv1/authorize?response_type=code&client_id=@!2C74.3037.CC47.59B1!0001!39EA.4A64!0008!E6A1.EA30.20F5.1CC9&redirect_uri=https://client.local/logged_in.php&scope=openid+profile+email+uma_protection+uma_authorization&state=r38b40kn95ok4rlknjt09c8k7g&nonce=inkgtgqt4i5gllh5rbv531htrl"}} 2017-11-08 16:48:59,836 TRACE [org.xdi.oxd.server.SocketProcessor] Socket processor handling... 2017-11-08 16:48:59,836 TRACE [org.xdi.oxd.common.CoreUtils] commandSize: -1, stringStorage: 2017-11-08 16:48:59,836 ERROR [org.xdi.oxd.server.SocketProcessor] Software caused connection abort: recv failed java.net.SocketException: Software caused connection abort: recv failed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at sun.nio.cs.StreamDecoder.readBytes(Unknown Source) at sun.nio.cs.StreamDecoder.implRead(Unknown Source) at sun.nio.cs.StreamDecoder.read(Unknown Source) at java.io.InputStreamReader.read(Unknown Source) at java.io.BufferedReader.read1(Unknown Source) at java.io.BufferedReader.read(Unknown Source) at org.xdi.oxd.common.CoreUtils.readCommand(CoreUtils.java:171) at org.xdi.oxd.server.SocketProcessor.run(SocketProcessor.java:51) at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) 2017-11-08 16:50:10,354 DEBUG [org.xdi.oxd.server.service.SocketService] Start new SocketProcessor... 2017-11-08 16:50:10,356 TRACE [org.xdi.oxd.server.SocketProcessor] Socket processor handling... 2017-11-08 16:50:10,356 TRACE [org.xdi.oxd.common.CoreUtils] commandSize: -1, stringStorage: 2017-11-08 16:50:10,365 TRACE [org.xdi.oxd.common.CoreUtils] Parsed sizeString: 0174, commandSize: 174 2017-11-08 16:50:10,366 TRACE [org.xdi.oxd.common.CoreUtils] Read result: ReadResult{m_command='{"command":"get_tokens_by_code","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","code":"9839abfc-b3e4-4d45-b89d-be7f4b4a3e2c","state":"moh579mhnd5kbmi5c20l72922i"}}', m_leftString=''} 2017-11-08 16:50:10,366 TRACE [org.xdi.oxd.server.Processor] Command: {"command":"get_tokens_by_code","params":{"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","code":"9839abfc-b3e4-4d45-b89d-be7f4b4a3e2c","state":"moh579mhnd5kbmi5c20l72922i"}} 2017-11-08 16:50:10,366 TRACE [org.xdi.oxd.server.service.HttpService] Created TRUST_ALL client. 2017-11-08 16:50:12,109 ERROR [org.xdi.oxd.server.op.GetTokensByCodeOperation] Failed to get tokens because response code is: null 2017-11-08 16:50:12,117 ERROR [org.xdi.oxd.server.Processor] No response from operation. Command: Command{command=GET_TOKENS_BY_CODE, params={"oxd_id":"7fa5fd9b-5473-4b10-9797-9c21cc69b034","code":"9839abfc-b3e4-4d45-b89d-be7f4b4a3e2c","state":"moh579mhnd5kbmi5c20l72922i"}} 2017-11-08 16:50:12,124 TRACE [org.xdi.oxd.server.Processor] Send back response: {"status":"error","data":{"error":"internal_error","error_description":"Unknown internal server error occurs."}} 2017-11-08 16:50:12,130 ERROR [org.xdi.oxd.server.SocketProcessor] Quit. Enable to process command.

By Jajati Badu Account Admin 08 Nov 2017 at 5:42 a.m. CST

Jajati Badu gravatar
Hi Jay, From the log file, I can see oxd-server was not started successfully. Since you are using Gluu server 3.1.1 Could you please try using newly released [oxd 3.1.1](https://gluu.org/docs/oxd/3.1.1/install/#windows) Thanks, Jajati