Very slow performance

Issue #442 resolved
Artur Shnayder created an issue

We use "JIRA Timesheet Reports and Gadgets Plugin". It works very slow. Opening https://<Jira URL>/secure/ConfigureReport!default.jspa?selectedProjectId=10210&projectOrFilterId=project-10210&projectOrFilterName=MB%20Analog&reportKey=jira-timesheet-plugin:report takes over 10 min and sometimes fails with timeout. I don't see any usable messages in log files.

I tried workaround with group restriction - it didn't help. I don;'t know even how to figure out source of the slowness. There're about 1000 custom fields.

Comments (29)

  1. Artur Shnayder reporter

    I have enabled SQL debug on QA instance and ran the following request: {code} /usr/bin/time -p curl -L -o /dev/null --connect-timeout 290 -s 'http://jira-qa.mediaocean.com/secure/ConfigureReport!default.jspa?selectedProjectId=10210&projectOrFilterId=project-10210&projectOrFilterName=MB%20Analog&reportKey=jira-timesheet-plugin:report'

    real 105.48 user 0.00 sys 0.00

    There were produced almost 100M of the SQL log files for the only request. There were over 100,000 SELECT statement, none of queries took over 230ms. Below are few examples: {code} 013-11-13 16:05:11,507 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 1ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='QATest-4976'" 2013-11-13 16:05:11,508 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 1ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='QATEST-4976'" 2013-11-13 16:05:11,509 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 1ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='qatest-4976'" 2013-11-13 16:05:11,510 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 1ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='QATEST-4977'" 2013-11-13 16:05:11,511 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 1ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='qatest-4977'" 2013-11-13 16:05:11,536 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 0ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='QATest-4977'" 2013-11-13 16:05:11,537 ajp-bio-10.221.61.17-8009-exec-7 anonymous 963x5255x1 - /secure/ConfigureReport!default.jspa 0ms "SELECT ID, pkey, PROJECT, REPORTER, ASSIGNEE, issuetype, SUMMARY, DESCRIPTION, ENVIRONMENT, PRIORITY, RESOLUTION, issuestatus, CREATED, UPDATED, DUEDATE, RESOLUTIONDATE, VOTES, WATCHES, TIMEORIGINALESTIMATE, TIMEESTIMATE, TIMESPENT, WORKFLOW_ID, SECURITY, FIXFOR, COMPONENT FROM jiraissue WHERE pkey='qatest-4978'" {code} It doesn't seem to be right.

    Thanks,

  2. Andriy Zhdanov

    Hi Artur,

    Those sql selects are rather expected, I would say they are cached, actually. And 100M log might be also not a problem, because there are a lot of exceptions logged, for some reason. There might be something else causing slowness.

    May be you could check atlassian-jira-slow-queries.log?

    And what JIRA version and plugin version do you use?

    And where did you get plugin from? I'm confused with the url you've given, I can't remember using projectOrFilterId and projectOrFilterName.

    Thank you.

  3. Artur Shnayder reporter

    Hi Andriy,

    I've re-run my test, as following : 1. I cleaned up all log files on QA instance - nobody uses it. 2. I enabled SQL logging 3. Navigated to one of the project -> Summary and copied HTML link to "Time Sheet Report" 4. from another linux box ran the below (the URL has been extracted from i.3):

    $ /usr/bin/time -p curl -L -o /dev/null --connect-timeout 290 -s 'http://jira-qa.mediaocean.com/secure/ConfigureReport!default.jspa?selectedProjectId=11190&projectOrFilterId=project-11190&projectOrFilterName=Prisma&reportKey=jira-timesheet-plugin:report'
    real 112.01
    user 0.00
    sys 0.00
    

    You can see from here that opening this page took 112 sec. 5. On jira server itself in log directories, I've few commands:

    ```

    $ grep SELECT atlassian-jira-sql.log* | awk '{print $8}' | sed 's/ms$//' |awk '{a+=$1}END{print a/1024}' 56.7373

    $ cat atlassian-jira-sql.log* | awk '{print $8}' | sed 's/ms$//' |awk '{a+=$1}END{print a/1024}' 165.054

    $ cat atlassian-jira-sql.log* | grep SELECT | awk '{print $8}' | sed 's/ms$//' | sort -k1n | tail 58 83 89 185 188 190 197 206 211 231

    ...

    From the above you can see that total SQL statement wess 56 sec, and the longest SQL query took 231ms.

    There were no new entries in atlassian-jira-slow-queries.log file.

    I use 5.2.8 Jira version and 2.6.3 plugin version. Plugin has been downloaded from Market place. I've modified it a little bit according to your recommentations on this blog https://answers.atlassian.com/questions/153863/time-sheet-reports-don-t-open-in-jira-5-2-7 to exclude AD groups.

    Thank you,

  4. Artur Shnayder reporter

    It took for a while to find this patch, finally I found it here: https://bitbucket.org/azhdanov/jiratimesheet/wiki/JRA-32510%20Timesheet%20report%20time-out%20workaround All other links don't point to the patch itself...

    Anyway, it didn't make any difference. The same test took 96 sec:

    # /usr/bin/time -p  curl -L -o /dev/null  --connect-timeout 290  -s 'http://jira-qa.mediaocean.com/secure/ConfigureReport!default.jspa?selectedProjectId=10210&projectOrFilterId=project-10210&projectOrFilterName=MB%20Analog&reportKey=jira-timesheet-plugin:report'
    
    
    real 96.94
    user 0.00
    sys 0.00
    

    Actually my manual change, which I mentioned in description of this ticket, had done pretty much the same.

  5. Andriy Zhdanov

    Sorry, I pasted wrong link, but you've found the right one. Well, I can't get what might be wrong. As an option, you may try upgrading to JIRA 6.1.

  6. Artur Shnayder reporter

    The problem doesn't seem to be related to AD, but most likely to size of our Jira. There're over 1000 custom fields and 350 projects. Is there a way to apply filter to all of them before running initial queries, preferably from configuration interface, so Jira admins can configure them?

    Thanks

  7. Andriy Zhdanov

    There in Administration - Add Ons - Timesheet Configuration, you can try 'Exclude Projects' option, but I don't think it may help.

    How did you get the url you try? I think that it generates report for all 350 projects, because projectOrFilterId and projectOrFilterName are not valid parameters.

    So you might try opening Report Configuration (click Change on report itself, or go to it from Projects menu, chose project, see Reports, and then the report you need (Time Sheet Rport or Project Pivot Report), finally specify Project you're interested in and see report for it.

    BTW, workaround is only applicable for Report Configuration screen and not for report displaying, and you seem to expirience slowness on report displaying.

    Finally, when did the slowness problem started? Was plugin performing well before? What has changes since then, if so.

    Thank you.

  8. Artur Shnayder reporter

    You're right, Add Ons didn't make any difference. The link was provided in Project Summary menu (see attachment). The slowness actually is happening on menu generating (Report configuration) - opening the link. Report itself is normal. I'm not sure when slowness has started. Recently 2 companies got merged and started to use this Jira instance much more intensively. I have QA instance ( 3 months old snapshot of production) - the slowness had already been there.

    Thank you, Artur

  9. Andriy Zhdanov

    Ok, then workaround (the patched jar) is the right direction, but it's strange it does not help. Also it's strange there are al those SQL queries for displaying Report Configuraiton screen.

    So, once it is shown, are the any drop down boxes with many optons?

    Also I believe JIRA was restarted already many times, but could you please try uninstalling plugin, restarting jire, and installed patched version? To make this all clean indeed.

    Thank you.

  10. Artur Shnayder reporter

    As you see in the attachment, group menu is "text" and not "select" type, so your patch has been installed. It didn't fix the issue thought. BTW, we don't use AD groups in Jira - only local ones. Yes, I have uninstalled the plugin and re-installed it for several times now with and without Jira restart. I have re-indexed it, as well. It's still very slow.

    Thank you

  11. Andriy Zhdanov

    But theare are Group By Field and Additional Fields lists. And you said There're about 1000 custom fields. With patched jar those fields should be replaced with edit boxes. Looks like it's not applied properly. Please try reinstalling cleanly patched jar: 2.6.3-JRA-32510.

  12. Artur Shnayder reporter

    I uninstalled plugin., restarted Jira and installed patched one. It seems it was cached somehow in Jira because both used the same version... Anyway - performance is good now. However almost all select menus are gone, including Project ones ... I guess I can recover Project one by myself.

    Here is my question:

    Is that possible for plugin to determine whether AD is used for groups and query DB only in case it is not. Alternatively, it can be configured in "Administration" menu.

    Thank you

  13. Andriy Zhdanov

    Great!

    But unfortunately for your quesiton, the answer is no, not in case of plugin. This screen is generated by JIRA and problem is caued not by AD, or not just by it. Mainly problem is in drop down boxes (and I assume list-boxes) that have a lot of values.

    Finally, 350 projects should not be the problem, so, right you can try bringing projects back. This is great you know how to do this.

    Thank you for great collaboraiton. Please let me know if you have further questions, though.

  14. Artur Shnayder reporter

    Thank you. I've re-activated "Project" select menu and had to go through the same procedure:

    1. uninstall old plugin
    2. restart jira
    3. install modified one.

    So far it seems all right.

  15. Andriy Zhdanov

    Right, Report Configuration screen does not catch up changes just with reinstalling plugin, unfortunately.

  16. Artur Shnayder reporter

    One more update on the issue. I have re-enabled groups. Performance impact is noticeable, but it is still much better than used to be (see below):

    [ashnddny@ny-inf-46 pdf]$ /usr/bin/time -p  curl -L -o /dev/null   -s 'http://jira-qa.mediaocean.com/secure/ConfigureReport!default.jspa?selectedProjectId=10210&projectOrFilterId=project-10210&projectOrFilterName=MB%20Analog&reportKey=jira-timesheet-plugin:report'
    real 2.29
    user 0.00
    sys 0.00
    

    The same test took 2.2 sec versa 96 sec in the past. I assume that "Custom fields" is the cause.
    We haven't added too many new ones recently. Is there a way to narrow down the problem and to catch specific one/s ?

    Thank you,

  17. Andriy Zhdanov

    Did you instead update JIRA recently? I'm not sure in which JIRA version the problem is introduced, but in 5.1.8 there is no such problem, and in 5.2.7 there is.

  18. Artur Shnayder reporter

    Nope, we upgraded from version 4.4. I ended up with attached atlassian-plugin.xml file, which excludes custom fields only from selected menu. My performance test shows excellent results:

    $ time -p curl -L -o /dev/null -s 'http://jira-qa.mediaocean.com/secure/ConfigureReport!default.jspa?selectedProjectId=10210&projectOrFilterId=project-10210&projectOrFilterName=MB%20Analog&reportKey=jira-timesheet-plugin:report'
    real 0.08
    user 0.00
    sys 0.00
    

    Thank you,

  19. Danny Hendargo

    Hi Andriy,

    Using the plugin version 2.8.0.2 on JIRA 6.2.7, it takes 55 seconds to load the configuration screen with a URL similar to below: http://jira/secure/ConfigureReport!default.jspa?selectedProjectId=15591&reportKey=jira-timesheet-plugin:report

    Please advise.

    Thank you

  20. Andriy Zhdanov

    Hi Danny,

    Did it work better before? If so, what has changed since then?

    Does Project Pivot Report configuration screen loading takes long too?

    Do you have too many Groups, Projects or Fields?

    Thank you.

  21. Danny Hendargo

    Hi Andriy,

    Thank you for your response.

    We upgraded JIRA from version 5.0.7 to 6.2.7 last week. The reports were a lot faster before the upgrade. Below is the comparison:

    • On JIRA 5.0.7 with Time Sheet plugin version 2.3.12, it took 2-3 seconds for the Time Sheet Report to come up. Project Pivot Report took 1-2 seconds.

    • On JIRA 6.2.7 with Time Sheet plugin version 2.8.0.2, it takes 70 seconds for the Time Sheet Report to come up. Project Pivot Report takes 46-50 seconds.

    In our JIRA instance, we have:

    • 494 groups

    • 469 projects

    • 810 custom fields

    Your assistance is greatly appreciated in resolving this issue. Let me know if you need more info.

    Thank you.

  22. Andriy Zhdanov

    Is it possible that it is overall degradation? May be there is some re-indexing still going on after upgrade.

    Could you monitor CPU usage, before report execution, during and after?

    Could you please also try some other report, e.g. Resolution Time Report.

    Afterall may be you can try some previous version of plugin, I think 2.3.12 should still work on JIRA 6, but you may try gradually other versions, please see here for full list.

    Thank you.

  23. Danny Hendargo

    Andriy,

    There is no reindexing on the JIRA 6.2.7 instances I tried this on.

    Resolution Time Report is also very slow.

    According to the Version History, Versions 2.3.12 -- 2.8.0.2 work with JIRA 5.0.7.

    I tried the following versions against JIRA 5.0.7: 2.3.12, 2.4, 2.5, 2.6, 2.7.1, 2.8, 2.8.0.2. For each version, Time Sheet Report takes 6-7 seconds to load for the first time and then 2 seconds in subsequent times. So, every version (2.3.12 or newer) works well with JIRA 5.0.7.

    I also tried version 2.7.7., which is the first version in the Version History that works with JIRA 6.2.7. It took 55+ seconds to load the Time Sheet Report.

    Per your comment, I will try 2.3.12 - 2.7.6 next.

    Thanks.

  24. Andriy Zhdanov

    Hi Danny,

    First of all, it looks like this is JIRA problem, basing on the fact that Resolution Time Report is also very slow (and also that any plugin version works fast on JIRA 5). Resolution Time Report is JIRA standard report, so may be you can work with Atlassian to make necessary tuning for your JIRA server.

    Otherwise, I should highlight that previous versions also should work for JIRA 6, but you may need to install them manually, by copying Download url from the Version History and then using it with Upload option at Manage Add-Ons screen in JIRA.

    But I would not like you to test all versions, just try 2.5.7, and if it works fast, try 2.6.3. It should be enough.

    Thank you for your collaboration.

  25. Danny Hendargo

    Hi Andriy,

    Below are the latest numbers on the same JIRA 6.2.7 instance, using Timesheet plugin versions 2.8.0.2 and 2.5.7.

    • Resolution Time Report takes about 1 second using either version.

    • Both Pivot Report and Time Sheet reports still take 44 - 64 seconds to load using either version.

    JIRA Timesheet Reports and Gadgets Plugin Version 2.8.0.2

    • Resolution Time Report: ~1 second to load.

    • Project Pivot Report: too long resulting in proxy error. Using port 8080, bypassing Apache: ~ 64 seconds. Second try (reload): ~ 60 seconds.

    • Time Sheet Report: Using port 8080, bypassing Apache: ~ 60 seconds. Second try (reload): ~52 seconds.

    JIRA Timesheet Reports and Gadgets Plugin Version 2.5.7

    • Resolution Time Report: ~1 second to load.

    • Project Pivot Report: Using port 8080, bypassing Apache: ~ 46 seconds. Second try (reload): ~30 seconds

    • Time Sheet Report: Using port 8080, bypassing Apache: ~ 44 seconds. Second try (reload): 48 seconds.

  26. Andriy Zhdanov

    Hi Danny,

    Thank you for performing these experiments, now it looks like it's problem with the plugin only, but unfortunately, I don't have any ideas how to solve it, sorry.

    Thank you for understanding.

  27. Danny Hendargo

    Andriy,

    We need to get this fixed for 6.2.7. Sooner or later other users will run into this problem too. I think I saw many more SQL queries running when using Time Sheet Report on JIRA 6.2.7 compared to JIRA 5.0.7. I can investigate further later. In the mean time, does that give you any idea what the issue might be? Let us know if there is anything we can do to help.

    Thanks.

  28. Log in to comment