Return-Path: Delivered-To: apmail-ws-axis-user-archive@ws.apache.org Received: (qmail 87477 invoked by uid 500); 29 Apr 2003 00:21:23 -0000 Mailing-List: contact axis-user-help@ws.apache.org; run by ezmlm Precedence: bulk Reply-To: axis-user@ws.apache.org list-help: list-unsubscribe: list-post: Delivered-To: mailing list axis-user@ws.apache.org Received: (qmail 87467 invoked from network); 29 Apr 2003 00:21:22 -0000 X-MimeOLE: Produced By Microsoft Exchange V6.0.5762.3 content-class: urn:content-classes:message MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable Subject: RE: Performance degradation with 1.1RC1 Date: Mon, 28 Apr 2003 17:21:30 -0700 Message-ID: <512CB547BE60CD47A75A5A969E10FE1044E269@mail.internal.siterra.com> X-MS-Has-Attach: X-MS-TNEF-Correlator: Thread-Topic: Performance degradation with 1.1RC1 Thread-Index: AcMN4FIX/VVmYmZGRgeQIC4zDGDHrgAAIm+g From: "Ron Ridenour" To: , X-Spam-Rating: daedalus.apache.org 1.6.2 0/1000/N RC2 Complex object C only ( C extends B extends A )=20 2003-04-28 15:56:26,032 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D851 post=3D10 send=3D0 = LocationProcessor.processLocation 2003-04-28 15:57:08,122 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D881 post=3D10 send=3D20 = LocationProcessor.processLocation 2003-04-28 15:57:21,014 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D1241 post=3D90 send=3D30 = LocationProcessor.processLocation 2003-04-28 15:57:47,990 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D791 post=3D0 send=3D30 = LocationProcessor.processLocation 2003-04-28 15:58:27,157 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D811 post=3D0 send=3D30 = LocationProcessor.processLocation RC2 C + 9 Attributes ( Map of Attribute keyed by AttributeKey )=20 2003-04-28 15:53:18,714 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D20 invoke=3D3233 post=3D10 send=3D30 = LocationProcessor.processLocation 2003-04-28 15:54:22,024 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D3383 post=3D10 send=3D30 = LocationProcessor.processLocation 2003-04-28 15:55:45,103 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D30 invoke=3D2993 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 15:59:32,749 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2713 post=3D20 send=3D0 = LocationProcessor.processLocation 2003-04-28 15:59:57,883 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2683 post=3D20 send=3D30 = 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=3D0 invoke=3D5946 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:00:51,894 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D6576 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:01:41,882 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D6086 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:02:07,596 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D6446 post=3D0 send=3D0 = 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=3D0 invoke=3D12692 post=3D91 send=3D50 = LocationProcessor.processLocation 2003-04-28 16:03:26,681 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D14774 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:04:43,003 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D13042 post=3D0 send=3D30 = 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=3D0 invoke=3D14024 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:06:03,410 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D16236 post=3D10 send=3D20 = LocationProcessor.processLocation 2003-04-28 16:06:56,840 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D200 invoke=3D14754 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:08:10,260 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D100 invoke=3D17747 post=3D10 send=3D0 = LocationProcessor.processLocation RC2 C + E[9] 2003-04-28 17:14:07,162 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2584 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 17:15:04,334 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D30 invoke=3D3475 post=3D20 send=3D1612 = LocationProcessor.processLocation 2003-04-28 17:16:38,179 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D100 invoke=3D3255 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 17:17:13,309 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2553 post=3D10 send=3D30 = LocationProcessor.processLocation 2003-04-28 17:17:46,437 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D30 invoke=3D3675 post=3D10 send=3D30 = LocationProcessor.processLocation --------------- RC1 Complex object C only ( C extends B extends A )=20 2003-04-28 16:40:51,127 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D341 post=3D0 send=3D10 = LocationProcessor.processLocation 2003-04-28 16:42:00,807 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D421 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:43:08,184 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D381 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:43:20,111 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D421 post=3D0 send=3D30 = LocationProcessor.processLocation 2003-04-28 16:43:32,118 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D360 post=3D0 send=3D30 = LocationProcessor.processLocation RC1 C + 9 Attributes ( Map of Attribute keyed by AttributeKey )=20 2003-04-28 16:39:05,294 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D1061 post=3D20 send=3D30 = LocationProcessor.processLocation 2003-04-28 16:39:22,199 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D872 post=3D10 send=3D20 = LocationProcessor.processLocation 2003-04-28 16:39:35,278 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D841 post=3D10 send=3D31 = LocationProcessor.processLocation 2003-04-28 16:39:54,705 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D841 post=3D10 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:40:07,624 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D811 post=3D0 send=3D0 = 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=3D0 invoke=3D2343 post=3D10 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:36:44,272 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D20 invoke=3D2674 post=3D0 send=3D10 = LocationProcessor.processLocation 2003-04-28 16:37:08,066 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2814 post=3D0 send=3D10 = LocationProcessor.processLocation 2003-04-28 16:37:22,697 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2444 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:37:38,339 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D2473 post=3D0 send=3D0 = 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=3D0 invoke=3D4697 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:32:56,073 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D4907 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:33:45,705 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D4406 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:34:04,252 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D4647 post=3D0 send=3D10 = LocationProcessor.processLocation 2003-04-28 16:34:22,918 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D4476 post=3D0 send=3D0 = 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=3D2674 invoke=3D7460 post=3D11 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:28:18,785 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D5238 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:28:43,641 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D5598 post=3D110 send=3D31 = LocationProcessor.processLocation 2003-04-28 16:29:13,453 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D5077 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 16:29:55,183 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D5478 post=3D691 send=3D60 = LocationProcessor.processLocation RC1 C + E[9] 2003-04-28 16:59:08,204 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D1272 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 17:00:45,474 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D1172 post=3D0 send=3D0 = LocationProcessor.processLocation 2003-04-28 17:01:16,539 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D952 post=3D0 send=3D30 = LocationProcessor.processLocation 2003-04-28 17:02:03,827 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D10 invoke=3D932 post=3D0 send=3D10 = LocationProcessor.processLocation 2003-04-28 17:02:24,707 DEBUG [org.apache.axis.TIME] axisServlet.doPost: = "" pre=3D0 invoke=3D1032 post=3D0 send=3D0 = 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 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. >=20 > 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 >=20 > Beta > 2003-04-28 14:41:08,677 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D2162 invoke=3D7657 > post=3D0 send=3D10 > 2003-04-28 14:42:00,146 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D11 invoke=3D6035 > post=3D0 send=3D0 > 2003-04-28 14:42:29,664 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D10 invoke=3D6136 > post=3D0 send=3D0 > 2003-04-28 14:43:05,188 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D5846 > post=3D10 send=3D0 > 2003-04-28 14:43:23,515 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D5765 > post=3D0 send=3D0=20 >=20 > RC1 > 2003-04-28 13:53:12,628 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D4914 invoke=3D8679 > post=3D120 send=3D20=20 > 2003-04-28 13:55:29,057 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D6486 > post=3D0 send=3D0 > 2003-04-28 13:56:13,289 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D6326 > post=3D0 send=3D0 > 2003-04-28 13:57:06,620 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D8008 > post=3D0 send=3D0 > 2003-04-28 13:57:47,278 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D5965 > post=3D0 send=3D0 >=20 >=20 > RC2 > 2003-04-28 14:00:28,752 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D20780 > post=3D0 send=3D0=20 > 2003-04-28 14:03:58,551 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D10 invoke=3D16756 > post=3D40 send=3D40 > 2003-04-28 14:21:15,855 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D100 invoke=3D21210 > post=3D0 send=3D10 > 2003-04-28 14:22:19,175 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D20 invoke=3D17756 > post=3D0 send=3D0=20 > 2003-04-28 14:23:36,178 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D250 invoke=3D20219 > post=3D0 send=3D0=20 >=20 > Nightly > 2003-04-28 14:26:38,722 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D1622 > invoke=3D18768 post=3D200 send=3D10=20 > 2003-04-28 14:28:29,026 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D100 invoke=3D19468 > post=3D0 send=3D0=20 > 2003-04-28 14:34:10,260 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D1251 > invoke=3D18918 post=3D110 send=3D40=20 > 2003-04-28 14:35:49,184 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D0 invoke=3D17356 > post=3D0 send=3D0=20 > 2003-04-28 14:36:43,726 DEBUG [org.apache.axis.TIME] = axisServlet.doPost: "" pre=3D10 invoke=3D17597 > post=3D0 send=3D0=20 >=20 > 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. >=20 > Beta > >=20 > RC2 > xmlns:tns3=3D"http://www.w3.org/2002/12/soap-encoding" > >=20 > - xmlns=3D"http://www.w3.org/2001/XMLSchema"> > =20 > - > - > - > =20 > > > > > >=20 > -----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 >=20 >=20 >=20 > Wish I had time to help, but I'm fairly booked solid at the moment. >=20 > I do have a question though, that's not clear from the below = description. >=20 > Is this Client side AXIS only, Server side AXIS only, or are you = switching > both at once? >=20 > Eg, were you only trying > AXIS-RC1 -> AXIS-RC1=20 > AXIS-RC2 -> AXIS-RC2 >=20 > or something more like: > .NET -> AXIS-RC1 > .NET -> AXIS-RC2 > AXIS-RC1 -> AXIS-RC1 > AXIS-RC1 -> AXIS-RC2 >=20 > 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 ... >=20 > Also, what max heap are you setting on the server's JVM? >=20 > 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... >=20 >=20 > -----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 >=20 >=20 > 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=20 > a few seconds, now take 12, 20, or 40 seconds=20 > per post. >=20 > I am using arrays, maps of arrays, and type inheritance. > Basically I have a JavaBeans Graph where I have=20 >=20 > 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 >=20 > Class User extends A > Class Role extends B >=20 > Class Attribute > Class AttributeKey >=20 > 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 >=20 > C is the single parameter to be passed to the service. >=20 > This model runs with acceptable speed on RC1 but screetchs to a halt > on RC2. Please help. >=20 >=20 >=20 > -----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 >=20 >=20 > Stephen, >=20 > Sounds Serious. We should try to fix this ASAP (in 1.1 Final). Any = help in > diagnosing/narrowing-down the cause would be helpful.=20 >=20 > Thanks, > dims >=20 > --- Stephen Graham 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! > >=20 > > Regards > > Stephen. > >=20 > > > -----Original Message----- > > > From: Ekbote, Niranjan [mailto:NEkbote@doubleclick.net]=20 > > > Sent: 26 April 2003 10:17 AM > > > To: 'Ron Ridenour '; 'axis-user@ws.apache.org ' > > > Subject: RE: Performance degradation with 1.1RC1 > > >=20 > > >=20 > > > Actuallty I have noticed that too. I didn't play around with=20 >=20 =3D=3D=3D message truncated =3D=3D=3D =3D=3D=3D=3D=3D Davanum Srinivas - http://webservices.apache.org/~dims/ __________________________________ Do you Yahoo!? The New Yahoo! Search - Faster. Easier. Bingo. http://search.yahoo.com