I've made a first pass at fixing this. Some profiling revealed a case where "contains" was being called on an ArrayList containing every entity in the transaction.

Currently, the fix is checked into Branch_3_0. I'll migrate it to HEAD and Branch_3_2 as soon as I find the time.

In general, the performance is 2 - 4 times better than it was.


Here's some performance comparisons, run on my 667Mhz Mac, using hsqldb:

BEFORE (with 1000 beans):

22:21:18,622 INFO [STDOUT] creating 1000 Blobs...
22:21:39,016 INFO [STDOUT] Creation complete, took 20391ms.
22:21:44,309 INFO [STDOUT] testing retrival speed...
22:21:44,311 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:21:44,581 INFO [STDOUT] finder took 268ms.
22:21:50,336 INFO [STDOUT] External ValueObject creation took 5753ms for 1000 objects.
22:21:51,858 INFO [STDOUT] Internal ValueObject creation took 1519ms for 1000 objects.
22:21:51,861 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:21:52,457 INFO [STDOUT] finder took 589ms.
22:21:57,761 INFO [STDOUT] External ValueObject creation took 5301ms for 1000 objects.
22:21:59,272 INFO [STDOUT] Internal ValueObject creation took 1508ms for 1000 objects.
22:22:29,303 INFO [STDOUT] testing retrival speed...
22:22:29,305 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:22:29,808 INFO [STDOUT] finder took 501ms.
22:22:36,482 INFO [STDOUT] External ValueObject creation took 6672ms for 1000 objects.
22:22:37,988 INFO [STDOUT] Internal ValueObject creation took 1504ms for 1000 objects.
22:22:37,990 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:22:38,597 INFO [STDOUT] finder took 605ms.
22:22:43,968 INFO [STDOUT] External ValueObject creation took 5368ms for 1000 objects.
22:22:45,490 INFO [STDOUT] Internal ValueObject creation took 1520ms for 1000 objects.
22:24:56,018 INFO [EntityContainer] flushing cache
22:25:32,450 INFO [EntityContainer] flushing cache
22:25:49,847 INFO [STDOUT] testing retrival speed...
22:25:49,849 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:25:50,321 INFO [STDOUT] finder took 470ms.
22:26:03,023 INFO [STDOUT] External ValueObject creation took 12700ms for 1000 objects.
22:26:04,586 INFO [STDOUT] Internal ValueObject creation took 1561ms for 1000 objects.
22:26:04,589 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:26:05,169 INFO [STDOUT] finder took 579ms.
22:26:10,496 INFO [STDOUT] External ValueObject creation took 5324ms for 1000 objects.
22:26:12,015 INFO [STDOUT] Internal ValueObject creation took 1516ms for 1000 objects.

AFTER (with 1000 beans):

22:33:35,577 INFO [STDOUT] creating 1000 Blobs...
22:33:51,482 INFO [STDOUT] Creation complete, took 15902ms.
22:33:56,738 INFO [STDOUT] testing retrival speed...
22:33:56,741 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:33:57,001 INFO [STDOUT] finder took 259ms.
22:33:59,286 INFO [STDOUT] External ValueObject creation took 2282ms for 1000 objects.
22:34:00,071 INFO [STDOUT] Internal ValueObject creation took 783ms for 1000 objects.
22:34:00,074 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:34:00,682 INFO [STDOUT] finder took 601ms.
22:34:02,594 INFO [STDOUT] External ValueObject creation took 1909ms for 1000 objects.
22:34:03,350 INFO [STDOUT] Internal ValueObject creation took 753ms for 1000 objects.
22:34:35,272 INFO [STDOUT] testing retrival speed...
22:34:35,275 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:34:35,758 INFO [STDOUT] finder took 482ms.
22:34:37,781 INFO [STDOUT] External ValueObject creation took 2021ms for 1000 objects.
22:34:38,538 INFO [STDOUT] Internal ValueObject creation took 754ms for 1000 objects.
22:34:38,541 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:34:39,134 INFO [STDOUT] finder took 592ms.
22:34:41,036 INFO [STDOUT] External ValueObject creation took 1900ms for 1000 objects.
22:34:41,795 INFO [STDOUT] Internal ValueObject creation took 757ms for 1000 objects.
22:35:01,771 INFO [EntityContainer] flushing cache
22:35:14,727 INFO [EntityContainer] flushing cache
22:35:24,426 INFO [STDOUT] testing retrival speed...
22:35:24,428 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:35:24,929 INFO [STDOUT] finder took 499ms.
22:35:34,056 INFO [STDOUT] External ValueObject creation took 9125ms for 1000 objects.
22:35:34,849 INFO [STDOUT] Internal ValueObject creation took 791ms for 1000 objects.
22:35:34,851 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:35:36,758 INFO [STDOUT] finder took 1905ms.
22:35:38,670 INFO [STDOUT] External ValueObject creation took 1910ms for 1000 objects.
22:35:39,461 INFO [STDOUT] Internal ValueObject creation took 789ms for 1000 objects.


BEFORE (2000 beans):

22:42:28,295 INFO [STDOUT] creating 2000 Blobs...
22:43:14,521 INFO [STDOUT] Creation complete, took 46224ms.
22:43:24,276 INFO [STDOUT] testing retrival speed...
22:43:24,279 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:43:24,701 INFO [STDOUT] finder took 421ms.
22:43:42,588 INFO [STDOUT] External ValueObject creation took 17885ms for 2000 objects.
22:43:47,016 INFO [STDOUT] Internal ValueObject creation took 4425ms for 2000 objects.
22:43:47,018 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:43:48,780 INFO [STDOUT] finder took 1755ms.
22:44:08,220 INFO [STDOUT] External ValueObject creation took 19436ms for 2000 objects.
22:44:12,629 INFO [STDOUT] Internal ValueObject creation took 4406ms for 2000 objects.
22:44:46,010 INFO [STDOUT] testing retrival speed...
22:44:46,012 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:44:47,585 INFO [STDOUT] finder took 1570ms.
22:45:06,972 INFO [STDOUT] External ValueObject creation took 19385ms for 2000 objects.
22:45:11,310 INFO [STDOUT] Internal ValueObject creation took 4335ms for 2000 objects.
22:45:11,313 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:45:13,046 INFO [STDOUT] finder took 1732ms.
22:45:30,442 INFO [STDOUT] External ValueObject creation took 17393ms for 2000 objects.
22:45:34,823 INFO [STDOUT] Internal ValueObject creation took 4378ms for 2000 objects.
22:45:58,992 INFO [EntityContainer] flushing cache
22:46:12,849 INFO [EntityContainer] flushing cache
22:46:24,904 INFO [STDOUT] testing retrival speed...
22:46:24,907 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:46:26,492 INFO [STDOUT] finder took 1584ms.
22:47:01,802 INFO [STDOUT] External ValueObject creation took 35306ms for 2000 objects.
22:47:06,211 INFO [STDOUT] Internal ValueObject creation took 4407ms for 2000 objects.
22:47:06,214 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:47:09,753 INFO [STDOUT] finder took 3538ms.
22:47:27,095 INFO [STDOUT] External ValueObject creation took 17340ms for 2000 objects.
22:47:31,495 INFO [STDOUT] Internal ValueObject creation took 4398ms for 2000 objects.


AFTER (2000 beans):

22:52:21,702 INFO [STDOUT] creating 2000 Blobs...
22:52:50,826 INFO [STDOUT] Creation complete, took 29122ms.
22:53:00,532 INFO [STDOUT] testing retrival speed...
22:53:00,535 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:53:00,951 INFO [STDOUT] finder took 414ms.
22:53:05,284 INFO [STDOUT] External ValueObject creation took 4330ms for 2000 objects.
22:53:06,773 INFO [STDOUT] Internal ValueObject creation took 1487ms for 2000 objects.
22:53:06,775 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:53:08,558 INFO [STDOUT] finder took 1776ms.
22:53:12,387 INFO [STDOUT] External ValueObject creation took 3826ms for 2000 objects.
22:53:13,869 INFO [STDOUT] Internal ValueObject creation took 1478ms for 2000 objects.
22:53:36,865 INFO [STDOUT] testing retrival speed...
22:53:36,867 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:53:38,437 INFO [STDOUT] finder took 1568ms.
22:53:42,490 INFO [STDOUT] External ValueObject creation took 4050ms for 2000 objects.
22:53:43,934 INFO [STDOUT] Internal ValueObject creation took 1441ms for 2000 objects.
22:53:43,936 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:53:48,015 INFO [STDOUT] finder took 4077ms.
22:53:51,795 INFO [STDOUT] External ValueObject creation took 3778ms for 2000 objects.
22:53:53,266 INFO [STDOUT] Internal ValueObject creation took 1468ms for 2000 objects.
22:54:20,212 INFO [EntityContainer] flushing cache
22:54:34,433 INFO [EntityContainer] flushing cache
22:54:47,587 INFO [STDOUT] testing retrival speed...
22:54:47,590 INFO [STDOUT] Initial Retrival, beans may or maynot be in cache.
22:54:49,200 INFO [STDOUT] finder took 1609ms.
22:55:10,730 INFO [STDOUT] External ValueObject creation took 21527ms for 2000 objects.
22:55:12,206 INFO [STDOUT] Internal ValueObject creation took 1473ms for 2000 objects.
22:55:12,209 INFO [STDOUT] Secondary Retrival, beans are in cache.
22:55:13,980 INFO [STDOUT] finder took 1770ms.
22:55:17,771 INFO [STDOUT] External ValueObject creation took 3789ms for 2000 objects.
22:55:19,230 INFO [STDOUT] Internal ValueObject creation took 1456ms for 2000 objects.


As always, YMV!

Regards,

Steve Coy

On Friday, November 8, 2002, at 08:28 AM, Luttrell, Peter wrote:

Over the last couple of weeks i started a couple threads about CMP performance in JBoss. Bill asked for comparison with what Weblogic can do, so i got my test case to work with it and the results speak for themselves.
 
 
-> Weblogic 7 is 330% to 715% faster then JBoss3.0.4 in the one test that I did. All code used is attached.
 
 
Output. Reference the other email threads for an overview of what I'm doing in the code and the confirmation that read-aheads are configured properly...or just look at the code/deployment descriptors.
 
JBoss3.0.4:
14:31:36,312 INFO  [STDOUT] creating 1000 Blobs...
14:31:43,968 INFO  [STDOUT] Creation complete, took 7656ms.
14:31:46,328 INFO  [STDOUT] testing retrival speed...
14:31:46,328 INFO  [STDOUT] Initial Retrival, beans may or maynot be in cache.
14:31:46,375 INFO  [STDOUT]     finder took 47ms.
14:31:49,140 INFO  [STDOUT]     External ValueObject creation took 2765ms for 1000 objects.
14:31:49,859 INFO  [STDOUT]     Internal ValueObject creation took 719ms for 1000 objects.
14:31:49,859 INFO  [STDOUT] Secondary Retrival, beans are in cache.
14:31:50,125 INFO  [STDOUT]     finder took 266ms.
14:31:52,765 INFO  [STDOUT]     External ValueObject creation took 2640ms for 1000 objects.
14:31:53,437 INFO  [STDOUT]     Internal ValueObject creation took 672ms for 1000 objects.

Note the 672 on the last line. With all of the object cached (which they will be), this is what would happen in production.
 
 
Weblogic7:
creating 1000 Blobs...
Creation complete, took 10297ms.
testing retrival speed...
Initial Retrival, beans may or maynot be in cache.
        finder took 422ms.
        External ValueObject creation took 8906ms for 1000 objects.
        Internal ValueObject creation took 47ms for 1000 objects.
Secondary Retrival, beans are in cache.
        finder took 235ms.
        External ValueObject creation took 171ms for 1000 objects.
        Internal ValueObject creation took 47ms for 1000 objects.
Note the 47ms on the last line. With all of the object cached (which they will be), this is what would happen in production. In other runs, i've seen this number as low as 31ms.

 
 
So for the findAll and get all data:
 
JBoss External ValueObject Creation: 266 + 2640 = 2906

JBoss Internal ValueObject Creation: 266 + 672 = 939
Weblogic External ValueObject Creation: 235 + 171 = 406 (715% faster)
Weblogic Internal ValueObject Creation: 235 + 47 = 282 (330% faster)
 
Side notes: With Weblogic i was going against Oracle vs Hypersonic in JBoss. This explains the difference in the initial reading in of the beans. But since both examples are 100% cached beans the db should not matter, except for the finder methods call to get all primary keys from db.
 
 
Closing Notes: I am a big JBoss fan. I would like these numbers to be totally wrong, or for me to have misconfigured JBoss in some way. If you can get JBoss to perform better then this, PLEASE tell us all how. All the code is attached.
 
.peter
 
<as always ignore my company's crazy warning message below>
<jboss.zip><weblogic.zip>

Reply via email to