Interesting... so the performance degrades in a linear fashion as a
function of the total number of the created contexts. Quick glance at
the code suggests this may have something to do with registering
DataContext's ObjectStore as a listener for the parent cache events.
Not sure what exactly causes it without deeper investigation.
If you have a chance to run it in profiler, and can find the actual
bottleneck, please share. And in any event I'd appreciate if you
could submit a Jira issue:
http://issues.apache.org/cayenne/
Thanks
Andrus
On Oct 16, 2006, at 1:03 PM, nakamurakenich..ail.goo.ne.jp wrote:
> Hello,
>
> I have used Cayenne-1.1.4 and I tried 1.2.1.
> I found 1.2.1's DataContext#createDataContext is much slower than
> 1.1.4's.
>
> The benchmark is:
>
> public void testLoop() {
> for (int i = 0; i < 100; i ++) {
> long before = System.currentTimeMillis();
> for (int ii = 0; ii < 100; ii ++) {
> DataContext.createDataContext();
> }
> System.out.println("iter:" + i + " time:" +
> (System.currentTimeMillis() - before));
> }
> }
>
>
> 1.1.4's result:
>
> iter:0 time:160
> iter:1 time:80
> iter:2 time:60
> iter:3 time:60
> iter:4 time:130
> iter:5 time:50
> iter:6 time:50
> iter:7 time:70
> iter:8 time:61
> iter:9 time:150
> iter:10 time:80
> iter:11 time:60
> iter:12 time:80
> iter:13 time:70
> iter:14 time:190
> iter:15 time:61
> iter:16 time:60
> iter:17 time:60
> iter:18 time:70
> iter:19 time:170
> iter:20 time:60
> iter:21 time:100
> iter:22 time:80
> iter:23 time:161
> iter:24 time:80
> iter:25 time:90
> iter:26 time:80
> iter:27 time:100
> iter:28 time:200
> iter:29 time:81
> iter:30 time:80
> iter:31 time:110
> iter:32 time:80
> iter:33 time:230
> iter:34 time:211
> iter:35 time:100
> iter:36 time:100
> iter:37 time:110
> iter:38 time:140
> iter:39 time:211
> iter:40 time:110
> iter:41 time:110
> iter:42 time:120
> iter:43 time:130
> iter:44 time:221
> iter:45 time:140
> iter:46 time:120
> iter:47 time:150
> iter:48 time:140
> iter:49 time:251
> iter:50 time:150
> iter:51 time:160
> iter:52 time:150
> iter:53 time:161
> iter:54 time:170
> iter:55 time:270
> iter:56 time:211
> iter:57 time:180
> iter:58 time:190
> iter:59 time:200
> iter:60 time:181
> iter:61 time:320
> iter:62 time:220
> iter:63 time:221
> iter:64 time:230
> iter:65 time:260
> iter:66 time:331
> iter:67 time:240
> iter:68 time:251
> iter:69 time:250
> iter:70 time:260
> iter:71 time:241
> iter:72 time:360
> iter:73 time:261
> iter:74 time:260
> iter:75 time:260
> iter:76 time:231
> iter:77 time:260
> iter:78 time:250
> iter:79 time:331
> iter:80 time:270
> iter:81 time:251
> iter:82 time:250
> iter:83 time:260
> iter:84 time:271
> iter:85 time:380
> iter:86 time:271
> iter:87 time:290
> iter:88 time:290
> iter:89 time:281
> iter:90 time:300
> iter:91 time:411
> iter:92 time:310
> iter:93 time:291
> iter:94 time:340
> iter:95 time:301
> iter:96 time:320
> iter:97 time:431
> iter:98 time:320
> iter:99 time:321
>
>
> 1.2.1's result:
>
> iter:0 time:90
> iter:1 time:60
> iter:2 time:80
> iter:3 time:100
> iter:4 time:90
> iter:5 time:90
> iter:6 time:91
> iter:7 time:110
> iter:8 time:100
> iter:9 time:120
> iter:10 time:130
> iter:11 time:140
> iter:12 time:141
> iter:13 time:180
> iter:14 time:210
> iter:15 time:301
> iter:16 time:170
> iter:17 time:210
> iter:18 time:220
> iter:19 time:231
> iter:20 time:240
> iter:21 time:240
> iter:22 time:290
> iter:23 time:280
> iter:24 time:331
> iter:25 time:360
> iter:26 time:351
> iter:27 time:370
> iter:28 time:421
> iter:29 time:411
> iter:30 time:450
> iter:31 time:451
> iter:32 time:501
> iter:33 time:610
> iter:34 time:521
> iter:35 time:541
> iter:36 time:561
> iter:37 time:551
> iter:38 time:701
> iter:39 time:590
> iter:40 time:591
> iter:41 time:611
> iter:42 time:641
> iter:43 time:651
> iter:44 time:671
> iter:45 time:691
> iter:46 time:651
> iter:47 time:701
> iter:48 time:691
> iter:49 time:871
> iter:50 time:741
> iter:51 time:751
> iter:52 time:781
> iter:53 time:812
> iter:54 time:801
> iter:55 time:811
> iter:56 time:831
> iter:57 time:851
> iter:58 time:852
> iter:59 time:1001
> iter:60 time:881
> iter:61 time:942
> iter:62 time:941
> iter:63 time:951
> iter:64 time:962
> iter:65 time:1111
> iter:66 time:1012
> iter:67 time:1252
> iter:68 time:1021
> iter:69 time:1032
> iter:70 time:1041
> iter:71 time:1072
> iter:72 time:1041
> iter:73 time:1072
> iter:74 time:1091
> iter:75 time:1092
> iter:76 time:1141
> iter:77 time:1112
> iter:78 time:1162
> iter:79 time:1171
> iter:80 time:1162
> iter:81 time:1172
> iter:82 time:1181
> iter:83 time:1212
> iter:84 time:1232
> iter:85 time:1222
> iter:86 time:1231
> iter:87 time:1212
> iter:88 time:1292
> iter:89 time:1272
> iter:90 time:1272
> iter:91 time:1282
> iter:92 time:1281
> iter:93 time:1312
> iter:94 time:1372
> iter:95 time:1322
> iter:96 time:1362
> iter:97 time:1372
> iter:98 time:1402
> iter:99 time:1402
>
>
> In 1.1.4, DataContext#createDataContext was enough fast after 10000
> times iteration
> so I didn't find performance sink after iteration.
>
> The performance behavior is by design? Or do I forget something to
> close?
> Should I use some object pooling for DataContext?
>
This archive was generated by hypermail 2.0.0 : Fri Oct 27 2006 - 16:08:24 EDT