axis-java-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ron Ridenour" <rriden...@siterra.com>
Subject RE: Performance degradation with 1.1RC1
Date Tue, 29 Apr 2003 00:21:30 GMT
RC2 Complex object C only ( C extends B extends A ) 
2003-04-28 15:56:26,032 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=851
post=10 send=0 LocationProcessor.processLocation
2003-04-28 15:57:08,122 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=881
post=10 send=20 LocationProcessor.processLocation
2003-04-28 15:57:21,014 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=1241
post=90 send=30 LocationProcessor.processLocation
2003-04-28 15:57:47,990 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=791
post=0 send=30 LocationProcessor.processLocation
2003-04-28 15:58:27,157 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=811
post=0 send=30 LocationProcessor.processLocation


RC2 C + 9 Attributes ( Map of Attribute keyed by AttributeKey ) 
2003-04-28 15:53:18,714 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=20 invoke=3233
post=10 send=30 LocationProcessor.processLocation
2003-04-28 15:54:22,024 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=3383
post=10 send=30 LocationProcessor.processLocation
2003-04-28 15:55:45,103 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=30 invoke=2993
post=0 send=0 LocationProcessor.processLocation
2003-04-28 15:59:32,749 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2713
post=20 send=0 LocationProcessor.processLocation
2003-04-28 15:59:57,883 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2683
post=20 send=30 LocationProcessor.processLocation

RC2 C + 9 Attributes +  D[9] (Thats an array of 9 D's) Remember D also extends B
2003-04-28 15:41:04,397 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5946
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:00:51,894 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=6576
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:01:41,882 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=6086
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:02:07,596 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=6446
post=0 send=0 LocationProcessor.processLocation

RC2 C + 9 Attributes +  D[9] + Map{ Role, User[9] } ( only one Array of users keyed by one
Role for this test )
2003-04-28 15:42:54,532 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=12692
post=91 send=50 LocationProcessor.processLocation
2003-04-28 16:03:26,681 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=14774
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:04:43,003 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=13042
post=0 send=30 LocationProcessor.processLocation

RC2 C + 9 Attributes +  D[9] + Map{ Role, User[9] } + E[9]
2003-04-28 15:44:46,268 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=14024
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:06:03,410 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=16236
post=10 send=20 LocationProcessor.processLocation
2003-04-28 16:06:56,840 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=200 invoke=14754
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:08:10,260 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=100 invoke=17747
post=10 send=0 LocationProcessor.processLocation


RC2 C + E[9]
2003-04-28 17:14:07,162 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2584
post=0 send=0 LocationProcessor.processLocation
2003-04-28 17:15:04,334 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=30 invoke=3475
post=20 send=1612 LocationProcessor.processLocation
2003-04-28 17:16:38,179 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=100 invoke=3255
post=0 send=0 LocationProcessor.processLocation
2003-04-28 17:17:13,309 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2553
post=10 send=30 LocationProcessor.processLocation
2003-04-28 17:17:46,437 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=30 invoke=3675
post=10 send=30 LocationProcessor.processLocation

---------------

RC1 Complex object C only ( C extends B extends A ) 
2003-04-28 16:40:51,127 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=341
post=0 send=10 LocationProcessor.processLocation
2003-04-28 16:42:00,807 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=421
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:43:08,184 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=381
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:43:20,111 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=421
post=0 send=30 LocationProcessor.processLocation
2003-04-28 16:43:32,118 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=360
post=0 send=30 LocationProcessor.processLocation

RC1 C + 9 Attributes ( Map of Attribute keyed by AttributeKey ) 
2003-04-28 16:39:05,294 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=1061
post=20 send=30 LocationProcessor.processLocation
2003-04-28 16:39:22,199 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=872
post=10 send=20 LocationProcessor.processLocation
2003-04-28 16:39:35,278 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=841
post=10 send=31 LocationProcessor.processLocation
2003-04-28 16:39:54,705 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=841
post=10 send=0 LocationProcessor.processLocation
2003-04-28 16:40:07,624 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=811
post=0 send=0 LocationProcessor.processLocation

RC1 C + 9 Attributes +  D[9] (Thats an array of 9 D's) Remember D also extends B
2003-04-28 16:35:57,374 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2343
post=10 send=0 LocationProcessor.processLocation
2003-04-28 16:36:44,272 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=20 invoke=2674
post=0 send=10 LocationProcessor.processLocation
2003-04-28 16:37:08,066 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2814
post=0 send=10 LocationProcessor.processLocation
2003-04-28 16:37:22,697 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2444
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:37:38,339 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=2473
post=0 send=0 LocationProcessor.processLocation

RC1 C + 9 Attributes +  D[9] + Map{ Role, User[9] } ( only one Array of users keyed by one
Role for this test )
2003-04-28 16:31:01,419 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=4697
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:32:56,073 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=4907
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:33:45,705 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=4406
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:34:04,252 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=4647
post=0 send=10 LocationProcessor.processLocation
2003-04-28 16:34:22,918 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=4476
post=0 send=0 LocationProcessor.processLocation

RC1 C + 9 Attributes +  D[9] + Map{ Role, User[9] } + E[9]
2003-04-28 16:24:09,637 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=2674 invoke=7460
post=11 send=0 LocationProcessor.processLocation
2003-04-28 16:28:18,785 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5238
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:28:43,641 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=5598
post=110 send=31 LocationProcessor.processLocation
2003-04-28 16:29:13,453 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5077
post=0 send=0 LocationProcessor.processLocation
2003-04-28 16:29:55,183 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5478
post=691 send=60 LocationProcessor.processLocation

RC1 C + E[9]
2003-04-28 16:59:08,204 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=1272
post=0 send=0 LocationProcessor.processLocation
2003-04-28 17:00:45,474 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=1172
post=0 send=0 LocationProcessor.processLocation
2003-04-28 17:01:16,539 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=952
post=0 send=30 LocationProcessor.processLocation
2003-04-28 17:02:03,827 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=932
post=0 send=10 LocationProcessor.processLocation
2003-04-28 17:02:24,707 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=1032
post=0 send=0 LocationProcessor.processLocation

-----Original Message-----
From: Davanum Srinivas [mailto:dims@yahoo.com]
Sent: Monday, April 28, 2003 4:46 PM
To: axis-user@ws.apache.org
Subject: RE: Performance degradation with 1.1RC1


Ron,

Is it possible to do the following test(s)?

Test #1: Comment out (or set to Null) both the HashMap's in C and keep just the "arrays of
D, E,
F"
Test #2: Comment out (or set to Null) the "arrays of D, E, F" in C and keep the HashMap's

The problem seems to be in the Deserializers....If we can narrow it down to either the
ArrayDeserializer or the MapDeserializer then we would be better positioned.

Thanks,
dims

--- Ron Ridenour <rridenour@siterra.com> wrote:
> I'm pretty sure this is not a memory or Garbage collection problem.
> The difference is on a restart of a jboss server with an embedded
> axis servlet. I have created client side files with wsdl2java and am
> posting them to the axis servlet. The problem comes when changing
> the server side axis.jar out for the new one. Recreating the client
> side wsdl files does not change anything so I think the problem lies
> in deserialization.
> 
> I tried the nightly build for 4-26 and got similar results to RC2
> Here are some performance numbers for 1.1 beta, RC1, RC2 and Nightly 4/26
> 
> Beta
> 2003-04-28 14:41:08,677 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=2162
invoke=7657
> post=0 send=10
> 2003-04-28 14:42:00,146 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=11 invoke=6035
> post=0 send=0
> 2003-04-28 14:42:29,664 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=6136
> post=0 send=0
> 2003-04-28 14:43:05,188 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5846
> post=10 send=0
> 2003-04-28 14:43:23,515 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5765
> post=0 send=0 
> 
> RC1
> 2003-04-28 13:53:12,628 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=4914
invoke=8679
> post=120 send=20 
> 2003-04-28 13:55:29,057 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=6486
> post=0 send=0
> 2003-04-28 13:56:13,289 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=6326
> post=0 send=0
> 2003-04-28 13:57:06,620 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=8008
> post=0 send=0
> 2003-04-28 13:57:47,278 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=5965
> post=0 send=0
> 
> 
> RC2
> 2003-04-28 14:00:28,752 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=20780
> post=0 send=0 
> 2003-04-28 14:03:58,551 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=16756
> post=40 send=40
> 2003-04-28 14:21:15,855 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=100 invoke=21210
> post=0 send=10
> 2003-04-28 14:22:19,175 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=20 invoke=17756
> post=0 send=0 
> 2003-04-28 14:23:36,178 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=250 invoke=20219
> post=0 send=0 
> 
> Nightly
> 2003-04-28 14:26:38,722 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=1622
> invoke=18768 post=200 send=10 
> 2003-04-28 14:28:29,026 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=100 invoke=19468
> post=0 send=0 
> 2003-04-28 14:34:10,260 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=1251
> invoke=18918 post=110 send=40 
> 2003-04-28 14:35:49,184 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=0 invoke=17356
> post=0 send=0 
> 2003-04-28 14:36:43,726 DEBUG [org.apache.axis.TIME] axisServlet.doPost: "" pre=10 invoke=17597
> post=0 send=0 
> 
> I am still working on narrowing this down. The one thing that I did notice was that the
handling
> of arrays seems
> to have been changed to use an array element that is a restriction of soapenc:Array rather
than
> the actual
> soapenc:Array as was the case in Beta and I assume RC1.
> 
> Beta
> <element name="containers" nillable="true" type="soapenc:Array"/>
> 
> RC2
> xmlns:tns3="http://www.w3.org/2002/12/soap-encoding"
> <element name="containers" nillable="true" type="tns3:Array"/>
> 
> - <schema targetNamespace="http://www.w3.org/2002/12/soap-encoding"
> xmlns="http://www.w3.org/2001/XMLSchema">
>   <import namespace="http://schemas.xmlsoap.org/soap/encoding/" /> 
> - <complexType name="Array">
> - <complexContent>
> - <restriction base="soapenc:Array">
>   <attribute ref="soapenc:arrayType" wsdl:arrayType="" /> 
>   </restriction>
>   </complexContent>
>   </complexType>
>   </schema>
>   </wsdl:types>
> 
> -----Original Message-----
> From: Mike Burati [mailto:mburati@bowstreet.com]
> Sent: Monday, April 28, 2003 12:46 PM
> To: 'axis-user@ws.apache.org'
> Subject: RE: Performance degradation with 1.1RC1
> 
> 
> 
> Wish I had time to help, but I'm fairly booked solid at the moment.
> 
> I do have a question though, that's not clear from the below description.
> 
> Is this Client side AXIS only, Server side AXIS only, or are you switching
> both at once?
> 
> Eg, were you only trying
>   AXIS-RC1 -> AXIS-RC1 
>   AXIS-RC2 -> AXIS-RC2
> 
> or something more like:
>   .NET -> AXIS-RC1
>   .NET -> AXIS-RC2
>   AXIS-RC1 -> AXIS-RC1
>   AXIS-RC1 -> AXIS-RC2
> 
> It would help to know what scenarios were tried, to know if it's a slowdown
> all on server side vs all on client side vs half and half vs ...
> 
> Also, what max heap are you setting on the server's JVM?
> 
> If you were nearly maxing out the Java heap on RC1, then it may perform ok,
> and then even a small amount of additional memory used in RC2 putting you up
> to or over the max heap may cause it to GC enough to kill performance, even
> if RC2 were only a little bit more memory/object intensive than RC1.  If on
> the other hand, RC1 runs fast in a small heap (eg, 64m), but RC2 is slow
> even with a larger heap (eg, 256 or 512m), then you've got bigger
> problems...
> 
> 
> -----Original Message-----
> From: Ron Ridenour [mailto:rridenour@siterra.com]
> Sent: Monday, April 28, 2003 2:41 PM
> To: axis-user@ws.apache.org; dims@yahoo.com
> Subject: RE: Performance degradation with 1.1RC1
> 
> 
> Sorry about the subject line above.
> The performance drop is between RC1 and RC2.
> The drop is so significant that RC2 is all but
> unusable. I have had posts that were taking 
> a few seconds, now take 12, 20, or 40 seconds 
> per post.
> 
> I am using arrays, maps of arrays, and type inheritance.
> Basically I have a JavaBeans Graph where I have 
> 
> Class Model
> Class A extends Model
> Class B extends A
> Class C extends B
> Class D extends B
> Class E extends B
> Class F extends B
> 
> Class User extends A
> Class Role extends B
> 
> Class Attribute
> Class AttributeKey
> 
> C contains a HashMap of Attributes keyed by AttributeKey
> C contains a HashMap of User [] keyed by Role
> C contains contain arrays of D, E, F
> 
> C is the single parameter to be passed to the service.
> 
> This model runs with acceptable speed on RC1 but screetchs to a halt
> on RC2. Please help.
> 
> 
> 
> -----Original Message-----
> From: Davanum Srinivas [mailto:dims@yahoo.com]
> Sent: Sunday, April 27, 2003 8:21 AM
> To: axis-user@ws.apache.org
> Subject: RE: Performance degradation with 1.1RC1
> 
> 
> Stephen,
> 
> Sounds Serious. We should try to fix this ASAP (in 1.1 Final). Any help in
> diagnosing/narrowing-down the cause would be helpful. 
> 
> Thanks,
> dims
> 
> --- Stephen Graham <sg3@bigpond.com> wrote:
> > I've also seen performance with RC2 degrade sharply. It so bad, that we
> > don't use RC2 anymore - we've gone back to RC1. My preliminary
> > investigations into this showed the deserialisation of Vectors to be a
> major
> > bottleneck, but as yet I haven't been able to find out anything else - not
> > enough time!
> > 
> > Regards
> > Stephen.
> > 
> > > -----Original Message-----
> > > From: Ekbote, Niranjan [mailto:NEkbote@doubleclick.net] 
> > > Sent: 26 April 2003 10:17 AM
> > > To: 'Ron Ridenour '; 'axis-user@ws.apache.org '
> > > Subject: RE: Performance degradation with 1.1RC1
> > > 
> > > 
> > > Actuallty I have noticed that too. I didn't play around with 
> 
=== message truncated ===


=====
Davanum Srinivas - http://webservices.apache.org/~dims/

__________________________________
Do you Yahoo!?
The New Yahoo! Search - Faster. Easier. Bingo.
http://search.yahoo.com

Mime
View raw message