Hello Richard, I progress on my testing, and I understand now why I did not get the same results than you ... I did two tests: one test on a machine with a relatively slow disk, and another test on a host whose disk is faster.
I did the test with the 213 bundles from glassfish 3.0.1 (glassfishv3/glassfish/modules/*.jar) Test on the host with the slow disk: ======================== I first measured the time needed to open a single file when disk buffers are flushed: 32 millis. (I did this to check that the disk io speed). Here are the results of the tests: * with felix 3.0.3 -> time to load an empty felix cache (with disk buffers flushed) = 9.2 millis time to load an existing felix cache (with dsk buffers flushed) = 14.9 millis * with felix trunk (optimized version that you uncommitted yesterday) -> time to load an empty felix cache (with disk buffers flushed) = 9.1 millis time to load an existing felix cache (with dsk buffers flushed) = 12.3 millis (here, we notice that it takes a longer time to load an existing felix cache, than an empty one, either with felix 3.0.3 or optimized felix trunk). Test on the host with the faster disk: ========================== Time needed to open a single file when disk buffers are flushed: 1 millis. * with felix 3.0.3 -> time to load an empty felix cache (with disk buffers flushed) = 8.1 millis time to load an existing felix cache (with dsk buffers flushed) = 5.3 millis * with felix trunk (optimized version that you recently uncommited) -> time to load an empty felix cache (with disk buffers flushed) = 7.9 millis time to load an existing felix cache (with dsk buffers flushed) = 4.7 millis (here, loading an existing felix cache is faster then an empty felix cache, as expected). So, in any cases, the optimized version of the trunk is faster than the 2.0.3. However, with a low disk IO rate, then it seems that it takes a longer time to load an existing felix cache than an empty one. /pierre On Tue, Oct 5, 2010 at 3:13 PM, Richard S. Hall <[email protected]>wrote: > On 10/5/10 2:59, Felix Meschberger wrote: > >> Hi, >> >> On 04.10.2010 22:26, Richard S. Hall wrote: >> >>> On 10/4/10 12:31, Pierre De Rop wrote: >>> >>>> This is surprising, because I double checked (I did the same kind of >>>> tests >>>> of differents machines), and I always see that loading a populated >>>> cache is >>>> a bit longer than an empty cache. >>>> Ok, it's confusing for now, I will do further investigation and will get >>>> back to you later, if I find something. >>>> >>> Let's keep investigating this. >>> >>> In the meantime, I decided to rollback the change for the next release >>> so we can have more time to investigate it because right now I need to >>> get a bug fix out. So, we won't introduce any bundle cache structure >>> changes in 3.0.4, but maybe in 3.0.5. >>> >> This sounds like a minor-release-number-worthy change ;-) >> > > I'm not sure that's necessary. It is still backward compatible, but it > isn't forward compatible. > > -> richard > > > Regards >> Felix >> >> -> richard >>> >>> On Mon, Oct 4, 2010 at 5:05 PM, Richard S. >>>> Hall<[email protected]>wrote: >>>> >>>> On 10/4/10 10:52, Richard S. Hall wrote: >>>>> >>>>> Thanks for the installer bundle, I did some tests locally on my Mac >>>>>> using >>>>>> 230 bundles from GlassFish, this is what I see (note: the "purge" >>>>>> command >>>>>> flushes disk buffers): >>>>>> >>>>>> Empty cache >>>>>> ----------------- >>>>>> [heavyweight main]$ rm -rf felix-cache; purge; date; java -jar >>>>>> bin/felix.jar >>>>>> Mon Oct 4 10:43:09 EDT 2010 >>>>>> 2010-10-04 10:43:24,541 - BundleInstaller starting and waiting for >>>>>> FrameworkEvent.STARTED event ... >>>>>> 2010-10-04 10:43:24,822 - Framework started: Installing bundles from >>>>>> ./load dir >>>>>> 2010-10-04 10:43:54,464 - Done. >>>>>> >>>>>> Populated cache >>>>>> ----------------------- >>>>>> [heavyweight main]$ purge; date; java -jar bin/felix.jar >>>>>> Mon Oct 4 10:44:49 EDT 2010 >>>>>> 2010-10-04 10:45:12,212 - BundleInstaller starting and waiting for >>>>>> FrameworkEvent.STARTED event ... >>>>>> 2010-10-04 10:45:13,340 - Framework started: Installing bundles from >>>>>> ./load dir >>>>>> 2010-10-04 10:45:13,342 - Done. >>>>>> >>>>>> You can see that the empty cache scenario takes about 45 seconds, >>>>>> whereas >>>>>> the populated cache takes about 24 seconds. So, on my machine, it >>>>>> takes a >>>>>> lot less time to re-load cached bundles...could be a function of my >>>>>> disk >>>>>> speed, I suppose, but it is what I would expect. >>>>>> >>>>>> Not sure how to proceed, other than trying to get more samples. >>>>>> >>>>>> Interestingly, I tried the same test using the 3.0.3 release (the >>>>> above was >>>>> with trunk) and I got the follow results: >>>>> >>>>> Empty cache (3.0.3) >>>>> ----------------- >>>>> >>>>> rm -rf felix-cache; purge; date; java -jar bin/felix.jar >>>>> Mon Oct 4 10:58:23 EDT 2010 >>>>> 2010-10-04 10:58:43,340 - BundleInstaller starting and waiting for >>>>> FrameworkEvent.STARTED event ... >>>>> 2010-10-04 10:58:43,557 - Framework started: Installing bundles from >>>>> ./load >>>>> dir >>>>> 2010-10-04 10:59:03,373 - Done. >>>>> >>>>> Populated cache (3.0.3) >>>>> ----------------------- >>>>> >>>>> purge; date; java -jar bin/felix.jar >>>>> Mon Oct 4 10:59:50 EDT 2010 >>>>> 2010-10-04 11:00:24,738 - BundleInstaller starting and waiting for >>>>> FrameworkEvent.STARTED event ... >>>>> 2010-10-04 11:00:26,736 - Framework started: Installing bundles from >>>>> ./load >>>>> dir >>>>> 2010-10-04 11:00:26,738 - Done. >>>>> >>>>> So, the populated cache takes nearly as long as the empty cache (36 >>>>> seconds >>>>> compared to 40 seconds)...this also makes sense, since the trunk has >>>>> patches >>>>> specifically designed to improve re-loading cached bundles. >>>>> >>>>> -> richard >>>>> >>>>> >>>>> >>>>> On Fri, Oct 1, 2010 at 11:30 PM,<[email protected]> wrote: >>>>>>> >>>>>>>> On Fri, 1 Oct 2010 23:25:35 +0200, Pierre De Rop< >>>>>>>>> [email protected]> >>>>>>>>> >>>>>>>>> wrote: >>>>>>>>>> >>>>>>>>>> On Fri, Oct 1, 2010 at 10:57 PM, Richard S. Hall >>>>>>>>>> >>>>>>>>>>> <[email protected]>wrote: >>>>>>>>>>> >>>>>>>>>>> One thing, was your performance comparison based on using >>>>>>>>>>> the new >>>>>>>>>>> cache >>>>>>>>>>> or >>>>>>>>>>> >>>>>>>>>>> old? >>>>>>>>>>>> >>>>>>>>>>>> I assume you are using a newly created cache for the framework >>>>>>>>>>>> snapshot >>>>>>>>>>>> and >>>>>>>>>>>> [obviously] an old cache for the 3.0.2, correct? >>>>>>>>>>>> >>>>>>>>>>>> yes: >>>>>>>>>>>> >>>>>>>>>>>> old cache with 3.0.2, and new cache with trunk. >>>>>>>>>>> but I also checked that new fwk/trunk is properly working when >>>>>>>>>>> being >>>>>>>>>>> started >>>>>>>>>>> with the old cache (from 3.0.2) >>>>>>>>>>> >>>>>>>>>>> You should also be testing an already created cache (i.e., a >>>>>>>>>>> framework >>>>>>>>>>> >>>>>>>>>>> restart), not an empty cache. >>>>>>>>>>>> >>>>>>>>>>>> In the previous test, I compared with already created cache, >>>>>>>>>>>> not >>>>>>>>>>>> with >>>>>>>>>>>> >>>>>>>>>>>> empty >>>>>>>>>>> >>>>>>>>>> caches. >>>>>>>>>> >>>>>>>>>>> With empty caches, here are the results: >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> - old fwk 3.0.2 / fresh empty cache -> 15.8 sec. (this is >>>>>>>>>>> surprising: >>>>>>>>>>> >>>>>>>>>>> I >>>>>>>>>>> >>>>>>>>>> would expect to get a longer delay, since the cache is >>>>>>>>>> empty when >>>>>>>>>> >>>>>>>>>>> I >>>>>>>>>>> start >>>>>>>>>>> the fwk) >>>>>>>>>>> >>>>>>>>>>> 2010-10-01 23:10:17,403 Starting Felix 3.0.2 >>>>>>>>>>> 2010-10-01 23:10:23,885 Starting cluster node "test" >>>>>>>>>>> 2010-10-01 23:10:33,208 Cluster node "test" ready >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> - new fwk / fresh empty cache ->15.2 sec >>>>>>>>>>> >>>>>>>>>>> 2010-10-01 23:15:46,2 Starting Felix 3.1.0.SNAPSHOT >>>>>>>>>>> 2010-10-01 23:15:52,417 Starting cluster node "test" >>>>>>>>>>> 2010-10-01 23:16:01,225 Cluster node "test" ready >>>>>>>>>>> >>>>>>>>>>> hmmm, I don't understand why the fwk startup time is better >>>>>>>>>>> when the >>>>>>>>>>> >>>>>>>>>>> cache >>>>>>>>>>> >>>>>>>>>> is empty (15.2 sec) than when the cache is non-empty (21.2 sec >>>>>>>>>> from >>>>>>>>>> >>>>>>>>>>> previous >>>>>>>>>>> mail) >>>>>>>>>>> Ok, I will do more tests ... may be I did something wrong ? ... >>>>>>>>>>> to be >>>>>>>>>>> continued ... >>>>>>>>>>> >>>>>>>>>>> Hmm. Yeah, that seems a little odd. In that case, you should >>>>>>>>>>> just >>>>>>>>>>> >>>>>>>>>> delete >>>>>>>>>> your cache each time to get better startup performance! ;-) >>>>>>>>>> >>>>>>>>>> Definitely let me know what you find out. I too would expect >>>>>>>>>> framework >>>>>>>>>> restarts to be faster since we don't have to copy the JAR files >>>>>>>>>> first. >>>>>>>>>> >>>>>>>>>> -> richard >>>>>>>>>> >>>>>>>>>> /pierre >>>>>>>>>> >>>>>>>>>> >>>>>>>>>>> Is that what you are doing? Just want to make sure I >>>>>>>>>>> understand what >>>>>>>>>>> is >>>>>>>>>>> >>>>>>>>>>> being measured. :-) >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> -> richard >>>>>>>>>>>> >>>>>>>>>>>> On 10/1/10 16:43, Pierre De Rop wrote: >>>>>>>>>>>> >>>>>>>>>>>> Hi Richard, >>>>>>>>>>>> >>>>>>>>>>>> I tried our app server with the trunk (old cache with the new >>>>>>>>>>>>> >>>>>>>>>>>>> fwk/trunk) >>>>>>>>>>>>> >>>>>>>>>>>> -> >>>>>>>>>>> >>>>>>>>>>> everything works ok >>>>>>>>>>>> >>>>>>>>>>>>> (I install 195 bundles, and start 41 bundles) >>>>>>>>>>>>> >>>>>>>>>>>>> With new cache/fwk trunk -> it's also ok. >>>>>>>>>>>>> >>>>>>>>>>>>> I also compared the performance of the startup time between >>>>>>>>>>>>> felix >>>>>>>>>>>>> >>>>>>>>>>>>> 2.0.2 >>>>>>>>>>>>> >>>>>>>>>>>> and >>>>>>>>>>> >>>>>>>>>>> felix trunk. >>>>>>>>>>>> >>>>>>>>>>>>> To do this, I managed to ensure that my linux IO buffers >>>>>>>>>>>>> cache are >>>>>>>>>>>>> >>>>>>>>>>>>> empty >>>>>>>>>>>>> >>>>>>>>>>>> before doing each test, by doing this: >>>>>>>>>>> >>>>>>>>>>> sync >>>>>>>>>>>> >>>>>>>>>>>>> echo 1> /proc/sys/vm/drop_caches >>>>>>>>>>>>> echo 2> /proc/sys/vm/drop_caches >>>>>>>>>>>>> echo 3> /proc/sys/vm/drop_caches >>>>>>>>>>>>> >>>>>>>>>>>>> This ensures that my linux has released all buffer cache >>>>>>>>>>>>> disk, like >>>>>>>>>>>>> it >>>>>>>>>>>>> is >>>>>>>>>>>>> the case when I boot my host (cold start). >>>>>>>>>>>>> Now, for felix 3.0.2, I load my server in around *21,1 *seconds >>>>>>>>>>>>> (it's >>>>>>>>>>>>> slow >>>>>>>>>>>>> because all disk buffers are empty): >>>>>>>>>>>>> >>>>>>>>>>>>> 2010-10-01 22:15:07,880 Starting Felix 3.0.2 >>>>>>>>>>>>> 2010-10-01 22:15:18,121 Starting cluster node "test" >>>>>>>>>>>>> 2010-10-01 22:15:28,966 Cluster node "test" ready >>>>>>>>>>>>> >>>>>>>>>>>>> and with felix/trunk, indeed, the server starts a little bit >>>>>>>>>>>>> quicker, >>>>>>>>>>>>> but >>>>>>>>>>>>> not so much: around *in 20,3* seconds (I also flushed disk >>>>>>>>>>>>> buffers >>>>>>>>>>>>> before >>>>>>>>>>>>> starting the test): >>>>>>>>>>>>> >>>>>>>>>>>>> 2010-10-01 22:17:47,505 Starting Felix 3.1.0.SNAPSHOT >>>>>>>>>>>>> 2010-10-01 22:17:56,815 Starting cluster node "test" >>>>>>>>>>>>> 2010-10-01 22:18:07,798 Cluster node "test" ready >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> /pierre >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> On Fri, Oct 1, 2010 at 5:39 PM, Richard S. Hall< >>>>>>>>>>>>> [email protected] >>>>>>>>>>>>> >>>>>>>>>>>>> wrote: >>>>>>>>>>>>> >>>>>>>>>>>>>> p.s. I deploy snapshots of the everything, including the >>>>>>>>>>>>>> >>>>>>>>>>>>> convenience >>>>>>>>>>>>> >>>>>>>>>>>>> framework distribution or you can build from trunk. >>>>>>>>>>>>> >>>>>>>>>>>>>> On 10/1/10 11:37, Richard S. Hall wrote: >>>>>>>>>>>>>> >>>>>>>>>>>>>> Hey everyone, >>>>>>>>>>>>>> >>>>>>>>>>>>>> I've made some changes to the bundle cache layout and >>>>>>>>>>>>>> handling to >>>>>>>>>>>>>> >>>>>>>>>>>>>>> improve >>>>>>>>>>>>>>> performance and clean up code. I've tried to maintain >>>>>>>>>>>>>>> backward >>>>>>>>>>>>>>> compatibility >>>>>>>>>>>>>>> with old caches, but I'd appreciate is someone could try it >>>>>>>>>>>>>>> out >>>>>>>>>>>>>>> on >>>>>>>>>>>>>>> their >>>>>>>>>>>>>>> caches to see if it works. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> ** Back up your caches just in case! ** >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Note that the new cache format will not work with older >>>>>>>>>>>>>>> frameworks. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> So >>>>>>>>>>>>>>> >>>>>>>>>>>>>> you >>>>>>>>>>>>> >>>>>>>>>>>> cannot use a cache created with this new framework with previous >>>>>>>>>>>> >>>>>>>>>>>>> frameworks; >>>>>>>>>>>>>>> however, previously created caches should mostly continue >>>>>>>>>>>>>>> to work >>>>>>>>>>>>>>> between >>>>>>>>>>>>>>> the two although there will be a loss of fidelity since >>>>>>>>>>>>>>> changes >>>>>>>>>>>>>>> to >>>>>>>>>>>>>>> state >>>>>>>>>>>>>>> are >>>>>>>>>>>>>>> only saved to the new way or the old way depending on if >>>>>>>>>>>>>>> you are >>>>>>>>>>>>>>> running >>>>>>>>>>>>>>> on >>>>>>>>>>>>>>> the new framework or the old one. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> For the curious, I've combined five bundle cache files (id, >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> location, >>>>>>>>>>>>>>> >>>>>>>>>>>>>> state, start level, last modified, and refresh count) into a >>>>>>>>>>>>> single >>>>>>>>>>>>> >>>>>>>>>>>> file >>>>>>>>>>>> >>>>>>>>>>>>> and >>>>>>>>>>>>>>> try to avoid excessive file accesses. This appears to improve >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> startup >>>>>>>>>>>>>>> >>>>>>>>>>>>>> time >>>>>>>>>>>>> >>>>>>>>>>>> when you have a cache with lots of bundles, but your mileage >>>>>>>>>>>> will >>>>>>>>>>>> >>>>>>>>>>>>> vary >>>>>>>>>>>>>>> >>>>>>>>>>>>>> based >>>>>>>>>>>>> >>>>>>>>>>>> on platform and other factors. Although, you won't necessarily >>>>>>>>>>>> see >>>>>>>>>>>> >>>>>>>>>>>>> any >>>>>>>>>>>>>>> >>>>>>>>>>>>>> improvements if you are using an old cache, since it will >>>>>>>>>>>>> revert to >>>>>>>>>>>>> >>>>>>>>>>>> the >>>>>>>>>>>> >>>>>>>>>>>>> old >>>>>>>>>>>>>>> way. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Thanks. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> -> richard >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>>
