Jump to content
Changes to the Jaspersoft community edition download ×

Long Reports Timing and Profiler Results


Recommended Posts

By: Claudio Pi - claudiopi

Long Reports Timing and Profiler Results

2003-07-12 07:51

Long Reports Timing and Profiler Results

 

Hi:

 

We have developed a web application that contains aprox. 40 JasperReports.

We are going into production soon and we are having performance problems regarding the large ones (between 5000 and 10000 rows and 15 columns).

 

 

I have already read the thread http://sourceforge.net/forum/message.php?msg_id=1746461, but found no answer to the problem.

 

So I decided to use JProfiler to see what was going on.

 

Test enviroment:

 

PIV 1.7Ghz, 512Mb RAM, WinXP SP 1

Sun JDK 1.4.2

JasperReports 0.5.0

itext 0.96

Tomcat 4.1.24

MS SQLServer 2000 SP3.

 

 

 

Test case:

 

Report with 5360 Rows and 14 columns.

 

Timing Results (in average):

 

Total Time (without profiler running) 44183ms (70ms parameters, 260ms query and resultset load, 43853 report filling).

 

Partial Invocation Tree View (Percentage of time in each method, I hope this is posted ok, if not I have an HTML version of it):

 

 

--------------------------------------------------------------------------------

93.0% - 260082 ms - 1 inv. dori.jasper.engine.JasperRunManager.runReportToPdf

82.7% - 231269 ms - 1 inv. dori.jasper.engine.JasperFillManager.fillReport

82.4% - 230289 ms - 1 inv. dori.jasper.engine.JasperFillManager.fillReport

82.3% - 230147 ms - 1 inv. dori.jasper.engine.fill.JRFiller.fillReport

81.2% - 227118 ms - 1 inv. dori.jasper.engine.fill.JRBaseFiller.fill

81.2% - 227099 ms - 1 inv. dori.jasper.engine.fill.JRVerticalFiller.fillReport

69.8% - 195070 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillReportContent

68.1% - 190500 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillDetail

61.2% - 171169 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillColumnBand

39.6% - 110598 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.fill

39.6% - 110582 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.fill

36.2% - 101259 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.prepareElements

35.5% - 99353 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.prepare

34.0% - 95163 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.chopTextElement

10.5% - 29275 ms - 75026 inv. java.awt.font.LineBreakMeasurer.<init>

10.3% - 28708 ms - 75026 inv. java.awt.font.LineBreakMeasurer.nextLayout

5.4% - 15076 ms - 150052 inv. java.awt.font.TextLayout.getLeading

2.6% - 7361 ms - 75026 inv. java.text.AttributedString.<init>

0.5% - 1280 ms - 75026 inv. java.text.AttributedString.getIterator

0.3% - 934 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.setStretchHeight

0.2% - 577 ms - 75026 inv. java.util.StringTokenizer.nextToken

0.2% - 451 ms - 75026 inv. java.util.StringTokenizer.<init>

0.2% - 429 ms - 300104 inv. java.awt.font.LineBreakMeasurer.getPosition

0.1% - 415 ms - 225078 inv. java.lang.String.length

0.1% - 408 ms - 150052 inv. java.util.StringTokenizer.hasMoreTokens

0.1% - 376 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getWidth

0.1% - 309 ms - 225078 inv. dori.jasper.engine.fill.JRFillTextField.getText

0.1% - 240 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getHeight

0.1% - 232 ms - 150052 inv. java.awt.font.TextLayout.getAscent

0.1% - 212 ms - 150052 inv. dori.jasper.engine.fill.JRFillTextElement.getTextEnd

0.1% - 179 ms - 150052 inv. java.awt.font.TextLayout.getDescent

0.1% - 163 ms - 75026 inv. java.lang.String.substring

0.1% - 151 ms - 75026 inv. java.lang.String.equals

0.1% - 144 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.getFloatLineSpacing

0.1% - 143 ms - 75026 inv. java.awt.font.LineBreakMeasurer.setPosition

0.0% - 131 ms - 150052 inv. dori.jasper.engine.fill.JRFillTextElement.getTextHeight

0.0% - 107 ms - 75026 inv. java.text.AttributedCharacterIterator.getBeginIndex

0.0% - 98 ms - 75026 inv. dori.jasper.engine.base.JRBaseFont.getAttributes

0.0% - 97 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.getFontRenderContext

0.0% - 84 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.getFont

0.0% - 78 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setAbsoluteLineSpacing

0.0% - 71 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setTextHeight

0.0% - 64 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setTextStart

0.0% - 63 ms - 75026 inv. java.text.AttributedCharacterIterator.getEndIndex

0.0% - 56 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.getTextStart

0.0% - 44 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setTextEnd

0.2% - 607 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.prepare

0.1% - 350 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isRemoveLineWhenBlank

0.1% - 318 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getEvaluationTime

0.1% - 255 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isPrintRepeatedValues

0.1% - 226 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getY

0.1% - 220 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.isStretchWithOverflow

0.0% - 91 ms - 75026 inv. java.lang.String.length

0.0% - 86 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getText

0.0% - 81 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.setReprinted

0.0% - 76 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getBandBottomY

0.0% - 67 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isToPrint

0.0% - 66 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isPrintWhenExpressionNull

0.0% - 59 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getRelativeY

0.0% - 58 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.setToPrint

0.0% - 51 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.getTextEnd

0.2% - 510 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.moveDependantElements

0.1% - 338 ms - 80385 inv. dori.jasper.engine.fill.JRFillBand.getHeight

0.0% - 128 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isToPrint

0.0% - 50 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getStretchHeight

0.0% - 49 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.getRelativeY

3.0% - 8364 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.fillElements

0.2% - 672 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.resetElements

0.0% - 74 ms - 5359 inv. java.util.HashMap.<init>

0.0% - 33 ms - 5359 inv. java.lang.Thread.isInterrupted

0.0% - 18 ms - 5359 inv. java.lang.Thread.currentThread

0.0% - 6 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.moveBandBottomElements

0.0% - 5 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.stretchElements

0.0% - 3 ms - 5359 inv. dori.jasper.engine.fill.JRBaseFiller.isInterrupted

0.0% - 3 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.removeBlankElements

21.1% - 58917 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.evaluate

21.0% - 58698 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.evaluate

20.3% - 56785 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.evaluateText

15.8% - 44309 ms - 375130 inv. dori.jasper.engine.fill.JRCalculator.evaluate

15.4% - 43061 ms - 375130 inv. dori.jasper.engine.fill.JRCalculator.evaluate

7.2% - 20260 ms - 75026 inv. ActivosAVencerOficial.evaluate

0.0% - 58 ms - 75026 inv. dori.jasper.engine.base.JRBaseExpression.getId

2.9% - 8126 ms - 75026 inv. dori.jasper.engine.util.JRStringUtil.treatNewLineChars

0.1% - 418 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getExpression

0.1% - 368 ms - 75026 inv. java.lang.String.valueOf

0.1% - 307 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getHyperlinkPageExpression

0.1% - 306 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getHyperlinkAnchorExpression

0.1% - 287 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getAnchorNameExpression

0.1% - 258 ms - 75026 inv. java.lang.String.equals

0.1% - 257 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getHyperlinkReferenceExpression

0.0% - 81 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getText

0.0% - 70 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setTextEnd

0.0% - 64 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.setTextStart

0.2% - 635 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.evaluatePrintWhenExpression

0.2% - 580 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextElement.reset

0.1% - 180 ms - 75026 inv. dori.jasper.engine.fill.JRFillTextField.getEvaluationTime

0.0% - 64 ms - 75026 inv. dori.jasper.engine.fill.JRFillElement.isPrintWhenExpressionNull

0.0% - 4 ms - 5359 inv. dori.jasper.engine.fill.JRFillElementGroup.getElements

0.5% - 1508 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillBand

0.0% - 23 ms - 5359 inv. dori.jasper.engine.fill.JRFillBand.getHeight

0.0% - 7 ms - 10718 inv. dori.jasper.engine.fill.JRFillBand.willOverflow

0.0% - 6 ms - 5359 inv. dori.jasper.engine.fill.JRPrintBand.getHeight

5.7% - 15847 ms - 148 inv. dori.jasper.engine.fill.JRVerticalFiller.fillColumnBreak

1.2% - 3261 ms - 5359 inv. dori.jasper.engine.fill.JRCalculator.calculateVariables

0.0% - 60 ms - 10718 inv. dori.jasper.engine.fill.JRFillBand.isPrintWhenExpressionNull

0.0% - 59 ms - 10718 inv. dori.jasper.engine.fill.JRFillBand.isToPrint

0.0% - 11 ms - 5359 inv. dori.jasper.engine.JRAbstractScriptlet.callBeforeDetailEval

0.0% - 10 ms - 5507 inv. dori.jasper.engine.fill.JRFillBand.getHeight

0.0% - 9 ms - 5359 inv. dori.jasper.engine.JRAbstractScriptlet.callAfterDetailEval

1.5% - 4066 ms - 5359 inv. dori.jasper.engine.fill.JRCalculator.estimateGroupRuptures

0.1% - 317 ms - 5359 inv. dori.jasper.engine.fill.JRCalculator.initializeVariables

0.0% - 21 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillGroupFooters

0.0% - 17 ms - 5359 inv. dori.jasper.engine.fill.JRBaseFiller.resolveGroupBoundTexts

0.0% - 17 ms - 5359 inv. dori.jasper.engine.JRAbstractScriptlet.callAfterGroupInit

0.0% - 15 ms - 5359 inv. dori.jasper.engine.JRAbstractScriptlet.callBeforeGroupInit

0.0% - 14 ms - 5359 inv. dori.jasper.engine.fill.JRBaseFiller.resolveGroupBoundImages

0.0% - 10 ms - 5359 inv. dori.jasper.engine.fill.JRVerticalFiller.fillGroupHeaders

10.8% - 30099 ms - 5361 inv. dori.jasper.engine.fill.JRBaseFiller.next

0.5% - 1346 ms - 1 inv. dori.jasper.engine.fill.JRVerticalFiller.fillReportStart

0.2% - 555 ms - 1 inv. dori.jasper.engine.fill.JRVerticalFiller.fillReportEnd

0.0% - 1 ms - 12 inv. java.util.HashMap.<init>

0.0% - 0 ms - 2 inv. java.util.Map.put

0.0% - 0 ms - 2 inv. dori.jasper.engine.fill.JRFillGroup.getName

0.0% - 0 ms - 1 inv. dori.jasper.engine.fill.JRBaseFiller.setParameters

0.0% - 0 ms - 6 inv. dori.jasper.engine.JasperPrint.addFont

0.0% - 0 ms - 1 inv. dori.jasper.engine.JasperPrint.<init>

0.0% - 0 ms - 3 inv. java.util.Map.get

0.0% - 0 ms - 3 inv. java.util.Map.put

0.0% - 0 ms - 3 inv. dori.jasper.engine.fill.JRBaseFiller.setParameter

0.8% - 2298 ms - 1 inv. dori.jasper.engine.fill.JRBaseFiller.<clinit>

0.2% - 673 ms - 1 inv. dori.jasper.engine.fill.JRVerticalFiller.<init>

0.0% - 0 ms - 1 inv. dori.jasper.engine.fill.JRVerticalFiller.<clinit>

0.0% - 0 ms - 1 inv. dori.jasper.engine.base.JRBaseReport.getPrintOrder

0.3% - 875 ms - 1 inv. dori.jasper.engine.util.JRLoader.loadObject

0.0% - 73 ms - 1 inv. dori.jasper.engine.util.JRLoader.<clinit>

0.0% - 0 ms - 1 inv. java.io.File.<init>

10.3% - 28736 ms - 1 inv. dori.jasper.engine.JasperExportManager.exportReportToPdf

 

 

--------------------------------------------------------------------------------

 

In the above results you can see what methods are taking more time in the filling process.

 

I hope this information helps you and any solution to lower the loading time of large reports is welcomed.

 

Regards,

Claudio.

Link to comment
Share on other sites

  • Replies 0
  • Created
  • Last Reply

Top Posters In This Topic

Popular Days

Top Posters In This Topic

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now

×
×
  • Create New...