Hi Andreas/Jeremias, Thanks for the quick responses. Provided below are my responses to your questions.
Thanks!! -----Original Message----- From: Andreas Delmelle [mailto:[EMAIL PROTECTED] Sent: Tuesday, February 12, 2008 2:22 PM To: [email protected] Subject: Re: Fop 0.20.5 vs Fop Trunk Performace On Feb 12, 2008, at 17:06, Puppala, Kumar (LNG-CON) wrote: Hi Kumar > We are currently using FOP 0.20.5 on our production boxes and > intend to use the latest FOP at some point this year. As such, we > are trying to gauge performance improvements between the two. > However, I am finding that the new FOP is taking more time to > render than the old one. The options used to run the FOP (both old > and new) are as shown below: > Just to be sure: which revision of the trunk are you trying out? --> I obtained the latest from the trunk on Jan 22nd. Information pertaining to the fopTrunk as seen in the status.xml file is: "status.xml 614201 2008-01-22 14:02:27Z jeremias" As Jeremias already pointed out, make sure that at least the FopFactory is instantiated only once (that was the whole point of its inception: to save time on reloading resources that can be shared between multiple runs). --> Yes, I am instantiating FopFactory just once. Initially I was not doing that but I changed my code to instantiate it just once. The results provided are with the change. Apart from that, focusing purely on FOP Trunk, if you know how to narrow it down to specific methods/calls that cause the increase in processing time that would help us a lot. --> I do have the complete Heap report. Some of the classes having maximum instances are as shown below: 463132 instances <http://dvc7632:7172/instances/0xb4d0a270> of class org.apache.fop.traits.MinOptMax <http://dvc7632:7172/class/0xb4d0a270> 441537 instances <http://dvc7632:7172/instances/0xb4d139a8> of class org.apache.fop.layoutmgr.NonLeafPosition <http://dvc7632:7172/class/0xb4d139a8> 386229 instances <http://dvc7632:7172/instances/0xb4bd3f50> of class org.apache.fop.fo.properties.CondLengthProperty <http://dvc7632:7172/class/0xb4bd3f50> 362166 instances <http://dvc7632:7172/instances/0xb4d33020> of class org.apache.fop.layoutmgr.LeafPosition <http://dvc7632:7172/class/0xb4d33020> 216985 instances <http://dvc7632:7172/instances/0xb4bd6648> of class org.apache.fop.fo.properties.SpaceProperty <http://dvc7632:7172/class/0xb4bd6648> 181359 instances <http://dvc7632:7172/instances/0xb4cf9dd0> of class org.apache.fop.layoutmgr.KnuthGlue <http://dvc7632:7172/class/0xb4cf9dd0> 164198 instances <http://dvc7632:7172/instances/0xb4d69638> of class org.apache.fop.layoutmgr.inline.TextLayoutManager$AreaInfo <http://dvc7632:7172/class/0xb4d69638> 140706 instances <http://dvc7632:7172/instances/0xb4d17690> of class org.apache.fop.layoutmgr.KnuthPenalty <http://dvc7632:7172/class/0xb4d17690> 107113 instances <http://dvc7632:7172/instances/0xb4c62c38> of class org.apache.fop.fo.properties.CommonBorderPaddingBackground <http://dvc7632:7172/class/0xb4c62c38> 107113 instances <http://dvc7632:7172/instances/0xb4c64700> of class [Lorg.apache.fop.fo.properties.CommonBorderPaddingBackground$BorderInfo; <http://dvc7632:7172/class/0xb4c64700> 104453 instances <http://dvc7632:7172/instances/0xb4d69f18> of class org.apache.fop.layoutmgr.inline.KnuthInlineBox <http://dvc7632:7172/class/0xb4d69f18> 91823 instances <http://dvc7632:7172/instances/0xb4c64c78> of class [Lorg.apache.fop.fo.properties.CondLengthProperty; <http://dvc7632:7172/class/0xb4c64c78> 84488 instances <http://dvc7632:7172/instances/0xb4cc3ac8> of class org.apache.fop.layoutmgr.LMiter <http://dvc7632:7172/class/0xb4cc3ac8> 78913 instances <http://dvc7632:7172/instances/0xb4d7acb0> of class org.apache.fop.area.inline.WordArea <http://dvc7632:7172/class/0xb4d7acb0> 73825 instances <http://dvc7632:7172/instances/0xb4c91138> of class org.apache.fop.fo.flow.table.BorderSpecification <http://dvc7632:7172/class/0xb4c91138> 70532 instances <http://dvc7632:7172/instances/0xb4c79380> of class org.apache.fop.datatypes.LengthBase <http://dvc7632:7172/class/0xb4c79380> 70532 instances <http://dvc7632:7172/instances/0xb4bdea20> of class org.apache.fop.fo.properties.PercentLength <http://dvc7632:7172/class/0xb4bdea20> 69942 instances <http://dvc7632:7172/instances/0xb4c7bbd8> of class org.apache.fop.fo.FObj$FObjIterator <http://dvc7632:7172/class/0xb4c7bbd8> 67494 instances <http://dvc7632:7172/instances/0xb4c92670> of class org.apache.fop.fo.flow.table.ConditionalBorder <http://dvc7632:7172/class/0xb4c92670> 63321 instances <http://dvc7632:7172/instances/0xb4d24378> of class org.apache.fop.traits.SpaceVal <http://dvc7632:7172/class/0xb4d24378> 62513 instances <http://dvc7632:7172/instances/0xb4d7a598> of class org.apache.fop.area.inline.SpaceArea <http://dvc7632:7172/class/0xb4d7a598> 60204 instances <http://dvc7632:7172/instances/0xb4c712e0> of class [Lorg.apache.fop.fo.FONode; <http://dvc7632:7172/class/0xb4c712e0> 50599 instances <http://dvc7632:7172/instances/0xb4d2c5a8> of class [Lorg.apache.fop.traits.MinOptMax; <http://dvc7632:7172/class/0xb4d2c5a8> I am not sure if this is something expected. I can provide the complete jmap dump (its 341 MB). Small question: Did you, by any chance, also try different JVM versions? Different platform? > /usr/local/jvta/jre1.6.0_02/bin/java -Djava.endorsed.dirs=/usr/ > local/java/pkgs/jmx1.0.1 -server -Xms128m -Xmx1024m - > XX:MaxPermSize=128m -verbose:gc -XX:+PrintGCDetails -XX: > +PrintGCTimeStamps -DJMX_1_2=true -D -Sqds_fop_dev5_001 -javaagent:/ > opt/wily/Agent.jar -Dcom.wily.introscope.agentProfile=/l-n/app/ > sysman/wily/default/Agent_tier1.profile - > Dcom.wily.introscope.agentName=FOP -Dpid=11403 > com.lxnx.ols.qds.fop.gen.server.FOPServer > --> No. I can try on jre1.6.0_04. Since we are running the current FOP on Solaris platform, we are performing our tests on Solaris. Do you know which XML parser / XSLT processor gets used at runtime? Not necessarily to shift the blame, but if you can check whether substituting one of those helps, that would again be very helpful. --> We do not use an XSLT processor. We generate the FO file using an in-house application and feed it to the FOP Server. Since I am using the default handler, I think it's using SAX Parser behind the scenes. > <snip /> > > Here are my findings after running: > > 1) After server startup, the initial transactions are not > that far apart from those obtained using old FOP. However, as time > progresses, I do see the time for the same transactions increases. > After about 15 such iterations, the processing time almost doubles. > So, (again focusing on FOP Trunk) this would mean that the processing time increases with the number of runs, or do I interpret this wrong? --> Yes, the processing time increases with the number of runs. In local tests I ran here, with two concurrent threads and a shared FopFactory instance, the processing time remains quite stable for me (test run on Apple JVM 1.5 using a document that generates two page- sequences (=2+69 pages; the larger page-sequence contains forced breaks for each page)) --> My tests are much more diverse. Each iteration contains about 120 testcases. Each testcase targets a specific feature that we use. Hence each such iteration covers most of the features like tables, cells, images, big documents, rowspanning, columnSpanning, dual column layout etc... In total I would say I am generating about 3000 pages per iteration. When comparing the results, I am comparing them after each such iteration for about 15 times and I am seeing a gradual increase in processing times. > 2) I do see a lot of garbage collection happening in the new > FOP. The collection times are also very high. I am hereby attaching > the garbage collection stats for both the old and new FOP for about > the same number of transactions (refer to newFop_SL.stdout.txt and > oldFop_SL_stdout.txt). Also a thread dump for the server running > new FOP is provided (threadDump_newFop.txt). > > 3) After using jmap and jhat to analyze the heap, I do see a > lot of objects consuming lot of memory in the new FOP. I am hereby > providing a spreadsheet containing Heap histograms for both the old > and new FOP for the same load (refer to HeapObjects.xls). Also, the > jmap output for the server using old and new FOP is provided (refer > to oldFopMap.txt and newFopMap.txt) > > 4) Documents containing lots of Images are rendered amazingly > fast (about 85% improvement). > That last bit is certainly good to know. The high ratio of GC is also to be expected, since both during parsing and layout, a lot of short-lived objects are created. FOP 0.20.5 simply offered the JVM less opportunity to clean up any mess. Come to think of it: are your images stored on a local disk, or is there any network traffic involved that might explain the increasing lag...? --> The images are stored on local disk. However, I do see better results for testcases containing Images and hence I do not believe that there are any network traffic issues involved. HTH! Cheers Andreas --------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
