APP (Glassfish4) looses connection to STS Host

[AndreasTWolf]

[Version]
V17.2.0

[Date]
2017/06/29

[Test category]
Production

[Description]
Frequently the Glassfish4 instance, where the APP is installed, looses the connection to the STS server when attempting to read the meta-data-exchange file.
Error: "WST0017:Could not obtain STS metadata. MEX call to STS https://Time.DarkSide.com/adfs/services/trust/mex/ failed"

This happend on installations running the MockUp -STS AND or on installations running ADFS. The Glassfish4 must be restarted to overcome this problem. Once the Glassfish4 is restarted the connection is reestablished at ADFS, on the STSMockup sometimes the PC must be rebooted.
This behavior happened on three different installations.
[Steps to reproduce]
Install CT-MG in SAML mode;
Install APP with Adapter;
Work with APP;
Wait; (we cannot say for sure whether just waiting (1-2 days) or frequent using kills the beast)
Crash;
[Expected result]
The connection between APP and CT-MG is never interrupted.
[Observed result]
The APP cannot call to the STS identity provider, thuis not authentication a call from APP to CT-MG
[Details]
See above;

[Messages and logs]
Server.log file from APP Glassfish:

[2017-06-29T15:47:23.633+0200] [glassfish 4.1] [INFO] [] [] [tid: _ThreadID=136 _ThreadName=Thread-8] [timeMillis: 1498744043633] [levelValue: 800] [[
Retrieving document at 'https://Time.DarkSide.com:8081/oscm/v1.9/SubscriptionService/STS?wsdl'.]]

[2017-06-29T15:47:23.675+0200] [glassfish 4.1] [INFO] [] [com.sun.metro.policy] [tid: _ThreadID=136 _ThreadName=__ejb-thread-pool3] [timeMillis: 1498744043675] [levelValue: 800] [[
WSP5018: Loaded WSIT configuration from file: jar:file:/C:/RunTime/GF4/glassfish/domains/app17/lib/CT-MG-ALL-wsit.jar!/wsit-client.xml.]]

[2017-06-29T15:47:23.820+0200] [glassfish 4.1] [SEVERE] [] [com.sun.xml.ws.security.trust] [tid: _ThreadID=136 _ThreadName=__ejb-thread-pool3] [timeMillis: 1498744043820] [levelValue: 1000] [[
WST0017:Could not obtain STS metadata. MEX call to STS https://Time.DarkSide.com/adfs/services/trust/mex/ failed.]]

[2017-06-29T15:47:23.824+0200] [glassfish 4.1] [SEVERE] [] [com.sun.xml.wss.jaxws.impl] [tid: _ThreadID=136 _ThreadName=__ejb-thread-pool3] [timeMillis: 1498744043824] [levelValue: 1000] [[
WSSTUBE0035: Received Exception during IssuedToken Creation.
com.sun.xml.ws.api.security.trust.WSTrustException: WST0017:Could not obtain STS metadata. MEX call to STS https://Time.DarkSide.com/adfs/services/trust/mex/ failed.
at com.sun.xml.ws.security.trust.impl.TrustPluginImpl.doMexRequest(TrustPluginImpl.java:687)
at com.sun.xml.ws.security.trust.impl.TrustPluginImpl.invokeRST(TrustPluginImpl.java:525)
at com.sun.xml.ws.security.trust.impl.TrustPluginImpl.process(TrustPluginImpl.java:175)
at com.sun.xml.ws.security.trust.impl.client.STSIssuedTokenProviderImpl.getIssuedTokenContext(STSIssuedTokenProviderImpl.java:144)
at com.sun.xml.ws.security.trust.impl.client.STSIssuedTokenProviderImpl.issue(STSIssuedTokenProviderImpl.java:74)
at com.sun.xml.ws.api.security.trust.client.IssuedTokenManager.getIssuedToken(IssuedTokenManager.java:83)
at com.sun.xml.wss.jaxws.impl.SecurityClientTube.invokeTrustPlugin(SecurityClientTube.java:686)
at com.sun.xml.wss.jaxws.impl.SecurityClientTube.processClientRequestPacket(SecurityClientTube.java:283)
at com.sun.xml.wss.jaxws.impl.SecurityClientTube.processRequest(SecurityClientTube.java:249)
at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:1136)
at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:1050)
at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:1019)
at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:877)
at com.sun.xml.ws.client.Stub.process(Stub.java:463)
at com.sun.xml.ws.client.sei.SEIStub.doProcess(SEIStub.java:191)
at com.sun.xml.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:108)
at com.sun.xml.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:92)
at com.sun.xml.ws.client.sei.SEIStub.invoke(SEIStub.java:161)
at com.sun.proxy.$Proxy480.completeAsyncSubscription(Unknown Source)
at org.oscm.app.dao.BesDAO.notifyAsyncSubscription(BesDAO.java:315)
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.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4786)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:64)
at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
at sun.reflect.GeneratedMethodAccessor80.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:140)
at sun.reflect.GeneratedMethodAccessor77.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:369)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4758)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4746)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
at com.sun.proxy.$Proxy249.notifyAsyncSubscription(Unknown Source)
at org.oscm.app.dao.EJB31_Generated__BesDAO__Intf____Bean.notifyAsyncSubscription(Unknown Source)
at org.oscm.app.v2_0.service.APPTimerServiceBean.notifyOnProvisioningCompletion(APPTimerServiceBean.java:918)
at org.oscm.app.v2_0.service.APPTimerServiceBean.doHandleControllerProvisioning(APPTimerServiceBean.java:358)
at org.oscm.app.v2_0.service.APPTimerServiceBean.doHandleSystems(APPTimerServiceBean.java:281)
at org.oscm.app.v2_0.service.APPTimerServiceBean.handleTimer(APPTimerServiceBean.java:216)
at sun.reflect.GeneratedMethodAccessor511.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4786)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
at sun.reflect.GeneratedMethodAccessor80.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:163)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundTimeout(SystemInterceptorProxy.java:145)
at sun.reflect.GeneratedMethodAccessor447.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:822)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:369)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4758)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4746)
at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4051)
at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1199)
at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:89)
at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1919)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
]]

[ghost]

This issue also occurs on 2 of our windows environments with openam as identity provider.

[StavrevaS]

Issue with SAML and higher JDK versions was observed also with Glassfish 3.1.2 (Issue #541)
It is not known if it is in anyway connected to this issue.

The web service requests in Glassfish are handled from Metro. The Metro Package for Glassfish 4.1.2 can be found here: https://mvnrepository.com/artifact/org.glassfish.main.packager/metro/4.1.2

Analyzing the manifest files of the jars and war file, it can be seen that many of them are built with jdk 1.6.0 versions. The problems may be some Java compatibility issues.
Payara project already recompiled Metro libraries for Java 7 compatibility:
https://github.com/payara/Payara_PatchedProjects/tree/master/org/glassfish/metro/webservices-osgi/2.3.2-b608.payara-p2

[GoebelL]

Payara project already recompiled Metro libraries for Java 7 compatibility.

Then let's try them.

[kwodzynski]

Windows Server 2016, jdk1.8u131, build BES_MASTER_UNIT-1813 2017/07/06 in SAML mode.
I have installed jar file from Suzana's comment. I have not noticed any negative impact of working of application, but I could not reproduce the issue earlier.

[GoebelL]

@AndreasTWolf
Could you share more details? We spent much effort trying to reproduce but without success. Any hints would be welcome.

[StavrevaS]

@AndreasTWolf tested with updated Metro libraries, as proposed in previous comments, but without success.

[StavrevaS]

It seems that the problem is not reproducible in all environments.