10 Replies Latest reply on Apr 3, 2008 11:11 AM by hoschi

    Performance issues - jbr-listener

    hoschi

      Hi everyone,

      I got a "little" problem when invoking services using jbr-listener: every time a service gets invoked using jbr-listener, the request takes three seconds and more until it gets to the first action in the action pipeline.

      I've built the following testing scenario:
      A client sends a SOAP request to the ESB using XFire. This request gets forwarded to a Webservice on another JBossAS instance (let's call it JB2 - JBoss ESB is not deployed there), the response gets send back to the client.

      Long story short: Client <--> ESB <--> External Webservice

      When the SOAP request arrives at the first action it just takes some milliseconds until the response of the external webservice is back at the client - however, as stated above, until the request gets to the first action it takes about three seconds - I'm sure you understand that this is simply too much time for using it in a production environment.

      What I've tried so far:
      -) Blaming XFire - well, it is not XFires fault - the request gets send to the ESB in no time (used tcpmon for recording messages and their timestamps). Additionaly, a direct call to the external webservice results in about 25 calls per second, not 1 call in 3 seconds.

      -) Using SOAPClient with a transformer action for SOAP --> Map transformation: well, same problem - three seconds until the request gets to the transformer

      -) just print out the message which gets onto the bus using org.jboss.soa.esb.actions.SystemPrintln: same here, 3 seconds

      -) Debugging -- well, didn't get far with this - it seems that the lag is caused by jmsMessage = _messageConsumer.receive(millis); in JmsCourier.pickupPayload() -- however, I think the real problem is between keyboard an chair writing the configuration ;)

      So, now to the configuration details:
      JBoss ESB is deployed on JBoss EAP 4.3.0 (the problem persists when deploying on the standalone version of JBoss ESB)

      jboss-esb.xml:

      <jbossesb
       xmlns="http://anonsvn.labs.jboss.com/labs/jbossesb/trunk/product/etc/schemas/xml/jbossesb-1.0.1.xsd"
       parameterReloadSecs="5">
      
       <providers>
       <jbr-provider name="JBR-Http" protocol="http" host="localhost">
       <jbr-bus busid="Http-1" port="8888" />
       </jbr-provider>
      
       <jms-provider name="JMS-Provider"
       connection-factory="ConnectionFactory"
       jndi-context-factory="org.jnp.interfaces.NamingContextFactory"
       jndi-URL="localhost">
       <jms-bus busid="EchoEsbChannel">
       <jms-message-filter dest-type="QUEUE"
       dest-name="queue/inet_esb_test_echo" />
       </jms-bus>
       </jms-provider>
       </providers>
      
       <services>
       <service category="EchoEsb" name="EchoForward" description="Simple SOAP Forwarding Example">
       <listeners>
       <jbr-listener name="Http-Gateway" busidref="Http-1"
       is-gateway="true" maxThreads="1" />
       <jms-listener name="JMS-ESBListener"
       busidref="EchoEsbChannel" maxThreads="1" />
       </listeners>
      
       <actions mep="RequestResponse">
       <action name="forwardAction"
       class="inet.esb.test.jboss.actions.SOAPForwarder">
       <property name="listenerPath" value="EchoWs" />
       <property name="forwardUrl" value="http://localhost:8280/EchoWs/EchoWs" />
       <property name="portName" value="EchoWsHttpPort" />
       <property name="namespace" value="http://inet.esb.test" />
       </action>
       </actions>
       </service>
       </services>
      </jbossesb>


      server.log: The first line is from the response of a previous service call - after that, a new request gets send within some milliseconds
      2008-04-02 13:27:10,712 DEBUG [org.jboss.soa.esb.listeners.gateway.JBossRemotingGatewayListener] Re
      turning response [<soap:Envelope xmlns:soap='http://schemas.xmlsoap.org/soap/envelope/' xmlns:xsd='
      http://www.w3.org/2001/XMLSchema' xmlns:xsi='http://www.w3.org/2001/XMLSchema-instance'><soap:Body>
      <ns1:doEchoResponse xmlns:ns1='http://inet.esb.test'><ns1:out>Echo: ECHO2</ns1:out></ns1:doEchoResp
      onse></soap:Body></soap:Envelope>].
      2008-04-02 13:27:13,899 DEBUG [org.jboss.soa.esb.addressing.eprs.JMSEpr] 'acknowledge-mode' is : AU
      TO_ACKNOWLEDGE
      2008-04-02 13:27:13,899 DEBUG [org.jboss.internal.soa.esb.rosetta.pooling.JmsConnectionPool] Return
      ing session, poolsize=4, maxsize=20, number of pools=1
      2008-04-02 13:27:13,899 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier delivery
      Mode: 2, peristent:true
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSCorreletionID to : 63cf2f61-e1df-4fd2-bcff-5bf11a6af503
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : HttpVersion, value : HTTP/1.1
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : MethodType, value : POST
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : Path, value : /EchoWs
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : expect, value : 100-continue
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : soapaction, value : ""
      2008-04-02 13:27:13,914 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : host, value : localhost:8888
      2008-04-02 13:27:13,930 DEBUG [org.jboss.internal.soa.esb.rosetta.pooling.JmsConnectionPool] Return
      ing session, poolsize=4, maxsize=20, number of pools=1
      2008-04-02 13:27:13,992 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] pipeli
      ne process for message: header: [ To: JMSEpr [ PortReference < <wsa:Address jms://localhost/queue/i
      net_esb_test_echo/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interf
      aces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : localhost
      />, <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb
      :specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFa
      ctory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:a
      cknowledge-mode : 1/> > ] ReplyTo: JMSEpr [ PortReference < <wsa:Address jms://localhost/queue/inet
      _esb_test_echo_reply/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : localhost/>, <
      wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFact
      ory/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jboss
      esb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : Connectio
      nFactory/>, <wsa:ReferenceProperties jbossesb:message-selector : jbossESBresponseUUID='228f572e-d93
      0-4834-a2b7-fb7e6d2ac27d'/>, <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceP
      roperties jbossesb:acknowledge-mode : 1/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/e
      pr/type/jms/> > ] MessageID: ID:JBM-90187 RelatesTo: jms:correlationID#63cf2f61-e1df-4fd2-bcff-5bf1
      1a6af503 ]
      2008-04-02 13:27:13,992 DEBUG [org.jboss.soa.esb.listeners.message.ActionProcessingPipeline] execut
      ing processor 0 inet.esb.test.jboss.actions.SOAPForwarder@114b420 header: [ To: JMSEpr [ PortRefere
      nce < <wsa:Address jms://localhost/queue/inet_esb_test_echo/>, <wsa:ReferenceProperties jbossesb:ja
      va.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbo
      ssesb:java.naming.provider.url : localhost/>, <wsa:ReferenceProperties jbossesb:destination-type :
      queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties
      jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : t
      rue/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : 1/> > ] ReplyTo: JMSEpr [ PortReference
       < <wsa:Address jms://localhost/queue/inet_esb_test_echo_reply/>, <wsa:ReferenceProperties jbossesb
      :java.naming.provider.url : localhost/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.init
      ial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:destination-type
       : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperti
      es jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:message-sel
      ector : jbossESBresponseUUID='228f572e-d930-4834-a2b7-fb7e6d2ac27d'/>, <wsa:ReferenceProperties jbo
      ssesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : 1/>, <wsa:Reference
      Properties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] MessageID: ID:JBM-90187 RelatesTo: jms:
      correlationID#63cf2f61-e1df-4fd2-bcff-5bf11a6af503 ]
      2008-04-02 13:27:13,992 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Create new config [name
      =Standard Client,file=META-INF/standard-jaxws-client-config.xml]
      2008-04-02 13:27:13,992 DEBUG [org.jboss.ws.metadata.config.JBossWSConfigFactory] getConfig: [name=
      Standard Client,url=META-INF/standard-jaxws-client-config.xml]
      2008-04-02 13:27:13,992 DEBUG [org.jboss.ws.metadata.config.JBossWSConfigFactory] parse: file:/D:/a
      ppl/aik/Teststellungen/Server/JBoss/jboss-eap-4.3/jboss-as/server/default/deploy/jbossws.sar/META-I
      NF/standard-jaxws-client-config.xml
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Configure EndpointMetaD
      ata
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Added 0 PRE handlers
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Added 0 ENDPOINT handle
      rs
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Added 0 POST handlers
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.metadata.umdm.EndpointMetaData] Configure SOAPBinding
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.core.soap.MessageFactoryImpl] createMessage: [contentTy
      pe=text/xml]
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.core.client.RemotingConnectionImpl] Get locator for: ht
      tp://localhost:8280/EchoWs/EchoWs
      2008-04-02 13:27:14,055 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] org.jboss.remoting.tran
      sport.http.HTTPClientInvoker@4acc69 connecting
      2008-04-02 13:27:14,055 DEBUG [org.jboss.remoting.MicroRemoteClientInvoker] org.jboss.remoting.tran
      sport.http.HTTPClientInvoker@4acc69 connected
      2008-04-02 13:27:14,055 DEBUG [org.jboss.ws.core.client.RemotingConnectionImpl] Remoting metadata:
      {NoThrowOnError=true, HEADER={SOAPAction="", Content-Type=text/xml; charset=UTF-8}}
      2008-04-02 13:27:14,055 DEBUG [org.jboss.remoting.transport.http.HTTPClientInvoker] Setting request
       header with SOAPAction : ""
      2008-04-02 13:27:14,055 DEBUG [org.jboss.remoting.transport.http.HTTPClientInvoker] Setting request
       header with Content-Type : text/xml; charset=UTF-8
      2008-04-02 13:27:14,071 DEBUG [org.jboss.ws.core.soap.SOAPMessageUnMarshaller] getMimeHeaders from:
       {Date=[Wed, 02 Apr 2008 11:27:14 GMT], Transfer-Encoding=[chunked], NoThrowOnError=true, HEADER={S
      OAPAction="", Content-Type=text/xml; charset=UTF-8}, ResponseCode=200, ResponseCodeMessage=OK, Cont
      ent-Type=[text/xml;charset=UTF-8], X-Powered-By=[Servlet 2.4; JBoss-4.3.0.GA (build: SVNTag=JBPAPP_
      4_3_0_GA date=200801031548)/Tomcat-5.5], Server=[Apache-Coyote/1.1]}
      2008-04-02 13:27:14,071 DEBUG [org.jboss.ws.core.soap.MessageFactoryImpl] createMessage: [contentTy
      pe=text/xml; charset=UTF-8]
      2008-04-02 13:27:14,071 DEBUG [org.jboss.remoting.InvokerRegistry] removed org.jboss.remoting.trans
      port.http.HTTPClientInvoker@4acc69 from registry
      2008-04-02 13:27:14,071 DEBUG [org.jboss.internal.soa.esb.rosetta.pooling.JmsConnectionPool] Return
      ing session, poolsize=4, maxsize=20, number of pools=1
      2008-04-02 13:27:14,071 DEBUG [org.jboss.internal.soa.esb.couriers.JmsCourier] JMSCourier delivery
      Mode: 2, peristent:true
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSCorreletionID to : fb3435d7-ccac-4f09-9af4-2fd8a08baceb
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSCorreletionID to : null
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : HttpVersion, value : HTTP/1.1
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : MethodType, value : POST
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : Path, value : /EchoWs
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : expect, value : 100-continue
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : host, value : localhost:8888
      2008-04-02 13:27:14,086 DEBUG [org.jboss.soa.esb.notification.jms.DefaultJMSPropertiesSetter] Setti
      ng outgoing JMSProperty, key : soapaction, value : ""
      2008-04-02 13:27:14,117 DEBUG [org.jboss.soa.esb.listeners.gateway.JBossRemotingGatewayListener] Re
      turning response [<soap:Envelope xmlns:soap='http://schemas.xmlsoap.org/soap/envelope/' xmlns:xsd='
      http://www.w3.org/2001/XMLSchema' xmlns:xsi='http://www.w3.org/2001/XMLSchema-instance'><soap:Body>
      <ns1:doEchoResponse xmlns:ns1='http://inet.esb.test'><ns1:out>Echo: ECHO3</ns1:out></ns1:doEchoResp
      onse></soap:Body></soap:Envelope>].


      Any ideas how to remove this lag?

      Thanks & Regards

      Johannes

        • 1. Re: Performance issues - jbr-listener
          tfennelly

          This isn't making sense at the moment :-(

          So the 3 sec laps at the start is between an old request and the new request (the one we're interested in?). After that point I don't see any major lapses in time.

          Can you post that log again please and insert comments where you feel they are relevant?

          Also, might be worth trying (as an experiment) replacing the <jbr-listener> gateway with some other gateway (e.g. JMS) and testing to see what the lags look like between the JMS Gateway and JMS Listener.

          • 2. Re: Performance issues - jbr-listener
            hoschi

            I was hoping you could find some relevant information in the debug log ;) I can't see anything relevant that could cause the lag

            I noticed some other messages regarding JMSEpr and ServiceInvoker, which appear sometimes (not always) right before the messages posted before. I'm not sure if they are relevant to the lag in any case, as they also appear 3 seconds after the call from the client (see below).

            The 3 sec laps is at every request, not only between an old and a new request. At the first request there is even a 4 sec lag between sending the request and getting it on the action pipeline (the 1 second more is caused by some initialisations i guess).

            I'll try the JMS Gateway now - posting the results soon.

            2008-04-02 15:08:04,653 DEBUG [org.jboss.internal.soa.esb.services.registry.JAXRRegistryImpl] Going
             to query the registry for name pattern [EchoForward]
            2008-04-02 15:08:04,653 DEBUG [org.jboss.internal.soa.esb.services.registry.JAXRRegistryImpl] Servi
            ce name: EchoForward
            2008-04-02 15:08:04,653 DEBUG [org.jboss.internal.soa.esb.services.registry.JAXRRegistryImpl] Descr
            iption: null
            2008-04-02 15:08:04,653 DEBUG [org.jboss.internal.soa.esb.services.registry.JAXRRegistryImpl] Key i
            d: 1FB44450-FCDA-11DC-8450-C5FC31BB530B
            2008-04-02 15:08:04,825 DEBUG [org.jboss.soa.esb.client.ServiceInvoker] EPR=EPR: PortReference < <w
            sa:Address http://localhost:8888/> > XML=<?xml version="1.0" encoding="UTF-8"?>
            <From xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing">
             <wsa:Address>http://localhost:8888</wsa:Address>
            </From>
            
            2008-04-02 15:08:04,825 DEBUG [org.jboss.soa.esb.client.ServiceInvoker] EPR=JMSEpr [ PortReference
            < <wsa:Address jms://localhost/queue/inet_esb_test_echo/>, <wsa:ReferenceProperties jbossesb:java.n
            aming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbosses
            b:java.naming.provider.url : localhost/>, <wsa:ReferenceProperties jbossesb:destination-type : queu
            e/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbos
            sesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/
            >, <wsa:ReferenceProperties jbossesb:acknowledge-mode : 1/>, <wsa:ReferenceProperties jbossesb:type
             : urn:jboss/esb/epr/type/jms/> > ] XML=<?xml version="1.0" encoding="UTF-8"?>
            <From xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing">
             <wsa:Address>jms://localhost/queue/inet_esb_test_echo</wsa:Address>
             <wsa:ReferenceProperties>
             <jbossesb:java.naming.factory.initial xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/j
            bossesb">org.jnp.interfaces.NamingContextFactory</jbossesb:java.naming.factory.initial>
             <jbossesb:java.naming.provider.url xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbos
            sesb">localhost</jbossesb:java.naming.provider.url>
             <jbossesb:destination-type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">qu
            eue</jbossesb:destination-type>
             <jbossesb:specification-version xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbosses
            b">1.1</jbossesb:specification-version>
             <jbossesb:connection-factory xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">
            ConnectionFactory</jbossesb:connection-factory>
             <jbossesb:persistent xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">true</jb
            ossesb:persistent>
             <jbossesb:acknowledge-mode xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">1<
            /jbossesb:acknowledge-mode>
             <jbossesb:type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">urn:jboss/esb/
            epr/type/jms</jbossesb:type>
             </wsa:ReferenceProperties>
            </From>
            
            2008-04-02 15:08:04,825 DEBUG [org.jboss.soa.esb.client.ServiceInvoker] EPR=JMSEpr [ PortReference
            < <wsa:Address jms://127.0.0.1:1199/queue/inet_esb_test_echo/>, <wsa:ReferenceProperties jbossesb:j
            ava.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jb
            ossesb:java.naming.provider.url : localhost/>, <wsa:ReferenceProperties jbossesb:destination-type :
             queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties
             jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent :
            true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : 1/>, <wsa:ReferenceProperties jbossesb
            :type : urn:jboss/esb/epr/type/jms/> > ] XML=<?xml version="1.0" encoding="UTF-8"?>
            <From xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing">
             <wsa:Address>jms://127.0.0.1:1199/queue/inet_esb_test_echo</wsa:Address>
             <wsa:ReferenceProperties>
             <jbossesb:java.naming.factory.initial xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/j
            bossesb">org.jnp.interfaces.NamingContextFactory</jbossesb:java.naming.factory.initial>
             <jbossesb:java.naming.provider.url xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbos
            sesb">localhost</jbossesb:java.naming.provider.url>
             <jbossesb:destination-type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">qu
            eue</jbossesb:destination-type>
             <jbossesb:specification-version xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbosses
            b">1.1</jbossesb:specification-version>
             <jbossesb:connection-factory xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">
            ConnectionFactory</jbossesb:connection-factory>
             <jbossesb:persistent xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">true</jb
            ossesb:persistent>
             <jbossesb:acknowledge-mode xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">1<
            /jbossesb:acknowledge-mode>
             <jbossesb:type xmlns:jbossesb="http://schemas.jboss.com/ws/2007/01/jbossesb">urn:jboss/esb/
            epr/type/jms</jbossesb:type>
             </wsa:ReferenceProperties>
            </From>
            
            2008-04-02 15:08:04,840 WARN [org.jboss.soa.esb.client.ServiceInvoker] Badly formed EPR [EPR: Port
            Reference < <wsa:Address http://localhost:8888/> >] for Service [EchoEsb:EchoForward] and Message [
            header: [ ]].Courier for EPR not supported!
            2008-04-02 15:08:04,840 INFO [org.jboss.soa.esb.client.ServiceInvoker] Invalid EPR for service: ig
            noring for message: header: [ ]
            2008-04-02 15:08:04,871 DEBUG [org.jboss.soa.esb.addressing.eprs.JMSEpr] 'acknowledge-mode' is : AU
            TO_ACKNOWLEDGE


            • 3. Re: Performance issues - jbr-listener
              hoschi

              Tested the same using a JMS-Gateway - this works fine without a lag. So the problem is somewhere in jbr-listener i guess. Any ideas? ;)

              Thanks
              Johannes

              • 4. Re: Performance issues - jbr-listener
                tfennelly

                We'd need to be able to reproduce it here.

                I'd guess it's something to do with the sync invocation from the JBR gateway to the JMS listener (message aware listener). I assume you've configured an "inet_esb_test_echo_reply" queue to go with the "inet_esb_test_echo" queue (for passing back the sync replies)?

                The <jbr-listener> also supports a "synchronous" property. Try setting that to "false" and see what happens. You should get an immediate message with that set.

                • 5. Re: Performance issues - jbr-listener
                  hoschi

                  Yes, "inet_esb_test_echo_reply" is defined in deployment.xml, jbmq-queue-service.xml and jbm-queue-service.xml. Already tried defining it in jboss-esb.xml additionally.

                  Adding "" to jbr-listener doesn't change anything :( (except that the client gets an exception because it assumes it is a sync call). The request still needs 3 secs until it gets to the SOAPForwarder action

                  • 6. Re: Performance issues - jbr-listener
                    hoschi

                    After some debugging i could track the problem down to one line:

                    The problem is caused by org.jboss.internal.soa.esb.remoting.HttpUnmarshaller, method
                    public Object read(InputStream inputStream, Map metadata, int version)
                    line 101 --> int amtRead = inputStream.read(byteBuffer);

                    It calls CoyoteInputStream.read() (line 85), which calls InputBuffer.read() (line 311) which calls ByteChunk.substract(b, off, len) with b=byte[1024] filled with 0, off=0, len=1024 ... ByteChunk.substract() causes the 3 secs lag - so there is a pretty low level problem...

                    If I find a solution for this, I'll post it here, but first I have to find the source for ByteChunk ;)

                    Thanks for your help, tfennelly

                    Greetings
                    Johannes

                    • 7. Re: Performance issues - jbr-listener
                      tfennelly

                      Great work Johannes.

                      Now I'm wondering is this a JBR versioning issue! It's probably not the issue because you're client is XFire and the JBR version is "usually" only an issue when you're using JBR on both ends of the wire (JBR Client -> JBR Server) - they utilize some version sensitive optimizations when it's JBR on both ends. Also, ByteChunk is down in Coyote, right?

                      Anyway...
                      What version of the ESB are you using?
                      What version of JBoss AS are you using (if you are)?
                      Have you performed any patches on the AS/ESB Servers?

                      • 8. Re: Performance issues - jbr-listener
                        hoschi

                        First the easy answers ;)
                        JBoss ESB Version: 4.2.1GA
                        JBoss AS: 4.3.0 EAP ( -- problem persists when running JBoss ESB standalone)
                        No patches applied by me
                        Java 1.6.0 ( -- problem persists with Java 1.5.0)


                        ByteChunk is in org.apache.tomcat.util.buf (from JBossWeb) but calls some methods from coyote

                        I got a bit further with debugging.

                        Stacktrace (explained below):

                        Daemon Thread [http-localhost%2F127.0.0.1-8192-1] (Suspended (breakpoint at line 129 in SocketInputStream))
                         SocketInputStream.read(byte[], int, int) line: 129
                         InternalInputBuffer.fill() line: 716
                         InternalInputBuffer$InputStreamInputBuffer.doRead(ByteChunk, Request) line: 746
                         IdentityInputFilter.doRead(ByteChunk, Request) line: 116
                         InternalInputBuffer.doRead(ByteChunk, Request) line: 675
                         Request.doRead(ByteChunk) line: 419
                         InputBuffer.realReadBytes(byte[], int, int) line: 294
                         ByteChunk.substract(byte[], int, int) line: 405
                         InputBuffer.read(byte[], int, int) line: 311
                         CoyoteInputStream.read(byte[]) line: 85
                         HttpUnmarshaller.read(InputStream, Map, int) line: 101
                         CoyoteInvoker.versionedRead(Request, RequestMap, ResponseMap, int) line: 469
                         CoyoteInvoker.service(Request, Response) line: 304
                         Http11Processor.process(Socket) line: 844
                         Http11Protocol$Http11ConnectionHandler.process(Socket) line: 580
                         JIoEndpoint$Worker.run() line: 447
                         Thread.run() line: 619


                        At "SocketInputStream.read(byte b[], int off, int length)" the native method "socketRead0" gets called, which causes the lag always when the given offset is >0.

                        In my case the offset is 250 (=length of http header) and the method reads 301 bytes (= length of SOAP request = content-length in http-header). Conclusion: first the http-header gets read, then the content... well, nothing bad here I think

                        I will not blame the java implementation for being laggy, something done before must cause it - but currently I'm only guessing what it could be - no concrete idea yet :(

                        I should have paid more attention back in university at the networking lessons ;)

                        • 9. Re: Performance issues - jbr-listener
                          marklittle

                          What problems did you have with JDK 1.5? We don't support JDK 1.6 and it hasn't been tested with the platforms.

                          • 10. Re: Performance issues - jbr-listener
                            hoschi

                            Exactly the same as with Java 1.6.0 - the 3 sec lag until a request to jbr-listener comes to the action pipeline