How to dynamically parse Jira performance log used for gathering jmx statistics

Platform Notice: Data Center Only - This article only applies to Atlassian products on the Data Center platform.

Note that this KB was created for the Data Center version of the product. Data Center KBs for non-Data-Center-specific features may also work for Server versions of the product, however they have not been tested. Support for Server* products ended on February 15th 2024. If you are running a Server product, you can visit the Atlassian Server end of support announcement to review your migration options.

*Except Fisheye and Crucible

Summary

The Jira performance log atlassian-jira-perf.log contains valuable information logged every minute with Jira application utilizing jmx to expose run time metrics such as

  • JMXINSTRUMENTS-OS - Contains information on OS related metrics such as swap memory usage, system load average, virtual memory size etc.

  • JMXINSTRUMENTS-GC - Garbage collection count and collection time in young generation and old generation of the heap.

  • JMXINSTRUMENTS-Threading - Total thread count, peak thread count, daemon thread count

  • JMXINSTRUMENTS-ThreadPool - Information on busy threads, max threads etc. which can be used decide when to get thread dumps.

  • PLATFORMINSTRUMENTS - Loads of metrics, about dbcp pool, thread count, memory usage, issue created count, velocity template exception etc.

Firstly, you can gather information about all the metrics that are printed out by each of the instrumentation above with a command like below. You would want to install json parser jq . The output would look like below. This is to help identify and gather and plot metrics that may not be analyzed or plotted in the tools you might be currently using for troubleshooting.

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 % cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-OS/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].attributes[].name' "OpenFileDescriptorCount" "MaxFileDescriptorCount" "CommittedVirtualMemorySize" "TotalSwapSpaceSize" "FreeSwapSpaceSize" "ProcessCpuTime" "FreePhysicalMemorySize" "TotalPhysicalMemorySize" "SystemCpuLoad" "ProcessCpuLoad" "SystemLoadAverage" "AvailableProcessors" % cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-GC/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].attributes[].name' "CollectionCount" "CollectionTime" "Name" "CollectionCount" "CollectionTime" "Name" % cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-Threading/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].attributes[].name' "CurrentThreadUserTime" "ThreadCount" "TotalStartedThreadCount" "CurrentThreadCpuTime" "PeakThreadCount" "DaemonThreadCount" % cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-ThreadPool/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].ObjectName' "Catalina:name=\"https-jsse-nio-8080\",type=ThreadPool" "Catalina:name=\"http-nio-8898\",type=ThreadPool" % cat atlassian-jira-perf.log | awk '/PLATFORMINSTRUMENTS/{$1="";$2="";$3="";print}' | jq -s '.[1] |.instrumentList[].name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS="\n" '{print}' | sort cache.JiraOsgiContainerManager.evictionCount cache.JiraOsgiContainerManager.hitCount cache.JiraOsgiContainerManager.loadExceptionCount cache.JiraOsgiContainerManager.loadSuccessCount cache.JiraOsgiContainerManager.missCount cache.JiraOsgiContainerManager.size cache.JiraOsgiContainerManager.totalLoadTime cache.VelocityTemplateCache.directives.evictionCount cache.VelocityTemplateCache.directives.hitCount cache.VelocityTemplateCache.directives.loadExceptionCount cache.VelocityTemplateCache.directives.loadSuccessCount cache.VelocityTemplateCache.directives.missCount cache.VelocityTemplateCache.directives.size cache.VelocityTemplateCache.directives.totalLoadTime cache.VelocityTemplateCache.evictionCount cache.VelocityTemplateCache.hitCount cache.VelocityTemplateCache.loadExceptionCount cache.VelocityTemplateCache.loadSuccessCount cache.VelocityTemplateCache.missCount cache.VelocityTemplateCache.size cache.VelocityTemplateCache.totalLoadTime cache.i18n.CachingI18nFactory.evictionCount cache.i18n.CachingI18nFactory.hitCount cache.i18n.CachingI18nFactory.loadExceptionCount cache.i18n.CachingI18nFactory.loadSuccessCount cache.i18n.CachingI18nFactory.missCount cache.i18n.CachingI18nFactory.size cache.i18n.CachingI18nFactory.totalLoadTime concurrent.requests dashboard.view.count db.conns db.conns.borrowed db.conns.time.to.borrow db.reads db.writes dbcp.maxActive dbcp.numActive dbcp.numIdle entity.attachments.total entity.components.total entity.customfields.total entity.filters.total entity.groups.total entity.issues.total entity.projects.total entity.users.total entity.versions.total entity.workflows.total five.hundreds http.session.objects http.sessions index.writes issue.assigned.count issue.created.count issue.index.reads issue.link.count issue.search.count issue.updated.count issue.worklogged.count jira.license jmx.class.loaded.current jmx.class.loaded.total jmx.class.unloaded.total jmx.gc jmx.memory.heap.committed jmx.memory.heap.used jmx.memory.nonheap.committed jmx.memory.nonheap.used jmx.system.up.time jmx.thread.cpu.block.count jmx.thread.cpu.block.time jmx.thread.cpu.time jmx.thread.cpu.user.time jmx.thread.cpu.wait.count jmx.thread.cpu.wait.time jmx.thread.daemon.count jmx.thread.ever.count jmx.thread.nondaemon.count jmx.thread.peak.count jmx.thread.total.count quicksearch.concurrent.search sd.automation.async.psmq.thread.active.size sd.automation.async.psmq.thread.pool.size sd.automation.async.psmq.wait.queue.depth sd.automation.async.then.psmq.thread.active.size sd.automation.async.then.psmq.thread.pool.size sd.automation.async.then.psmq.wait.queue.depth web.requests writer.lucene.commit

Environment

9.x

Solution

For the PLATFORMINSTRUMENTS, which has too many metrics, it can be configured to print out the name and value for only certain metrics by providing a regex pattern. Below the Parameter variable can be modified to print only the metrics that match a pattern. You can also try a pattern such as "entity.*count" , "cache.*" , "dbcp.*" or even full metric name such as "web.requests" substituting in the parameter variable. Below we would be printing all metrics related to issues by using "issue.*count" as parameter.

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 parameter="issue.*count";ParseVar=$(cat atlassian-jira-perf.log | awk '/PLATFORMINSTRUMENTS/{$1="";$2="";$3="";print}' | jq --arg param $parameter -s '.|.[1] |.instrumentList[]|select(.name|test($param)).name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS=" " '{print}'); PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log | awk '/PLATFORMINSTRUMENTS/{$1="";$2="";$3="";print}' | jq --arg param $parameter -r '.|[.timestamp,(.instrumentList[]|select(.name|test($param))|.value)] | @tsv'| gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1), $1="",$0}' | column -t timestamp issue.link.count issue.created.count issue.search.count issue.updated.count issue.assigned.count issue.worklogged.count 2023-02-26-20:37:08 64 33 0 135 9 5 2023-02-26-20:38:07 64 33 0 135 9 5 2023-02-26-20:39:07 64 33 0 135 9 5 2023-02-26-20:40:07 64 33 0 135 9 5 2023-02-26-20:41:07 64 33 0 135 9 5 2023-02-26-20:42:07 64 33 0 135 9 5 2023-02-26-20:43:07 64 33 0 135 9 5 2023-02-26-20:44:07 64 33 0 137 9 5 2023-02-26-20:45:07 64 33 0 137 9 5 2023-02-26-20:46:07 64 33 0 138 9 5 2023-02-26-20:47:07 64 33 0 138 9 5 2023-02-26-20:48:08 64 33 0 138 9 5 ..................

The metrics for JMXINSTRUMENTS-GC and JMXINSTRUMENTS-Threading and JMXINSTRUMENTS-ThreadPool are few and can be printed in whole by running the below commands.

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 JMXINSTRUMENTS-GC ParseVar=$(cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-GC /{$1="";$2="";$3="";print}' | jq -s '.[1] | .[0].attributes[2].name,.[0].attributes[0].name,.[0].attributes[1].name,.[1].attributes[2].name,.[1].attributes[0].name,.[1].attributes[1].name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS=" " '{print}'); PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-GC /{$1="";$2="";$3="";print}' | jq -r '.[]|[.timestamp,(.attributes[2].value),(.attributes[0].value),(.attributes[1].value)] | @tsv' | awk '{key1=sprintf("%s%s%s%s",$1" ",$2$3$4" ",$5" ",$6);getline;key2=sprintf("%s%s%s",$2$3$4" ",$5" ",$6);print key1,key2}' | gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1),$1="",$0}' | column -t timestamp Name CollectionCount CollectionTime Name CollectionCount CollectionTime 2023-02-26-20:36:07 G1YoungGeneration 364 53671 G1OldGeneration 0 0 2023-02-26-20:37:07 G1YoungGeneration 366 54004 G1OldGeneration 0 0 2023-02-26-20:38:07 G1YoungGeneration 367 54212 G1OldGeneration 0 0 2023-02-26-20:39:07 G1YoungGeneration 368 54343 G1OldGeneration 0 0 2023-02-26-20:40:07 G1YoungGeneration 370 54697 G1OldGeneration 0 0 2023-02-26-20:41:07 G1YoungGeneration 371 54950 G1OldGeneration 0 0 2023-02-26-20:42:07 G1YoungGeneration 373 55198 G1OldGeneration 0 0 2023-02-26-20:43:07 G1YoungGeneration 376 55696 G1OldGeneration 0 0 2023-02-26-20:44:07 G1YoungGeneration 377 55795 G1OldGeneration 0 0 2023-02-26-20:45:07 G1YoungGeneration 378 55875 G1OldGeneration 0 0 2023-02-26-20:46:07 G1YoungGeneration 379 55952 G1OldGeneration 0 0 2023-02-26-20:47:07 G1YoungGeneration 380 56017 G1OldGeneration 0 0 .................. JMXINSTRUMENTS-Threading ParseVar=$(cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-Threading/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].attributes[].name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS=" " '{print}');PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-Threading/{$1="";$2="";$3="";print}' | jq -r '.[]|[.timestamp,(.attributes[].value)] | @tsv' | gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1),$1="",$0}' | column -t timestamp CurrentThreadUserTime ThreadCount TotalStartedThreadCount CurrentThreadCpuTime PeakThreadCount DaemonThreadCount 2023-02-26-20:36:07 1270000000 482 3249 2600797393 516 435 2023-02-26-20:37:07 1270000000 481 3254 2605854808 516 436 2023-02-26-20:38:07 1270000000 482 3258 2611078087 516 435 2023-02-26-20:39:07 1270000000 482 3262 2616168067 516 436 2023-02-26-20:40:07 1280000000 481 3265 2621064992 516 435 2023-02-26-20:41:07 1280000000 480 3267 2625968279 516 435 2023-02-26-20:42:07 1280000000 481 3271 2630787881 516 435 2023-02-26-20:43:07 1280000000 480 3278 2635774761 516 435 ................... JMXINSTRUMENTS-ThreadPool ParseVar=$(cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-ThreadPool/{$1="";$2="";$3="";print}' | jq -s '.[1] | [.[].ObjectName] | @csv' | sed -e 's/Catalina:name=//g' -e 's/type=ThreadPool//g' -e 's/"//g' -e 's/\\//g' -e 's/,/ /g');PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log* | awk '/JMXINSTRUMENTS-ThreadPool/{$1="";$2="";$3="";print}' | jq -r '. | .[0].timestamp as $time | [$time, (.[].attributes[]|select(.name|contains("currentThreadsBusy"))|.value)]| @tsv' | gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1), $1="",$0}' | column -t timestamp https-jsse-nio-8080 http-nio-8898 2023-03-27-10:31:49 3 30 2023-03-27-10:32:49 3 20 2023-03-27-10:33:49 4 25 2023-03-27-10:34:49 4 35 2023-03-27-10:35:49 5 45 2023-03-27-10:36:49 6 55 2023-03-27-10:37:49 6 50 ....................

Similar to PLATFORMINSTRUMENTS, the JMXINSTRUMENTS-OS can also be parameterized to provide only certain metrics such as SystemLoadAverage, ProcessCpuLoad, OpenFileDescriptorCount etc. Here we parameterize for physicalmemory

1 2 3 4 5 6 7 8 9 10 11 parameter=".*PhysicalMemory.*";ParseVar=$(cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-OS/{$1="";$2="";$3="";print}' | jq --arg param $parameter -s '.[1] | .[].attributes[]|select(.name|test($param)).name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS=" " '{print}');PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-OS/{$1="";$2="";$3="";print}' | jq --arg param $parameter -r '.[]|[.timestamp,(.attributes[]|select(.name|test($param))|.value)] | @tsv' | gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1),$1="",$0}' | column -t timestamp FreePhysicalMemorySize TotalPhysicalMemorySize 2023-02-26-20:36:07 4483416064 101206396928 2023-02-26-20:37:07 4480978944 101206396928 2023-02-26-20:38:07 4491440128 101206396928 2023-02-26-20:39:07 4497281024 101206396928 2023-02-26-20:40:07 4477222912 101206396928 2023-02-26-20:41:07 4473540608 101206396928 2023-02-26-20:42:07 4468113408 101206396928 .........

The non-parameterized version of the script for gathering all the metrics for JMXINSTRUMENTS-OS is provided below

1 ParseVar=$(cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-OS/{$1="";$2="";$3="";print}' | jq -s '.[1] | .[].attributes[].name' | sed -e 's/,//g' -e 's/"//g' | awk -v ORS=" " '{print}');PrintVar=$(eval echo $ParseVar); cat atlassian-jira-perf.log | awk '/JMXINSTRUMENTS-OS/{$1="";$2="";$3="";print}' | jq -r '.[]|[.timestamp,(.attributes[].value)] | @tsv' | gawk -v var="$PrintVar" 'BEGIN {print "timestamp",var}{print strftime("%Y-%m-%d-%H:%M:%S",$1),$1="",$0}' | column -t

Updated on March 11, 2025
Platform
Data Center only
Products
Jira Software Data Center
Jira Core Data Center
Jira Service Management Data Center
On this pageSummarySolution

Still need help?

The Atlassian Community is here for you.
Ask the Community