-
1. Re: Problem with http invocation of ejb
jaikiran Dec 18, 2017 7:14 AM (in response to crazycradd)What does your lookup code look like? Is the looked up proxy held on to further invocations or do you lookup every time you want to invoke on the EJB? How long before you start seeing these connection closures and subsequently invocation failures? Can you attach the entire debug log plus the exception stacktraces?
-
2. Re: Problem with http invocation of ejb
crazycradd Dec 18, 2017 8:50 AM (in response to jaikiran)Here is the stacktrace, this seems to happen after about 30 seconds of inactivity,I have tried it after disableing http 2 and I get the same results
Caused by: java.nio.channels.ClosedChannelException
at io.undertow.client.http2.Http2ClientConnection.sendRequest(Http2ClientConnection.java:132)
at io.undertow.client.http.HttpClientConnection.sendRequest(HttpClientConnection.java:331)
at org.wildfly.httpclient.common.HttpTargetContext.sendRequestInternal(HttpTargetContext.java:156)
at org.wildfly.httpclient.common.HttpTargetContext.lambda$sendRequest$3(HttpTargetContext.java:146)
at org.wildfly.httpclient.common.HttpConnectionPool.runPending(HttpConnectionPool.java:131)
at org.wildfly.httpclient.common.HttpConnectionPool.getConnection(HttpConnectionPool.java:83)
at org.wildfly.httpclient.common.HttpTargetContext.sendRequest(HttpTargetContext.java:146)
at org.wildfly.httpclient.naming.HttpRootContext.performOperation(HttpRootContext.java:283)
-
3. Re: Problem with http invocation of ejb
crazycradd Dec 18, 2017 12:18 PM (in response to jaikiran)I managed to recreate the issue outside of the swing application.
The remote calls fail after 60 seconds I wrote a small TestCase to see how long it takes to fail
try
{CPConnection conn = mHelper.getConnection(true);
conn.getListHelper().getAllBudgetHierarchies().getNumRows();
for(int i = 51; i < 80; i = i+10)
{
long sleeper = 1000 * i;
System.out.println("sleeping for :" + sleeper);
Thread.currentThread().sleep(sleeper);
conn.getListHelper().getAllBudgetHierarchies().getNumRows();
}
}
catch (Exception e)
{
fail(e.getMessage());
}
When the program runs I see all the connection info just like in the swing app but I get the following
17:11:48,694 DEBUG [Recycler] -Dio.netty.recycler.maxSharedCapacityFactor: 2
17:11:48,694 DEBUG [Recycler] -Dio.netty.recycler.linkCapacity: 16
17:11:48,694 DEBUG [Recycler] -Dio.netty.recycler.ratio: 8
sleeping for :51000
sleeping for :61000
17:13:39,968 DEBUG [HttpClientConnection] connection to /10.2.33.3:8020 closed
17:13:40,919 DEBUG [HttpClientConnection] close called on connection to /10.2.33.3:8020
17:13:40,919 WARN [ListSessionServer] getRemote
17:13:40,919 WARN [ListSessionServer] getRemote retrying in 10
Disconnected from the target VM, address: '127.0.0.1:55659', transport: 'socket'
-
4. Re: Problem with http invocation of ejb
crazycradd Dec 18, 2017 1:42 PM (in response to jaikiran)I removed some of my framework and the following lookup now fails so I expect you can quickly amend one of your tests to replicate the issue.
try
{Properties contextProps = new Properties();
contextProps.put(Context.INITIAL_CONTEXT_FACTORY, "org.wildfly.naming.client.WildFlyInitialContextFactory");
contextProps.put("jboss.naming.client.ejb.context", true);
contextProps.put(Context.SECURITY_PRINCIPAL, "admin");
contextProps.put(Context.SECURITY_CREDENTIALS, "password");
contextProps.put(Context.PROVIDER_URL, "http://abs16874:8020/wildfly-services");
Context context = new InitialContext(contextProps);
Object o = context.lookup("cp/cp-server/LogonSEJB!com.cedar.cp.ejb.api.logon.LogonRemote");
assertNotNull(o);
Thread.currentThread().sleep(60000);
context = new InitialContext(contextProps);
o = context.lookup("cp/cp-server/LogonSEJB!com.cedar.cp.ejb.api.logon.LogonRemote");
assertNotNull(o);
}
catch (Exception e)
{
e.printStackTrace();
fail();
}
I get the same issue if I create a new context or not
-
5. Re: Problem with http invocation of ejb
jaikiran Dec 19, 2017 2:52 AM (in response to crazycradd)I tried various variants of this and so far haven't been able to reproduce this. Given that it seems to be reproducible on your setup, can you attach the client and server side logs (DEBUG level) to this thread?
-
6. Re: Problem with http invocation of ejb
crazycradd Dec 19, 2017 3:02 AM (in response to jaikiran)The server.log file is clean would you like me to alter a particular log level and try again ?
The client log is as follows
07:55:23,656 INFO [naming] WildFly Naming version 1.0.7.Final
07:55:23,812 INFO [security] ELY00001: WildFly Elytron version 1.1.6.Final
07:55:24,528 DEBUG [HttpClientExchange] request terminated for request to /192.168.56.1:8020 /wildfly-services/naming/v1/lookup/cp%2Fcp-server%2FLogonSEJB%21com.cedar.cp.ejb.api.logon.LogonRemote
07:55:24,548 DEBUG [HttpClientConnection] connection to /192.168.56.1:8020 is being upgraded
07:56:24,826 DEBUG [HttpClientConnection] connection to /192.168.56.1:8020 closed
07:56:29,211 DEBUG [HttpClientConnection] close called on connection to /192.168.56.1:8020
javax.naming.CommunicationException [Root exception is java.nio.channels.ClosedChannelException]
at org.wildfly.httpclient.naming.HttpRootContext.performOperation(HttpRootContext.java:336)
at org.wildfly.httpclient.naming.HttpRootContext.lambda$processInvocation$0(HttpRootContext.java:257)
at org.wildfly.httpclient.naming.HttpRootContext.performWithRetry(HttpRootContext.java:173)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:234)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:228)
at org.wildfly.httpclient.naming.HttpRootContext.lookupNative(HttpRootContext.java:110)
at org.wildfly.naming.client.AbstractContext.lookup(AbstractContext.java:84)
at org.wildfly.naming.client.WildFlyRootContext.lookup(WildFlyRootContext.java:144)
at javax.naming.InitialContext.lookup(InitialContext.java:417)
-
7. Re: Problem with http invocation of ejb
dmlloyd Dec 19, 2017 11:29 AM (in response to crazycradd)Is there a firewall involved?
-
8. Re: Problem with http invocation of ejb
crazycradd Dec 19, 2017 11:47 AM (in response to dmlloyd)No firewall connection works fine then you see the connection is closed after inactivity of 60 seconds then the next invocation fails
-
9. Re: Problem with http invocation of ejb
jaikiran Dec 20, 2017 8:48 AM (in response to crazycradd)I haven't yet been able to reproduce this. But looking at the wildfly naming client code, it appears that this destination probably is getting added to a (internal time based) blacklist due to this communication failure. That effectively seems to disable retries for this single destination. Whether or not that's the right thing for this specific case of connections idling out, isn't something I can't say yet, since I don't have much knowledge of the code.
For now, can you enable TRACE level logging of org.wildfly.naming on the client side and TRACE level logging of org.wildfly, io.undertow on the server side (I haven't checked which exact classes/packages are involved on server side, so a broader range of packages might be relevant for now). Attach those generated logs when you reproduce this.
-
10. Re: Problem with http invocation of ejb
crazycradd Dec 20, 2017 12:34 PM (in response to jaikiran)I altered the code to lookup 2 different beans and this works if the sleeptime is 30 seconds but still fails if the sleep time goes up to 60 seconds.
Here is the server log
2017-12-20 17:26:07,915 TRACE [org.wildfly.security] (default task-1) Created HttpServerAuthenticationMechanism [org.wildfly.security.http.util.SecurityIdentityServerMechanismFactory$1@3434aa8c] for mechanism [DIGEST]
2017-12-20 17:26:07,920 TRACE [org.wildfly.security] (default task-1) Handling MechanismInformationCallback type='HTTP' name='DIGEST' host-name='abs16874' protocol='http'
2017-12-20 17:26:07,923 TRACE [org.wildfly.security] (default task-1) Handling AvailableRealmsCallback: realms = [ApplicationRealm]
2017-12-20 17:26:07,930 TRACE [org.wildfly.security] (default task-1) New nonce generated AAAAAQAb+yihB905/ReF5Hglc7lmY2WY94nXt/K7jg0dLMSJyB6jdoauYU4=, using seed 4170706c69636174696f6e5265616c6d
2017-12-20 17:26:07,978 TRACE [org.wildfly.security] (default task-2) Created HttpServerAuthenticationMechanism [org.wildfly.security.http.util.SecurityIdentityServerMechanismFactory$1@4654f5e4] for mechanism [DIGEST]
2017-12-20 17:26:07,978 TRACE [org.wildfly.security] (default task-2) Handling MechanismInformationCallback type='HTTP' name='DIGEST' host-name='abs16874' protocol='http'
2017-12-20 17:26:07,981 TRACE [org.wildfly.security] (default task-2) Currently 1 nonces being tracked
2017-12-20 17:26:07,982 TRACE [org.wildfly.security] (default task-2) Handling AvailableRealmsCallback: realms = [ApplicationRealm]
2017-12-20 17:26:07,983 TRACE [org.wildfly.security] (default task-2) Handling AvailableRealmsCallback: realms = [ApplicationRealm]
2017-12-20 17:26:07,984 TRACE [org.wildfly.security] (default task-2) Handling RealmCallback: selected = [ApplicationRealm]
2017-12-20 17:26:07,984 TRACE [org.wildfly.security] (default task-2) Handling NameCallback: authenticationName = admin
2017-12-20 17:26:07,987 TRACE [org.wildfly.security] (default task-2) Principal assigning: [admin], pre-realm rewritten: [admin@ApplicationRealm], realm name: [DIGEST], post-realm rewritten: [admin@ApplicationRealm], realm rewritten: [admin@ApplicationRealm]
2017-12-20 17:26:08,002 TRACE [org.wildfly.security] (default task-2) Handling CredentialCallback: obtained credential for correct realm "ApplicationRealm"
2017-12-20 17:26:08,002 TRACE [org.wildfly.security] (default task-2) Handling CredentialCallback: obtained credential: org.wildfly.security.credential.PasswordCredential@6ccbde9
2017-12-20 17:26:08,004 TRACE [org.wildfly.security] (default task-2) Role mapping: principal [admin@ApplicationRealm] -> decoded roles [] -> realm mapped roles [] -> domain mapped roles []
2017-12-20 17:26:08,004 TRACE [org.wildfly.security] (default task-2) Authorizing principal admin.
2017-12-20 17:26:08,018 TRACE [org.wildfly.security] (default task-2) Authorizing against the following attributes: [] => []
2017-12-20 17:26:08,019 TRACE [org.wildfly.security] (default task-2) Permission mapping: identity [admin@ApplicationRealm] with roles [] implies ("org.wildfly.security.auth.permission.LoginPermission" "") = true
2017-12-20 17:26:08,019 TRACE [org.wildfly.security] (default task-2) Authorization succeed
2017-12-20 17:26:08,021 TRACE [org.wildfly.security] (default task-2) RunAs authorization succeed - the same identity
2017-12-20 17:26:08,021 TRACE [org.wildfly.security] (default task-2) Handling AuthorizeCallback: authenticationID = admin authorizationID = admin authorized = true
2017-12-20 17:26:08,021 TRACE [org.wildfly.security] (default task-2) Handling AuthenticationCompleteCallback: succeed
2017-12-20 17:26:08,022 TRACE [org.wildfly.security] (default task-2) Handling SecurityIdentityCallback: identity = SecurityIdentity{principal=admin@ApplicationRealm, securityDomain=org.wildfly.security.auth.server.SecurityDomain@4ce659f8, authorizationIdentity=EMPTY, realmInfo=RealmInfo{name='DIGEST', securityRealm=org.jboss.as.domain.management.security.SecurityRealmService$SharedStateSecurityRealm@cd7e1bb}, creationTime=2017-12-20T17:26:08.004Z}
2017-12-20 17:26:08,038 TRACE [org.wildfly.security] (default task-2) Role mapping: principal [admin@ApplicationRealm] -> decoded roles [] -> realm mapped roles [] -> domain mapped roles []
2017-12-20 17:26:08,056 INFO [org.jboss.ejb.client] (default task-2) JBoss EJB Client version 4.0.7.Final
2017-12-20 17:27:55,382 TRACE [org.wildfly.security] (default task-3) Created HttpServerAuthenticationMechanism [org.wildfly.security.http.util.SecurityIdentityServerMechanismFactory$1@2568b0cc] for mechanism [DIGEST]
2017-12-20 17:27:55,382 TRACE [org.wildfly.security] (default task-3) Handling MechanismInformationCallback type='HTTP' name='DIGEST' host-name='abs16874' protocol='http'
2017-12-20 17:27:55,382 TRACE [org.wildfly.security] (default task-3) Handling AvailableRealmsCallback: realms = [ApplicationRealm]
2017-12-20 17:27:55,382 TRACE [org.wildfly.security] (default task-3) New nonce generated AAAAAgAb+0GlfmVyIYWTKUavcvW9ZpEYeylhDSwl6ueddspvZuMw5jOY2BI=, using seed 4170706c69636174696f6e5265616c6d
2017-12-20 17:27:55,487 TRACE [org.wildfly.security] (default task-4) Created HttpServerAuthenticationMechanism [org.wildfly.security.http.util.SecurityIdentityServerMechanismFactory$1@225485ef] for mechanism [DIGEST]
I dont see much new in the client side log but here it is
7:27:54,562 INFO [naming] WildFly Naming version 1.0.7.Final
17:27:54,710 INFO [security] ELY00001: WildFly Elytron version 1.1.6.Final
17:27:54,996 TRACE [security] getAuthenticationConfiguration uri=http://abs16874:8020/wildfly-services, protocolDefaultPort=80, abstractType=jndi, abstractTypeAuthority=jboss, MatchRule=[], AuthenticationConfiguration=[AuthenticationConfiguration:principal=admin,set-host=abs16874,set-protocol=http,sasl-protocol-name=remote,set-port=8020,credentials-present,providers-supplier=org.wildfly.security.util.ProviderUtil$1@1c481ff2,mechanism-properties={javax.security.sasl.policy.noanonymous=false, wildfly.sasl.local-user.quiet-auth=false}]
17:27:55,380 DEBUG [HttpClientExchange] request terminated for request to /10.2.33.3:8020 /wildfly-services/naming/v1/lookup/cp%2Fcp-server%2FBudgetCycleHelperSEJB%21com.cedar.cp.ejb.api.model.BudgetCycleHelperRemote
17:27:55,391 DEBUG [HttpClientConnection] connection to /10.2.33.3:8020 is being upgraded
17:28:55,548 DEBUG [HttpClientConnection] connection to /10.2.33.3:8020 closed
17:28:55,636 TRACE [security] getAuthenticationConfiguration uri=http://abs16874:8020/wildfly-services, protocolDefaultPort=80, abstractType=jndi, abstractTypeAuthority=jboss, MatchRule=[], AuthenticationConfiguration=[AuthenticationConfiguration:principal=admin,set-host=abs16874,set-protocol=http,sasl-protocol-name=remote,set-port=8020,credentials-present,providers-supplier=org.wildfly.security.util.ProviderUtil$1@1c481ff2,mechanism-properties={javax.security.sasl.policy.noanonymous=false, wildfly.sasl.local-user.quiet-auth=false}]
17:28:55,637 DEBUG [HttpClientConnection] close called on connection to /10.2.33.3:8020
javax.naming.CommunicationException [Root exception is java.nio.channels.ClosedChannelException]
at org.wildfly.httpclient.naming.HttpRootContext.performOperation(HttpRootContext.java:336)
at org.wildfly.httpclient.naming.HttpRootContext.lambda$processInvocation$0(HttpRootContext.java:257)
at org.wildfly.httpclient.naming.HttpRootContext.performWithRetry(HttpRootContext.java:173)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:234)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:228)
at org.wildfly.httpclient.naming.HttpRootContext.lookupNative(HttpRootContext.java:110)
at org.wildfly.naming.client.AbstractContext.lookup(AbstractContext.java:84)
at org.wildfly.naming.client.WildFlyRootContext.lookup(WildFlyRootContext.java:144)
at javax.naming.InitialContext.lookup(InitialContext.java:417)
at com.cedar.cp.tests.util.ConnectionTest.test001localConnection(ConnectionTest.java:58)
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 junit.framework.TestCase.runTest(TestCase.java:176)
at junit.framework.TestCase.runBare(TestCase.java:141)
at junit.framework.TestResult$1.protect(TestResult.java:122)
at junit.framework.TestResult.runProtected(TestResult.java:142)
at junit.framework.TestResult.run(TestResult.java:125)
at junit.framework.TestCase.run(TestCase.java:129)
at junit.framework.TestSuite.runTest(TestSuite.java:252)
at junit.framework.TestSuite.run(TestSuite.java:247)
at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:78)
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:212)
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:68)
Caused by: java.nio.channels.ClosedChannelException
-
11. Re: Problem with http invocation of ejb
crazycradd Dec 20, 2017 12:44 PM (in response to jaikiran)Here is a new client side log that shows more IO detail
17:37:14,898 INFO [naming] WildFly Naming version 1.0.7.Final
17:37:15,072 INFO [security] ELY00001: WildFly Elytron version 1.1.6.Final
17:37:15,441 TRACE [security] getAuthenticationConfiguration uri=http://abs16874:8020/wildfly-services, protocolDefaultPort=80, abstractType=jndi, abstractTypeAuthority=jboss, MatchRule=[], AuthenticationConfiguration=[AuthenticationConfiguration:principal=admin,set-host=abs16874,set-protocol=http,sasl-protocol-name=remote,set-port=8020,credentials-present,providers-supplier=org.wildfly.security.util.ProviderUtil$1@1c481ff2,mechanism-properties={javax.security.sasl.policy.noanonymous=false, wildfly.sasl.local-user.quiet-auth=false}]
17:37:15,886 TRACE [request] flush
17:37:15,886 TRACE [request] Starting request
17:37:15,888 TRACE [request] Processing header 'Accept'
17:37:15,889 TRACE [request] Processing header value 'application/x-wf-jndi-jbmar-value;version=1,application/x-wf-jbmar-exception;version=1'
17:37:15,890 TRACE [request] Processing header 'HTTP2-Settings'
17:37:15,890 TRACE [request] Processing header value ''
17:37:15,890 TRACE [request] Processing header 'Connection'
17:37:15,890 TRACE [request] Processing header value 'Upgrade, HTTP2-Settings'
17:37:15,890 TRACE [request] Processing header 'Upgrade'
17:37:15,890 TRACE [request] Processing header value 'h2c'
17:37:15,890 TRACE [request] Processing header 'Host'
17:37:15,891 TRACE [request] Processing header value 'abs16874'
17:37:15,891 TRACE [request] Body
17:37:15,891 TRACE [request] Delegating flush
17:37:15,891 DEBUG [HttpClientExchange] request terminated for request to /10.2.33.3:8020 /wildfly-services/naming/v1/lookup/cp%2Fcp-server%2FBudgetCycleHelperSEJB%21com.cedar.cp.ejb.api.model.BudgetCycleHelperRemote
17:37:15,902 DEBUG [HttpClientConnection] connection to /10.2.33.3:8020 is being upgraded
17:37:15,946 TRACE [io] Invoking receive listener
17:37:15,974 TRACE [io] Invoking receive listener
17:37:16,000 TRACE [io] Invoking receive listener
17:37:16,002 TRACE [io] Invoking receive listener
17:37:16,027 TRACE [io] Invoking receive listener
17:37:16,028 TRACE [io] Invoking receive listener
17:38:16,078 TRACE [io] Invoking receive listener
17:38:16,081 TRACE [io] Sending goaway on channel Http2Channel peer /10.2.33.3:8020 local /10.2.33.3:64128[ No Receiver [] -- [] -- []]
java.nio.channels.ClosedChannelException
at io.undertow.protocols.http2.Http2Channel.sendGoAway(Http2Channel.java:761)
at io.undertow.protocols.http2.Http2Channel.sendGoAway(Http2Channel.java:752)
at io.undertow.protocols.http2.Http2Channel.createChannelImpl(Http2Channel.java:487)
at io.undertow.protocols.http2.Http2Channel.createChannel(Http2Channel.java:323)
at io.undertow.protocols.http2.Http2Channel.createChannel(Http2Channel.java:65)
at io.undertow.server.protocol.framed.AbstractFramedChannel.receive(AbstractFramedChannel.java:452)
at io.undertow.client.http2.Http2ClientConnection$Http2ReceiveListener.handleEvent(Http2ClientConnection.java:352)
at io.undertow.client.http2.Http2ClientConnection$Http2ReceiveListener.handleEvent(Http2ClientConnection.java:347)
at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:932)
at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:913)
at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66)
at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:591)
17:38:16,087 TRACE [io] Channel Http2Channel peer /10.2.33.3:8020 local /10.2.33.3:64128[ No Receiver [] -- [] -- []] is being closed
java.nio.channels.ClosedChannelException
at io.undertow.server.protocol.framed.AbstractFramedChannel.close(AbstractFramedChannel.java:791)
at org.xnio.IoUtils.safeClose(IoUtils.java:152)
at io.undertow.protocols.http2.Http2Channel.sendGoAway(Http2Channel.java:775)
at io.undertow.protocols.http2.Http2Channel.sendGoAway(Http2Channel.java:752)
at io.undertow.protocols.http2.Http2Channel.createChannelImpl(Http2Channel.java:487)
at io.undertow.protocols.http2.Http2Channel.createChannel(Http2Channel.java:323)
at io.undertow.protocols.http2.Http2Channel.createChannel(Http2Channel.java:65)
at io.undertow.server.protocol.framed.AbstractFramedChannel.receive(AbstractFramedChannel.java:452)
at io.undertow.client.http2.Http2ClientConnection$Http2ReceiveListener.handleEvent(Http2ClientConnection.java:352)
at io.undertow.client.http2.Http2ClientConnection$Http2ReceiveListener.handleEvent(Http2ClientConnection.java:347)
at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:932)
at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:913)
at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66)
at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89)
at org.xnio.nio.WorkerThread.run(WorkerThread.java:591)
17:38:16,091 DEBUG [HttpClientConnection] connection to /10.2.33.3:8020 closed
javax.naming.CommunicationException [Root exception is java.nio.channels.ClosedChannelException]
at org.wildfly.httpclient.naming.HttpRootContext.performOperation(HttpRootContext.java:336)
at org.wildfly.httpclient.naming.HttpRootContext.lambda$processInvocation$0(HttpRootContext.java:257)
at org.wildfly.httpclient.naming.HttpRootContext.performWithRetry(HttpRootContext.java:173)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:234)
at org.wildfly.httpclient.naming.HttpRootContext.processInvocation(HttpRootContext.java:228)
17:38:16,159 TRACE [security] getAuthenticationConfiguration uri=http://abs16874:8020/wildfly-services, protocolDefaultPort=80, abstractType=jndi, abstractTypeAuthority=jboss, MatchRule=[], AuthenticationConfiguration=[AuthenticationConfiguration:principal=admin,set-host=abs16874,set-protocol=http,sasl-protocol-name=remote,set-port=8020,credentials-present,providers-supplier=org.wildfly.security.util.ProviderUtil$1@1c481ff2,mechanism-properties={javax.security.sasl.policy.noanonymous=false, wildfly.sasl.local-user.quiet-auth=false}]
17:38:16,160 DEBUG [HttpClientConnection] close called on connection to /10.2.33.3:8020
-
12. Re: Problem with http invocation of ejb
crazycradd Dec 21, 2017 10:12 AM (in response to jaikiran)@jaikiran I think I have found the issue if you can confirm my findings that would be great.
I traced the client side connection and it looked like the connection was being closed because the server was telling it to. So after checking the xnio options and the undertow config i discovered the following default value
<xs:attribute name="no-request-timeout" type="xs:int" default="60000"/>
I altered this in the server config file to be -1
<http-listener enable-http2="true" max-parameters="10000" name="default" redirect-socket="https" socket-binding="http" no-request-timeout="-1"/>
Once I restarted the server my test ran ok, I then doubled the thread sleep and that was also ok.
This seems to fix the issue I had but can you see this causing any adverse effects or should I set this to a high number.
-
13. Re: Problem with http invocation of ejb
jaikiran Dec 22, 2017 5:50 AM (in response to crazycradd)Although this does seem to solve the issue, I still think that the fact that you weren't able to seamlessly invoke on the EJBs after idling a bit on the client side, is a bug. Can you please file a WFLY JIRA here - JBoss Issue Tracker so that someone can try and reproduce this issue?
-
14. Re: Problem with http invocation of ejb
jaikiran Jan 4, 2018 1:27 AM (in response to jaikiran)I see you filed [WEJBHTTP-13] EJB lookup over HTTP times out connection after 60 seconds - JBoss Issue Tracker JIRA for this issue. That's now been fixed and available upstream. If you want to verify this fix, before it's made available in WildFly nightly build, you can follow the same instructions noted here Re: wildfly 11 rmi over http and give it a try locally.