1 2 Previous Next 18 Replies Latest reply on Jan 4, 2018 8:29 AM by jaikiran

    Problem with http invocation of ejb

    crazycradd

      jaikiran recently helped me find a bug in the wildfly 11 release when perfoming a lookup of a remote ejb.

       

      This now works but the client closes the http connection so the next invokation made by the client fails.

       

      I have tried this with http2 enabled and disabled and both get the same problem.

       

      The last thing in the log is this

      DEBUG [HttpClientConnection] close called on connection to /192.168.56.1:8020

       

      then the next invocation fails

      11:04:27,001 WARN  [ListSessionServer] getRemote

      11:04:27,001 WARN  [ListSessionServer] getRemote retrying in 10

       

      The code seems to call a safe close

        • 1. Re: Problem with http invocation of ejb
          jaikiran

          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

            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

              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

                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

                  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

                    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

                      Is there a firewall involved?

                      • 8. Re: Problem with http invocation of ejb
                        crazycradd

                        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

                          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

                            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

                              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

                                @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

                                  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

                                    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.

                                    1 2 Previous Next