jira-slow-queries.log

Hi, 
need your advice on how to understand atlassian-jira-slow-queries.log


From my atlassian-jira-slow-queries.log :

...took '11256' ms to run - is the highest result in milliseconds
...took '403' ms to run - is the minimum result 
...~ '1700' ms to run - most regular result

What is the ms count gotta be for jql queries to get written to this log? I mean when? 
How many times my highest result is bigger than normal? And what is a good result?

I've red that there is some issues with JQL architecture, that provides slowness but it's fixed in 6.3.x.
If I upgrade to 6.3. will it help? Any examples from real life will be appreciated.

Thanx. 

JIRA: 5.0.4
Oracle Linux, VM, RAM 2Gb, Issues: 240k, projects: 4, users: 500 active (~20 concurrent a day), groups: 20, workflows: 6 active, + 15-20k issues a month

 

9 answers

I'm not going to elaborate on the times, because tuning database is a complicated matter in any application... but just out of curiosity... Are you running both: JIRA and MySQL on the same host? If yes, 2GB of RAM seems a bit too low for that number of users and issues/month. What are your JAVA memory settings and innodb_pool_size settings?

Hi, Radoslav We are on Oracle 11g, our data base runs on a separate machine. JVM: MaxPermSize=256m -Xms256m -Xmx768m

Xmx768m seems quite low. Check the JIRA "health", aka memory usage before trying to "tune" the database

I've got 37.7% of RAM free (free -m): total used free shared buffers cached Mem: 2001 1984 16 0 21 718 -/+ buffers/cache:1245 755 Swap: 1023 35 988 ----------------------------------------------- And the following: %CPU %MEM COMMAND 9.9 54.9 /usr/bin/java ---------------------------------------------- top - 10:47:01 up 32 days, 17:29, 2 users, load average: 0.00, 0.00, 0.00 Tasks: 91 total, 1 running, 90 sleeping, 0 stopped, 0 zombie Cpu(s): 2.5%us, 0.3%sy, 0.0%ni, 97.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 2049188k total, 2033936k used, 15252k free, 22652k buffers Swap: 1048568k total, 36408k used, 1012160k free, 729612k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 11191 xxx 20 0 2292m 1.1g 8204 S 10.0 55.0 1098:43 java ------------------------------------------------------------------------------------------------------------------------------ vmstat -S M 1 10 procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 0 0 35 16 22 711 0 0 6 20 4 2 3 1 96 0 0 0 0 35 16 22 711 0 0 0 0 140 252 0 0 100 0 0 1 0 35 16 22 711 0 0 0 16 156 261 0 0 99 0 0 1 0 35 16 22 711 0 0 0 0 134 250 0 0 100 0 0 0 0 35 16 22 711 0 0 0 108 162 264 0 0 100 0 0 0 0 35 16 22 711 0 0 0 0 228 280 1 0 100 0 0 0 0 35 16 22 711 0 0 0 0 1125 468 15 3 82 0 0 1 0 35 16 22 711 0 0 0 0 174 261 0 0 100 0 0 0 0 35 16 22 711 0 0 0 0 136 259 0 0 100 0 0 0 0 35 16 22 711 0 0 0 12 138 257 0 0 100 0 0

Is it when you run your slow queries? And java uses 1.1g, actually 768M... you have no stats for what is going on in JAVA VM... Try something like http://docs.oracle.com/javase/7/docs/technotes/tools/share/jmap.html to get inside the JVM and see what is going on

Sash, thank you for the tip. I hope to get the results of JVM stats soon. But can you say how bad are the results: ...took '11256' ms to run - ...took '403' ms to run - ...~ '1700' ms to run - And how bad bad are the results of JIRA profiling: [868ms] - /jira/secure/IssueNavigator!executeAdvanced.jspa [66ms] - IssueNavigator.execute() [18ms] - PermissionManager.getProjectObjects() [22ms] - Lucene Search [604ms] - IssueTableHtml another user: [224ms] - /secure/WorkflowUIDispatcher.jspa [34ms] - WorkflowUIDispatcher.execute() [4ms] - PermissionManager.hasPermission() [4ms] - PermissionManager.hasPermission() [5ms] - PermissionManager.hasPermission() [5ms] - PermissionManager.hasPermission() [0ms] - PermissionManager.hasPermission() [176ms] - SimpleWorkflowAction.execute() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [0ms] - IssueIndexManager.reIndex() [0ms] - IssueIndexManager.reIndexIssueObjects() [86ms] - IssueIndexManager.reIndex() [548ms] - /browse/ABC-112835 [472ms] - QuickLinkServlet.service() [40ms] - ViewIssue.execute() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [2ms] - PermissionManager.hasPermission() [11ms] - Updating Pager for viewing issue:ABC-112835 [109ms] - /secure/CommentAssignIssue!default.jspa [34ms] - CommentAssignIssue.execute() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [2ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [2ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [2ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [0ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [2ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [3ms] - PermissionManager.hasPermission() [1ms] - PermissionManager.hasPermission() one more: [817ms] - /plugins/servlet/streams [671ms] - /secure/IssueNavigator.jspa [252ms] - IssueNavigator.execute() [3674ms] - /browse/ABC-204911 [3621ms] - QuickLinkServlet.service() [33ms] - ViewIssue.execute() [3ms] - PermissionManager.hasPermission() [0ms] - PermissionManager.hasPermission() [1ms] - PermissionManager.hasPermission() [1ms] - PermissionManager.hasPermission() [0ms] - Updating Pager for viewing issue:ABC-204911 [557ms] - IssueTableHtml Thank you.

Please, can anyone explain when results of slow queries get into atlassian-jira-slow-queries.log file?
Hitting what ms limit queries are considered to be slow?
If [3674ms] - /browse/ABC-204911 is slow, what is normal browsing time?

Suggest an answer

Log in or Sign up to answer
Atlassian Community Anniversary

Happy Anniversary, Atlassian Community!

This community is celebrating its one-year anniversary and Atlassian co-founder Mike Cannon-Brookes has all the feels.

Read more
Community showcase
Julia Dillon
Posted Tuesday in Jira

Tell us how your team runs on Jira!

Hey Atlassian Community! Today we are launching a bunch of customer stories about the amazing work teams, like Dropbox and Twilio, are doing with Jira. You can check out the stories here. The thi...

236 views 1 18
Join discussion

Atlassian User Groups

Connect with like-minded Atlassian users at free events near you!

Find a group

Connect with like-minded Atlassian users at free events near you!

Find my local user group

Unfortunately there are no AUG chapters near you at the moment.

Start an AUG

You're one step closer to meeting fellow Atlassian users at your local meet up. Learn more about AUGs

Groups near you