10 Replies Latest reply on Feb 1, 2011 12:49 AM by michal.wroblewski

    getPort() call takes too long

      Hi there!

       

      In our project we are accessing web services provided by two partner systems which, for testing, are installed in our local network.

       

      We are using JBossWS-Native stack 3.2.0.GA to access these services.

       

      With one partner system the call of the getPort(serviceEndpointInterface) method, specified by javax.xml.rpc.Service, lasts for about 1 second. With the other system it lasts 10 seconds.

       

      So, my question is: What might cause the method to take so long?

       

      I tried to check what traffic goes over the network, but nothing, it just stays there.

       

      Thanks!

        • 1. Re: getPort() call takes too long
          cullendw

          Hi Bu,

           

          Could be many things. Latency would be the first thing to look at (are you accessing this web service within a VPN, intranet or over the web?). Is there any encryption/authentication happening? Are you going through any firewalls? Maybe the webservice you are trying to consume is under heavy load? Maybe your application is under heavy load?

           

          Could you please elaborate on "I tried to check what traffic goes over the network, but nothing, it just stays there.". Are you using a sniffer to monitor the traffic?

           

          It may also be advisable to get the provider of the web service to look into it from their side.

          • 2. Re: getPort() call takes too long

            As I said, we have a test installation of each partner system properly set up in our local network. No tunneling, no firewall, no heavy load neither on our, nor on the partner system.

             

            I'm sure, the network can't be the cause of that discrepancy. I checked that using Wireshark: Network traffic happens AFTER that time consuming call.

             

            When I access the service via soapUI, no problem, therefore I can't blame that problem on our partner.

            • 3. Re: getPort() call takes too long
              cullendw

              I overlooked your post saying that your partner systems are installed on your local network. I agree that it is unlikely to be a network issue based on what you mentioned.

               

              Are you running SoapUI the same machine your webservice consumer is running on?

               

              I have not worked much at all with JBossWS-Native but maybe try use a java profiler to see where the bottleneck is.

              • 4. Re: getPort() call takes too long

                > Are you running SoapUI the same machine your webservice consumer is running on?

                 

                yes

                 

                > I have not worked much at all with JBossWS-Native but maybe try use a java profiler to see where the bottleneck is.

                 

                I will give it a try.

                 

                Anyway, I'd really like to know why the getPort call differs in that way between the two partner systems. The consumers both go through the same code.

                • 5. Re: getPort() call takes too long

                  After I downloaded the sources of the JavaWS native stack 3.2.0.GA and debugged through the code, I was able to identify the piece of code that consumes so much CPU, thus time:

                   

                  Class: ServiceDelegateImpl.java

                  Method: private <T> T getPortInternal(EndpointMetaData epMetaData, Class<T> seiClass)

                  Line 268: synchronized (epMetaData)

                   

                  With one partner system it takes 1 to 2 seconds, with the other nearly 8 to 10 seconds.

                  • 6. Re: getPort() call takes too long

                    Below you find an excerpt of Java VisualVM. It shows the thread processing the call during that blocking period. At the bottom you see the entry call to getPort. It seems that the call to JAXWSClientMetaDataBuilder.rebuildEndpointMetaData might take so long. The duration of that call might possibly depend on the complexity of the web service interface. Just my assumption.

                     

                     

                     

                    "http-0.0.0.0-8080-1" daemon prio=6 tid=0x462e3400 nid=0x8cc runnable [0x4bfec000..0x4bfefd94]
                       java.lang.Thread.State: RUNNABLE
                    at java.lang.Class.isAssignableFrom(Native Method)
                    at org.jboss.wsf.common.JavaUtils.isAssignableFrom(JavaUtils.java:402)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.isAttachmentDataType(ReflectiveAttachmentRefScanner.java:253)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:86)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.extensions.xop.jaxws.ReflectiveAttachmentRefScanner.scanBean(ReflectiveAttachmentRefScanner.java:119)
                    at org.jboss.ws.metadata.umdm.ParameterMetaData.initializeAttachmentParameter(ParameterMetaData.java:497)
                    at org.jboss.ws.metadata.umdm.ParameterMetaData.eagerInitialize(ParameterMetaData.java:482)
                    at org.jboss.ws.metadata.umdm.OperationMetaData.eagerInitialize(OperationMetaData.java:466)
                    at org.jboss.ws.metadata.umdm.EndpointMetaData.eagerInitializeOperations(EndpointMetaData.java:559)
                    at org.jboss.ws.metadata.umdm.EndpointMetaData.initializeInternal(EndpointMetaData.java:543)
                    at org.jboss.ws.metadata.umdm.EndpointMetaData.eagerInitialize(EndpointMetaData.java:533)
                    at org.jboss.ws.metadata.builder.jaxws.JAXWSClientMetaDataBuilder.rebuildEndpointMetaData(JAXWSClientMetaDataBuilder.java:312)
                    at org.jboss.ws.core.jaxws.spi.ServiceDelegateImpl.getPortInternal(ServiceDelegateImpl.java:269)
                    at org.jboss.ws.core.jaxws.spi.ServiceDelegateImpl.getPort(ServiceDelegateImpl.java:240)
                    at javax.xml.ws.Service.getPort(Service.java:169)

                    • 7. Re: getPort() call takes too long

                      Hi there!

                       

                      Below is an excerpt of the org.jboss.ws.core.jaxws.spi.ServiceDelegateImpl.java class which shows the method that consumes so much time in my case. What I'd like to know is, how can I prevent the if part being executed, i.e. how can I put the portName into annotatedPorts before getPort is called?

                       

                       

                      private <T> T getPortInternal(EndpointMetaData epMetaData, Class<T> seiClass)

                      {

                           QName portName = epMetaData.getPortName();

                           // Adjust the endpoint meta data according to the annotations

                           if (annotatedPorts.contains(portName) == false)

                           {

                                synchronized (epMetaData)

                                {

                                     if (annotatedPorts.contains(portName) == false)

                                     {

                                          JAXWSClientMetaDataBuilder metaDataBuilder =

                                          new JAXWSClientMetaDataBuilder();

                                          metaDataBuilder.rebuildEndpointMetaData(epMetaData, seiClass);

                       

                                          annotatedPorts.add(portName);

                                     }

                                }

                           }

                       

                           return (T)createProxy(seiClass, epMetaData);

                      }

                       

                       

                       

                      • 8. Re: getPort() call takes too long
                        sridhark79

                        Hi All,

                         

                        Did we get to the root cause of this issue. we are using Jbossws-native for ws stack and our app platform is jboss 5.0.0 and when we use wsconsume-generated clients to hit the service, we see the same behaviour. In our case the rebuildEndPointMetaData takes a pretty nasty 22seconds. Any reason why the EndPoint's meta data is not found on the annotatedPort List in the getPortInternal method? Any suggestion or guidance in this matter would be really help us save our face before our clients

                         

                        Thanks & Regards

                        Sridhar

                         

                        Thanks & Regards

                        sridhar

                        • 9. Re: getPort() call takes too long
                          michal.wroblewski

                          Hi All.

                           

                          I have problem like to described. JBoss 5.1.0 JDK 6. My JVM stopped. Have you any idea?

                           

                          Stacktrace:

                           

                          "http-127.0.0.1-10080-1" daemon prio=6 tid=0x0000000006f1b2c0 nid=0x1fb4 runnable [0x000000000798b000..0x000000000798f910]

                                  at java.lang.ClassLoader.defineClass1(Native Method)

                                  at java.lang.ClassLoader.defineClass(ClassLoader.java:621)

                                  at org.jboss.classloader.spi.base.BaseClassLoader.access$200(BaseClassLoader.java:63)

                                  at org.jboss.classloader.spi.base.BaseClassLoader$2.run(BaseClassLoader.java:572)

                                  at org.jboss.classloader.spi.base.BaseClassLoader$2.run(BaseClassLoader.java:532)

                                  at java.security.AccessController.doPrivileged(Native Method)

                                  at org.jboss.classloader.spi.base.BaseClassLoader.loadClassLocally(BaseClassLoader.java:530)

                                  - locked <0x0000000027141168> (a org.jboss.classloader.spi.base.BaseClassLoader)

                                  at org.jboss.classloader.spi.base.BaseClassLoader.loadClassLocally(BaseClassLoader.java:507)

                                  at org.jboss.classloader.spi.base.BaseDelegateLoader.loadClass(BaseDelegateLoader.java:134)

                                  at org.jboss.classloader.spi.filter.FilteredDelegateLoader.loadClass(FilteredDelegateLoader.java:131)

                                  at org.jboss.classloader.spi.base.ClassLoadingTask$ThreadTask.run(ClassLoadingTask.java:452)

                                  at org.jboss.classloader.spi.base.ClassLoaderManager.nextTask(ClassLoaderManager.java:251)

                                  at org.jboss.classloader.spi.base.ClassLoaderManager.process(ClassLoaderManager.java:150)

                                  at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:265)

                                  at org.jboss.classloader.spi.base.BaseClassLoaderDomain.loadClass(BaseClassLoaderDomain.java:1119)

                                  at org.jboss.classloader.spi.base.BaseClassLoader.loadClassFromDomain(BaseClassLoader.java:798)

                                  at org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:441)

                                  - locked <0x0000000027141168> (a org.jboss.classloader.spi.base.BaseClassLoader)

                                  at java.lang.ClassLoader.loadClass(ClassLoader.java:252)

                                  at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)

                                  - locked <0x0000000027141168> (a org.jboss.classloader.spi.base.BaseClassLoader)

                                  at pl.com.disc.link.webinsurer.client.WebInsurerService.getWebInsurerPort(WebInsurerService.java:55)

                                  at com.idit.wi.fhh.util.WebServiceConnectorImpl.getWebInsurer(WebServiceConnectorImpl.java:32)

                                  at com.idit.wi.fhh.service.ServiceLocator.getService(ServiceLocator.java:26)

                                  at com.idit.wi.fhh.dao.BaseDao.getService(BaseDao.java:26)

                           

                          Thanks & Regards

                          • 10. getPort() call takes too long
                            michal.wroblewski

                            In my situation it was problem with version of stax jar. It is located in JBoss lib directory. I had to add this dependency to my pom.xml

                             

                                 <dependency>

                                    <groupId>stax</groupId>

                                    <artifactId>stax</artifactId>

                                    <version>1.2.0</version>

                                    <scope>provided</scope>

                                </dependency>

                             

                            It resolved my problem.

                             

                            All works fine.

                             

                            Regards