5 Replies Latest reply on Mar 5, 2006 8:39 AM by thomas.diesler

    jboss 4.0.2 serialization speed compare to jboss4.0.0

    singular_droid

      A week ago we have started redevelopment of our webservice from jboss4.0.0 to jboss4.0.2. Saying shortly, we have discovered that serialization of server response in jboss4.0.2 is about 8-10 times slowly than in jboss4.0.0. The execution speed of session bean public method in both cases are equal, but the construction of soap message take a much more time. Our tests didn't change except for replacing "org.apache.axis" with "org.jboss.axis" in ws4ee-deployment.xml and classpaths. Of cause our tests are not fine-grained perfomance tests, they are simply junit test cases, but imagine that overall test execution time jump from 5-7 to 40-45 seconds. Except for this reason(very long time of response) we are still on jboss4.0.0. May be there are some fixes or workaround that can help to overcome this problem(if it is really jboss problem, not ours)?

        • 1. Re: jboss 4.0.2 serialization speed compare to jboss4.0.0

          Hi!

          What are the signatures of your web-service methods in your ejb? Are you using jbossws serialization of java-objects or returning DOM elements/documents? Have you configured your own serializers?

          regards!

          /Ole

          • 2. Re: jboss 4.0.2 serialization speed compare to jboss4.0.0
            thomas.diesler

            Could you provide a sample deployment + unit test that proofs allows me to reproduce what you are seeing?

            • 3. Re: jboss 4.0.2 serialization speed compare to jboss4.0.0
              singular_droid

              I can email 2 jars - 4.0.2 and 4.0.0 versions of our webservice(with the minimal changes). But it uses hibernate3 and oracle legacy stored procs. This is ours ws4ee-deployment for jboss4.0.0:

              <deployment xmlns='http://xml.apache.org/axis/wsdd/'
               xmlns:java='http://xml.apache.org/axis/wsdd/providers/java'
               xmlns:soap='http://schemas.xmlsoap.org/soap/encoding/'
               xmlns:xsi='http://www.w3.org/2000/10/XMLSchema-instance'
               xmlns:xsd='http://www.w3.org/2001/XMLSchema'>
              
               <typeMapping qname='ns1:PriceUpdateSoapBean'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateSoapBean'
               serializer='org.jboss.webservice.encoding.ser.MetaDataBeanSerializerFactory'
               deserializer='org.jboss.webservice.encoding.ser.MetaDataBeanDeserializerFactory'
               encodingStyle=''>
               <typeDesc xmlType='ns1:PriceUpdateSoapBean'>
               <elementOrder>
               <element name="cod" />
               <element name="name" />
               <element name="price" />
               <element name="t_group" />
               <element name="c_group" />
               <element name="opdml" />
               <element name="met" />
               <element name="log" />
               </elementOrder>
               </typeDesc>
               </typeMapping>
              
               <typeMapping qname='ns1:PriceUpdateSoapBeans'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateSoapBeans'
               serializer='org.apache.axis.encoding.ser.BeanSerializerFactory'
               deserializer='org.apache.axis.encoding.ser.BeanDeserializerFactory'
               encodingStyle='' />
              
               <typeMapping qname='ns1:PriceUpdateResultBean'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateResultBean'
               serializer='org.apache.axis.encoding.ser.BeanSerializerFactory'
               deserializer='org.apache.axis.encoding.ser.BeanDeserializerFactory'
               encodingStyle='' />
              
              </deployment>
              


              And this is one for jboss4.0.2
              <deployment xmlns='http://xml.apache.org/axis/wsdd/'
               xmlns:java='http://xml.apache.org/axis/wsdd/providers/java'
               xmlns:soap='http://schemas.xmlsoap.org/soap/encoding/'
               xmlns:xsi='http://www.w3.org/2000/10/XMLSchema-instance'
               xmlns:xsd='http://www.w3.org/2001/XMLSchema'>
              
               <typeMapping qname='ns1:PriceUpdateSoapBean'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateSoapBean'
               serializer='org.jboss.webservice.encoding.ser.MetaDataBeanSerializerFactory'
               deserializer='org.jboss.webservice.encoding.ser.MetaDataBeanDeserializerFactory'
               encodingStyle=''>
               <typeDesc xmlType='ns1:PriceUpdateSoapBean'>
               <elementOrder>
               <element name="cod" />
               <element name="name" />
               <element name="price" />
               <element name="t_group" />
               <element name="c_group" />
               <element name="opdml" />
               <element name="met" />
               <element name="log" />
               </elementOrder>
               </typeDesc>
               </typeMapping>
              
               <typeMapping qname='ns1:PriceUpdateSoapBeans'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateSoapBeans'
               serializer='org.jboss.axis.encoding.ser.BeanSerializerFactory'
               deserializer='org.jboss.axis.encoding.ser.BeanDeserializerFactory'
               encodingStyle='' />
              
               <typeMapping qname='ns1:PriceUpdateResultBean'
               xmlns:ns1='http://hibernate.service.dealer.zenith.ru'
               type='java:ru.zenith.dealer.service.hibernate.PriceUpdateResultBean'
               serializer='org.jboss.axis.encoding.ser.BeanSerializerFactory'
               deserializer='org.jboss.axis.encoding.ser.BeanDeserializerFactory'
               encodingStyle='' />
              
              </deployment>
              

              First, when we transfer our ws to 4.0.2 we have changed hibernate-related part of ws(move it in separate .har), but after that(in order to find the bottleneck) we have downgrade it to previous version(single jar with hibernate and ejb classes). In that case there are two versions of our ws for jboss4.0.2 - ear(with jar and har inside) and single jar. In both cases serialization is slow.
              In order to illustrate junit results with timings we have start jboss and tests on the same machine, so in this tests client connects to localhost. First I want to say that we run this tests a lot of times so it's not a single moment jboss4.0.2 behavior.
              This is the parts of code of statless session bean (ejbCreate() and public buisness method)
              ...
               public void ejbCreate() throws CreateException {
               URL log4jConfig = DealerServiceBean.class
               .getResource("/META-INF/log4j.xml");
               DOMConfigurator.configure(log4jConfig);
               logger.info("Logger initialized");
              
               // Create the SessionFactory
               sessionFactory = new Configuration().configure(
               "/META-INF/jboss-hibernate.cfg.xml").buildSessionFactory();
               }
              ...
              
               public PriceUpdateSoapBean[] getPriceUpdate(long p_log, long p_firstload) {
               logger.info("into getPriceUpdateSoap()");
               PriceUpdateSoapBean[] pusb = new PriceUpdateSoapBean[1];
               session = sessionFactory.openSession();
               Transaction tx = session.beginTransaction();
               logger.debug("Tx at the beginning");
               Query query = session.getNamedQuery("get_price_update");
               query.setLong("in_log", p_log);
               query.setLong("first_load", p_firstload);
               logger.debug("after binding input values: in_log="+p_log+"; first_load="+p_firstload);
               List l = query.list();
               logger.debug("after executing");
               pusb = (PriceUpdateSoapBean[]) l.toArray(pusb);
               tx.commit();
               logger.info("before return of PriceUpdateSoapBean[] with length of"+pusb.length);
               return pusb;
               }
              

              This is the test for ws:
               public void testGetPriceUpdateInLoop() throws Exception {
               int tr = 10;
               long[] tries = new long[tr];
               for (int i = 0; i < tr; i++) {
               logger.debug("try number:" + i);
               factoryImpl = (ServiceFactoryImpl) ServiceFactory.newInstance();
              
               Service service = factoryImpl.createService(new URL(endpoint),
               new File(mapping).toURL(), new File(deployment).toURL(),
               new QName("http://interfaces.service.dealer.zenith.ru",
               "DealerService"), null);
              
               Integer p_log = new Integer(-1);
               Integer p_firstload = new Integer(1);
               Call call3 = (Call) service.createCall(new QName(
               "http://interfaces.service.dealer.zenith.ru",
               "DealerServiceBeanEndpoint"), "getPriceUpdate");
               long start = System.currentTimeMillis();
               PriceUpdateSoapBean[] result = (PriceUpdateSoapBean[]) call3
               .invoke(new Object[] { p_log, p_firstload });
               long finish = System.currentTimeMillis();
               tries=finish - start;
               logger.debug("time:" + tries);
               assertNotNull(result);
               assertEquals(100, result.length);
               }
               long sum = 0;
               for (int j = 0; j < tries.length; j++) {
               sum = sum + tries[j];
               }
               double sr = sum / tries.length;
               logger.debug("sum/tries:" + sr);
               }
              

              This is the merged output of junit test for jboss 4.0.0:
              Buildfile: D:\dev\eclipse31\eclipse\workspace\DealerService1.0\build.xml
               [echo] JRE_HOME=C:\Program Files\Java\jdk1.5.0\jre
               [echo] JBOSS_HOME=D:/dev/jboss-4.0.0
               [echo] axis.home.dir=D:/dev/axis-1_1
               [echo] xdt.home.dir=D:/dev/xdoclet-1.2.2
               [echo] junit.home.dir=D:/dev/junit3.8.1
               [echo] src.dir=src
               [echo] meta.inf.dir=src/META-INF
               [echo] wsdl.dir=src/META-INF/wsdl
               [echo] build.dir=classes
               [echo] build.test.dir=classes/ru/zenith/dealer/service/test
               [echo] reports.dir=log
               [echo] hibernate3.home.dir=D:/dev/hibernate-3.0.2
              prepare:
              compile-tests:
              test:
               [junit] 12:10:29,421 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:10:29,421 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:10:29,421 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:10:29,437 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:10:29,453 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:10:29,453 DEBUG [DealerServiceBeanTest] Created LoginContext
              
              //server output
              12:10:31,359 INFO [DealerServiceBean] Logger initialized
              12:10:31,984 INFO [DealerServiceBean] Authenticated principal:R19640
              //end of server output
              
               [junit] 12:10:32,031 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:10:32,125 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:10:33,703 DEBUG [DealerServiceBeanTest] start=1116490233703
              
              //server output
              12:10:33,750 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:33,750 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:33,937 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:35,265 DEBUG [DealerServiceBeanTest] finish=1116490235265
               [junit] 12:10:35,265 DEBUG [DealerServiceBeanTest] finish-start(in milliseconds)=1562
               [junit] 12:10:35,265 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:10:35,265 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:10:35,328 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:10:35,343 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:10:35,343 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:10:35,343 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:10:35,343 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:10:35,781 DEBUG [DealerServiceBeanTest] after service creation
               [junit] 12:10:35,781 DEBUG [DealerServiceBeanTest] start=1116490235781
              
              //server output
              12:10:35,812 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:35,828 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:35,984 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:36,890 DEBUG [DealerServiceBeanTest] finish=1116490236890
               [junit] 12:10:36,890 DEBUG [DealerServiceBeanTest] finish-start(in milliseconds)=1109
               [junit] 12:10:36,890 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:10:36,968 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:10:36,984 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:10:37,125 DEBUG [DealerServiceBeanTest] try number:0
              
              //server output
              12:10:37,406 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:37,406 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:37,546 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:38,218 DEBUG [DealerServiceBeanTest] time:843
               [junit] 12:10:38,218 DEBUG [DealerServiceBeanTest] try number:1
              
              //server output
              12:10:38,593 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:38,609 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:38,734 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:39,328 DEBUG [DealerServiceBeanTest] time:766
               [junit] 12:10:39,328 DEBUG [DealerServiceBeanTest] try number:2
              
              //server output
              12:10:39,625 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:39,625 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:39,796 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:40,359 DEBUG [DealerServiceBeanTest] time:781
               [junit] 12:10:40,359 DEBUG [DealerServiceBeanTest] try number:3
              
              //server output
              12:10:40,671 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:40,671 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:40,875 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:41,437 DEBUG [DealerServiceBeanTest] time:812
               [junit] 12:10:41,437 DEBUG [DealerServiceBeanTest] try number:4
              
              //server output
              12:10:41,781 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:41,781 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:41,937 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:42,484 DEBUG [DealerServiceBeanTest] time:750
               [junit] 12:10:42,484 DEBUG [DealerServiceBeanTest] try number:5
              
              //server output
              12:10:42,796 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:42,859 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:42,968 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:43,546 DEBUG [DealerServiceBeanTest] time:781
               [junit] 12:10:43,546 DEBUG [DealerServiceBeanTest] try number:6
              
              //server output
              12:10:43,828 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:43,843 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:44,000 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:44,562 DEBUG [DealerServiceBeanTest] time:750
               [junit] 12:10:44,562 DEBUG [DealerServiceBeanTest] try number:7
              
              //server output
              12:10:44,843 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:44,890 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:44,984 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:45,546 DEBUG [DealerServiceBeanTest] time:734
               [junit] 12:10:45,546 DEBUG [DealerServiceBeanTest] try number:8
              
              //server output
              12:10:45,812 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:45,812 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:45,906 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:46,468 DEBUG [DealerServiceBeanTest] time:687
               [junit] 12:10:46,468 DEBUG [DealerServiceBeanTest] try number:9
              
              //server output
              12:10:46,734 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:10:46,796 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:10:46,890 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              //end of server output
              
               [junit] 12:10:47,437 DEBUG [DealerServiceBeanTest] time:734
               [junit] 12:10:47,437 DEBUG [DealerServiceBeanTest] sum/tries::763.0
               [junit] 12:10:47,437 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] Testsuite: ru.zenith.dealer.service.test.DealerServiceBeanTest
               [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 18,031 sec
               [junit] ------------- Standard Error -----------------
               [junit] log4j:WARN No appenders could be found for logger (org.jboss.webservice.EngineConfigurationFinder).
               [junit] log4j:WARN Please initialize the log4j system properly.
               [junit] ------------- ---------------- ---------------
              BUILD SUCCESSFUL
              Total time: 22 seconds
              


              And this is the same junit test output on jboss4.0.2
              Buildfile: D:\dev\eclipse31\eclipse\workspace\DealerService1.0\build.xml
               [echo] JRE_HOME=C:\Program Files\Java\jdk1.5.0\jre
               [echo] JBOSS_HOME=D:/dev/jboss-4.0.2
               [echo] axis.home.dir=D:/dev/axis-1_1
               [echo] xdt.home.dir=D:/dev/xdoclet-1.2.2
               [echo] junit.home.dir=D:/dev/junit3.8.1
               [echo] src.dir=src
               [echo] meta.inf.dir=src/META-INF
               [echo] wsdl.dir=src/META-INF/wsdl
               [echo] build.dir=classes
               [echo] build.test.dir=classes/ru/zenith/dealer/service/test
               [echo] reports.dir=log
               [echo] hibernate3.home.dir=D:/dev/hibernate-3.0.2
              prepare:
              compile-tests:
              test:
               [junit] 12:58:53,093 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:58:53,109 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:58:53,125 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:58:53,125 DEBUG [DealerServiceBeanTest] Created LoginContext
              
              12:58:57,734 INFO [DealerServiceBean] Logger initialized
              12:59:00,906 INFO [DealerServiceBean] Authenticated principal:R19640
              
               [junit] 12:59:01,171 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:59:01,250 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:59:03,187 DEBUG [DealerServiceBeanTest] start=1116493143187
              
              12:59:03,281 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:03,437 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:03,734 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:09,312 DEBUG [DealerServiceBeanTest] finish=1116493149312
               [junit] 12:59:09,328 DEBUG [DealerServiceBeanTest] finish-start(in milliseconds)=6125
               [junit] 12:59:09,328 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:59:09,328 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:59:09,343 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:59:09,843 DEBUG [DealerServiceBeanTest] after service creation
               [junit] 12:59:09,859 DEBUG [DealerServiceBeanTest] start=1116493149859
              
              12:59:09,921 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:09,921 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:10,203 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:15,078 DEBUG [DealerServiceBeanTest] finish=1116493155078
               [junit] 12:59:15,078 DEBUG [DealerServiceBeanTest] finish-start(in milliseconds)=5219
               [junit] 12:59:15,078 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] 12:59:15,078 DEBUG [DealerServiceBeanTest] into setUp()
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/mapping.xml
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] D:/dev/eclipse31/eclipse/workspace/DealerService1.0/classes/META-INF/ws4ee-deployment.xml
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] http://localhost:8080/DealerService?wsdl
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] DealerService
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] DealerServiceBean
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] javax.xml.rpc.encodingstyle.namespace.uri
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] http://www.w3.org/2001/XMLSchema
               [junit] 12:59:15,109 DEBUG [DealerServiceBeanTest] http://schemas.xmlsoap.org/soap/encoding/
               [junit] 12:59:15,125 DEBUG [DealerServiceBeanTest] R19640
               [junit] 12:59:15,125 DEBUG [DealerServiceBeanTest] dare
               [junit] 12:59:15,125 DEBUG [DealerServiceBeanTest] 6004949
               [junit] 12:59:15,125 DEBUG [DealerServiceBeanTest] Created LoginContext
               [junit] 12:59:15,125 DEBUG [DealerServiceBeanTest] try number:0
              
              12:59:15,406 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:15,406 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:15,546 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:20,218 DEBUG [DealerServiceBeanTest] time:4843
               [junit] 12:59:20,218 DEBUG [DealerServiceBeanTest] try number:1
              
              12:59:20,578 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:20,593 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:20,734 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:25,109 DEBUG [DealerServiceBeanTest] time:4578
               [junit] 12:59:25,109 DEBUG [DealerServiceBeanTest] try number:2
              
              12:59:25,390 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:25,390 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:25,515 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:29,953 DEBUG [DealerServiceBeanTest] time:4610
               [junit] 12:59:29,953 DEBUG [DealerServiceBeanTest] try number:3
              
              12:59:30,203 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:30,203 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:30,343 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:34,734 DEBUG [DealerServiceBeanTest] time:4563
               [junit] 12:59:34,734 DEBUG [DealerServiceBeanTest] try number:4
              
              12:59:34,953 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:34,953 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:35,078 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:39,578 DEBUG [DealerServiceBeanTest] time:4657
               [junit] 12:59:39,578 DEBUG [DealerServiceBeanTest] try number:5
              
              12:59:39,875 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:39,890 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:40,015 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:44,375 DEBUG [DealerServiceBeanTest] time:4532
               [junit] 12:59:44,375 DEBUG [DealerServiceBeanTest] try number:6
              
              12:59:44,562 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:44,562 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:44,687 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:49,140 DEBUG [DealerServiceBeanTest] time:4609
               [junit] 12:59:49,140 DEBUG [DealerServiceBeanTest] try number:7
              
              12:59:49,390 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:49,390 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:49,515 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:53,906 DEBUG [DealerServiceBeanTest] time:4547
               [junit] 12:59:53,906 DEBUG [DealerServiceBeanTest] try number:8
              
              12:59:54,328 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:54,328 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:54,437 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 12:59:58,687 DEBUG [DealerServiceBeanTest] time:4391
               [junit] 12:59:58,687 DEBUG [DealerServiceBeanTest] try number:9
              
              12:59:58,859 INFO [DealerServiceBean] into getPriceUpdateSoap()
              12:59:58,859 INFO [STDOUT] Hibernate: {? = call trate.pks_remote_diler.get_price_update_soap(?,?) }
              12:59:59,453 INFO [DealerServiceBean] before return of PriceUpdateSoapBean[] with length of100
              
               [junit] 13:00:03,953 DEBUG [DealerServiceBeanTest] time:5125
               [junit] 13:00:03,953 DEBUG [DealerServiceBeanTest] sum/tries:4645.0
               [junit] 13:00:03,953 DEBUG [DealerServiceBeanTest] in tearDown()
               [junit] Testsuite: ru.zenith.dealer.service.test.DealerServiceBeanTest
               [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 70,875 sec
               [junit] ------------- Standard Error -----------------
               [junit] log4j:WARN No appenders could be found for logger (org.jboss.webservice.EngineConfigurationFinder).
               [junit] log4j:WARN Please initialize the log4j system properly.
               [junit] ------------- ---------------- ---------------
              BUILD SUCCESSFUL
              Total time: 1 minute 18 seconds
              


              • 4. Re: jboss 4.0.2 serialization speed compare to jboss4.0.0
                lepe

                Did you ever find out a reason for the loss of performance?

                /L

                • 5. Re: jboss 4.0.2 serialization speed compare to jboss4.0.0
                  thomas.diesler

                  How does this compare to the latest jboss-4.0.x which uses jbossws?

                  cvs co -r Branch_4_0 jboss-4.0.x