It's all about the answers!

Ask a question

How to troubleshoot BIRT reports that consume excessive time/CPU ?


0
1
Kevin Ramer (4.5k8183200) | asked Apr 08 '13, 9:09 a.m.
RTC 4.0.1, Tomcat J2EE, AIX 6.1

Users have gotten er, creative with BIRT somehow and I see things like this with alarming frequency (from the Active Services)

com.ibm.team.reports.service.internal.ReportRestService.postRenderReport    1 days, 07:23:31:853   
com.ibm.team.reports.service.internal.ReportRestService.postRenderReport    1 days, 09:57:03:083   

The Statistics Page
Web Services
Longest Average Time
Seconds    Name
3,888.0728    com.ibm.team.reports.common.internal.service.IReportRestService.postRenderReport()
218.8494    com.ibm.team.reports.service.internal.IReportViewerService.GET()
14.9058    com.ibm.team.workitem.service.internal.rest.IAttachmentRestService.POST()
12.9089    com.ibm.team.reports.common.service.IReportImageService.GET()
11.5733    com.ibm.team.workitem.service.internal.rest.IAttachmentRestService.GET()
10.0012    com.ibm.team.filesystem.common.IFilesystemService.getFileTreeByVersionable4()

We have to restart this repository almost weekly as the JVM heap gets exhausted with ~90% of the active JVM heap being java.lang.LinkedList elements (several HUNDRED thousand).   Increasing JVM only extends the time that restart are required.  During the time that these active services are seen CPU use on the LPAR is plateaued at ~45%.

Comments
Clement Liu commented Apr 08 '13, 9:48 a.m.

Do you know which report was causing this? We had the same issue before and the problem was happening when more than one of the custom attributes are used as BIRT report parameters.



If it's not your case, do you mind sending me your BIRT template so I can review? Thanks.


Kevin Ramer commented Apr 08 '13, 9:52 a.m.

I do not "own" the report template; it was added by RTC users (I'm their admin, in case it's not already obvious :-) )  Is there a way to slurp the template from the innards of RTC ?

I'll review the article and inquire of the author if there are custom attributes used.



Kevin Ramer commented Apr 08 '13, 10:08 a.m.

Wow, that is a warehouse extension is a monstrous undertaking....


Krzysztof Kaźmierczyk commented Apr 08 '13, 10:12 a.m.

Hi Kevin,
You can add following property in log4j.properties for ccm:
log4j.logger.com.ibm.team.repo <wbr> rts.service=DEBUG
After adding please reload your log4j settings by navigating to https://your-server:9443/ccm/admin?internal=true#action=com.ibm.team.repository.admin.reloadLoggingSettings

This option traces which reports already started and which have finished. Once you have the issue again, you can check in the log which report did not finish.

Let me know if it helped for you.

Regards,
Krzysztof Kazmierczyk


Kevin Ramer commented Apr 08 '13, 10:36 a.m.

Krzysztof,
Is the <wbr> literal in the property setting ?


Clement Liu commented Apr 08 '13, 11:05 a.m.

Hi Kevin, I thought you were the template owner. :) it's better you discuss the performance issue with the owner first. They probably know how to fix it. Let me know if you need further help. Thanks.


Krzysztof Kaźmierczyk commented Apr 09 '13, 4:07 a.m.

Hi Kevin,
Sorry for typo. Here is valid property:
log4j.logger.com.ibm.team.reports.service=DEBUG


Kevin Ramer commented Apr 22 '13, 7:25 a.m.

I obtained the report design file and opened it in RTC Eclipse Report Design perspective.  When I preview the data sets the number of rows returned is barely over 50 for the one that does return any data.  The other data sets are dependent upon the first.  Yet, again today the server is rendered helpless from long running reports.

showing 5 of 8 show 3 more comments

3 answers



permanent link
Eric Jodet (6.3k5111120) | answered Apr 16 '13, 4:56 a.m.
JAZZ DEVELOPER
 Hello,
to trace reports, you may want to add the following entry to CCM's log4j.properties:
log4j.rootLogger=DEBUG, file

sample entry will be like:
DEBUG com.ibm.team.reports                                - User rafik started displaying report workitems.OpenWorkItems


Hope it helps,
Eric.

Comments
Kevin Ramer commented Apr 16 '13, 7:08 a.m.

That works, BUT waay too chatty.  logger is writing a forest, I only need a glade.


Kevin Ramer commented May 03 '13, 4:02 p.m.

I obtained the report design that the user claims is being executed. I loaded into Report project and did a preview on the data sets.  None were of any significant size (54 rows, iirc was the most).

Yet here I am today facing having to restart this RTC because:

com.ibm.team.reports.service.internal.ReportRestService.postRenderReport 1 days, 05:12:04:383

Which never leads to any good outcome.  <sigh>


Clement Liu commented May 03 '13, 8:37 p.m.

Do you mind emailing me a copy of your report template? My email is liuy4@nationwide.com


Thanks.


permanent link
Krzysztof Kaźmierczyk (7.4k373103) | answered Mar 25 '14, 8:52 a.m.
Better solution:
to trace reports, you may want to add the following entry to CCM's log4j.properties:
log4j.logger.com.ibm.team.reports=DEBUG

After that reload log4j.properties for ccm:
https://your-server:9443/ccm/admin?internal=true#action=com.ibm.team.repository.admin.reloadLoggingSettings

permanent link
Kevin Ramer (4.5k8183200) | answered May 22 '14, 9:23 a.m.
edited May 22 '14, 9:25 a.m.
After almost 1.5y and 2 RTC Upgrades these BIRT users are still in the game.  Having the ability to terminate reports after some maximum run time doesn't help ( I don't think the report data is cleaned up ).   Since this past Sunday, report runners have successfully crashed RTC with OOM exceptions.  The most recent less than 24h following the previous.

I would like to ask what can be inferred from the following:

2014-05-21 21:34:34,765 [http-bio-9.42.60.109-9443-exec-1622 @@ 21:33 tianxing /jazz/service/com.ibm.team.reports.common.internal.service.IReportRestService/renderReport]  WARN com.ibm.team.reports                                - User XING in project area Applications displayed report MSG73_SVT Defect BacklogAged that run a query that exceeded the result set size of 640000: SELECT DISTINCT T0."REC_DATETIME", T1."EXTERNAL_KEY1", T2."NAME", T3."NAME", T4."NAME", T5."NAME", T6."NAME", T7."NAME", T8."NAME", T1."TAGS" FROM "RIODS"."TEAM" T3, "RIODS"."ITERATION" T9, "RIODS"."PROJECT" T2, "RIODS"."REQUEST_TYPE" T5, "RIODS"."REQUEST_STATE" T6, "RICALM"."REQUEST_HISTORY" T1, "RIODS"."REQUEST_PRIORITY" T7, "RIODS"."REQUEST_SEVERITY" T8, "RICALM"."REQUEST_BASELINE" T0, "RIODS"."REQUEST_CATEGORY" T4 WHERE T1."ISSOFTDELETED" = 0 AND T2."NAME" IN ('Applications') AND T2."ISSOFTDELETED" = 0 AND T3."NAME" IN ('/Messaging Agent Team') AND T4."ISSOFTDELETED" = 0 AND T9."ISSOFTDELETED" = 0 AND T5."NAME" IN ('Defect') AND T2."PROJECT_CLASS_ID" = 4 AND T2."SOURCE_ID" LIKE '_iB9jgXVDEd2N-9KLmHeDyQ%' AND T0."REC_DATETIME" >= '2013-01-01 00:00:00.0' AND T0."REQUEST_HISTORY_ID" = T1."REQUEST_HISTORY_ID" AND T1."PROJECT_ID" = T2."PROJECT_ID" AND T1."TEAM_ID" = T3."TEAM_ID" AND T1."REQUEST_CATEGORY_ID" = T4."REQUEST_CATEGORY_ID" AND T1."ITERATION_ID" = T9."ITERATION_ID" AND T1."REQUEST_TYPE_ID" = T5."REQUEST_TYPE_ID" AND T1."REQUEST_STATE_ID" = T6."REQUEST_STATE_ID" AND T1."REQUEST_PRIORITY_ID" = T7."REQUEST_PRIORITY_ID" AND T1."REQUEST_SEVERITY_ID" = T8."REQUEST_SEVERITY_ID".

I can't fathom why the report would want information from almost 2 years gone....

Your answer


Register or to post your answer.


Dashboards and work items are no longer publicly available, so some links may be invalid. We now provide similar information through other means. Learn more here.