We updated our Jira Data Center server from 7.19 to 8.13 (stable release) 2 month ago. Our Jira has been clustered in three nodes. All problems were started from when we re-indexed first node. Because our Jira server has thousands issue we have chosen full re-index method.
After that we are always faced with many problems such as full GC (we know Full GC is part of a normal process) but take it too long and subsequently being very slow Jira or sometime have a high CPU or memory doesn’t leave any choices for us unless we restart the Jira Machin.
We have been looking for a specific cause or reason, we don’t know which one of them (log information) are more related or more effective in our service failure.
I want to send you some log information before, during or after problem from all files which Jira saves log in it.
If you need more information from each aspect of server or resources or configurations. Please don’t hesitate to contact us. We would appreciate in advance for any guidance or point that help us to resolve this problem as soon as possible.
We don’t have a right clue for any errors that always happen in our Jira, but I have tried to put them in our request for help.
Caused by: java.rmi.UnmarshalException: Error unmarshaling return header; nested exception is:
java.net.SocketTimeoutException: Read timed out
at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:229)
at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:162)
at net.sf.ehcache.distribution.RMICachePeer_Stub.put(Unknown Source)
2021-07-27 16:28:13,526+0430 ISSUE-indexQueue:thread-1 WARN administrator x.x.x.x lztjsx xx.xx.xx.xx /secure/admin/IndexReIndex!reindex.jspa [c.a.jira.index.MonitoringIndexWriter] Detected frequent flushes (every 536 millis) of lucene index which is below warning limit: jira.index.warn.flush.min.interval.millis=1000 millis. This may affect indexing performance. Please visit https://confluence.atlassian.com/x/w0VwOQ for more information.
2021-07-31 11:26:05,629+0430 https-jsse-nio-8443-exec-4 INFO some_username686x14226596x4 e25akj xx.xx.xx.xx,xx.x.x.x /secure/QueryComponentRendererValue!Default.jspa [
c.a.j.i.s.searchers.transformer.DateSearchInputTransformer] Unable to parse date '1400/04/31'.
2021-07-31 11:26:09,829+0430 https-jsse-nio-8443-exec-105 INFO some_username686x14226679x7 e25akj xx.xx.xx.xx,xx.xx.xx.xx/secure/QueryComponentRendererValue!Default.jspa
[c.a.j.i.s.searchers.transformer.DateSearchInputTransformer] Unable to parse date '1400/04/31'.
2021-07-31 11:26:16,799+0430 ClusterMessageHandlerServiceThread:thread-1 INFO anonymous [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotC
ount=6, totalCount=52783, periodSec=384, flushIntervalMillis=64000, snapshotNoDocs=2, totalNoDocs=20402, indexDirectory=null, indexWriterId=com.atlassian.jira.index.Mon
itoringIndexWriter@12f14318, indexDirectoryId=RAMDirectory@3d4ca07f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76555f5b
2021-07-31 11:26:18,839+0430 https-jsse-nio-8443-exec-27 INFO some_username 686x14226943x7 1ko32mb 10.25.113.36,xx.xx.xx.xx/rest/servicedesk/1/CINS/webfragments/sections/sd-
queues-nav,servicedesk.agent.queues,servicedesk.agent.queues.ungrouped [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=235, totalCount=
250246, periodSec=300, flushIntervalMillis=1278, snapshotNoDocs=21328, totalNoDocs=4518291, indexDirectory=/opt/atlassian/application-data/jira/caches/indexesV1/changes
, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@7c947a16, indexDirectoryId=MMapDirectory@/opt/atlassian/application-data/jira/caches/indexesV1/changes lo
ckFactory=org.apache.lucene.store.NativeFSLockFactory@3fe9cf3c
2021-07-31 11:26:21,755+0430 NodeReindexServiceThread:thread-0 INFO [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=489, totalCoun
t=309884, periodSec=302, flushIntervalMillis=618, snapshotNoDocs=0, totalNoDocs=0, indexDirectory=/opt/atlassian/application-data/jira/caches/indexesV1/issues, indexWri
terId=com.atlassian.jira.index.MonitoringIndexWriter@20dc88e7, indexDirectoryId=MMapDirectory@/opt/atlassian/application-data/jira/caches/indexesV1/issues lockFactory=o
rg.apache.lucene.store.NativeFSLockFactory@3fe9cf3c
2021-07-31 11:26:21,757+0430 NodeReindexServiceThread:thread-0 WARN [c.a.jira.index.MonitoringIndexWriter] Detected frequent flushes (every 618 millis) of lucene i
ndex which is below warning limit: jira.index.warn.flush.min.interval.millis=1000 millis. This may affect indexing performance. Please visit https://confluence.atlassia
n.com/x/w0VwOQ for more information.
2021-07-31 11:26:26,291+0430 Structure-Jobs4ae6e2ec Attribute-Thread#15240 WARN some_username 1145x13165457x1 1jfkcgt xx.xx.xx.xx,xx.xx.xx.xx/rest/structure/2.0/attribute
/subscription [c.a.j.structure.attribute.AttributeLoaderInfo] 41 warnings from expr:{"variables":{"issuekey":{"id":"key","format":"text"},"issueage":{"id":"sum","params":{"attribute":{"id":"expr","format":"any","params":{"formula":"if(and(issuekey,or(eq(status,\"Reject Request\"),eq(status,\"closed شده\"))),minus(latesttransdone,firsttransinprogress),and(issuekey,ne(statuscategory,\"to do\")),minus(now(),firsttransinprogress))","variables":{"firsttransinprogress":{"id":"transition-date","params":{"transition":"first","category":"indeterminate"},"format":"time"},"latesttransdone":{"id":"transition-date","params":{"transition":"latest","category":"done"},"format":"time"},"status":{"id":"status","format":"text"},"issuekey":{"id":"key","format":"text"},"statuscategory":{"id":"status-category","format":"text"}}}}},"format":"number"},"leaves":{"id":"count","params":{"leaves":true},"format":"number"}},"formula":"issueage"}:number were not shown
2021-07-31 11:26:26,291+0430 Structure-Jobs4ae6e2ec Attribute-Thread#15240 WARN some_username1145x13165457x1 1jfkcgt xx.xx.xx.xx,xx.xx.xx.xx/rest/structure/2.0/attribute/subscription [c.a.j.structure.attribute.AttributeLoaderInfo] expr:{"variables":{"issuekey":{"id":"key","format":"text"},"issueage":{"id":"sum","params":{"attribute":{"id":"expr","format":"any","params":{"formula":"if(and(issuekey,or(eq(status,\"Reject Request\"),eq(status,\"closed شده\"))),minus(latesttransdone,firsttransinprogress),and(issuekey,ne(statuscategory,\"to do\")),minus(now(),firsttransinprogress))","variables":{"firsttransinprogress":{"id":"transition-date","params":{"transition":"first","category":"indeterminate"},"format":"time"},"latesttransdone":{"id":"transition-date","params":{"transition":"latest","category":"done"},"format":"time"},"status":{"id":"status","format":"text"},"issuekey":{"id":"key","format":"text"},"statuscategory":{"id":"status-category","format":"text"}}}}},"format":"number"},"leaves":{"id":"count","params":{"leaves":true},"format":"number"}},"formula":"issueage"}:number loader does not declare context dependency CURRENT_TIME
2021-07-31 11:26:26,367+0430 Structure-Jobs4ae6e2ec Attribute-Thread#15240 WARN some_username1145x13165457x1 1jfkcgt xx.xx.xx.xx,xx.xx.xx.xx/rest/structure/2.0/attribute/subscription [c.a.j.structure.attribute.AttributeLoaderInfo] 25068 warnings from -non-unique-items:{"type":"leaves","attribute":{"id":"expr","format":"number","params":{"variables":{"issuekey":{"id":"key","format":"text"},"issueage":{"id":"sum","params":{"attribute":{"id":"expr","format":"any","params":{"formula":"if(and(issuekey,or(eq(status,\"Reject Request\"),eq(status,\"closed شده\"))),minus(latesttransdone,firsttransinprogress),and(issuekey,ne(statuscategory,\"to do\")),minus(now(),firsttransinprogress))","variables":{"firsttransinprogress":{"id":"transition-date","params":{"transition":"first","category":"indeterminate"},"format":"time"},"latesttransdone":{"id":"transition-date","params":{"transition":"latest","category":"done"},"format":"time"},"status":{"id":"status","format":"text"},"issuekey":{"id":"key","format":"text"},"statuscategory":{"id":"status-category","format":"text"}}}}},"format":"number"},"leaves":{"id":"count","params":{"leaves":true},"format":"number"}},"formula":"issueage"}
021-07-27 16:31:12,528+0430 localq-reader-20 ERROR[c.a.j.c.distribution.localq.LocalQCacheOpReader] [LOCALQ] [VIA-COPY] Abandoning sending: LocalQCacheOp{cacheName='com.atlassian.jira.cluster.dbr.DBR
Message', action=PUT, key=DBR, value == null ? false, replicatePutsViaCopy=true, creationTimeInMillis=1627387257441} from cache replication queue: [queueId=queue_Node1_9_400f9eeb84980be1750162a139bd36fc_put
, queuePath=/opt/atlassian/application-data/jira/localq/queue_Node1_9_400f9eeb84980be1750162a139bd36fc_put], failuresCount: 1/1. Removing from queue. Error: java.rmi.UnmarshalException: Error
2021-07-27 16:31:12,528+0430 localq-reader-20 ERROR[c.a.j.c.distribution.localq.LocalQCacheOpReader] [LOCALQ] [VIA-COPY] Abandoning sending: LocalQCacheOp{cacheName='com.atlassian.jira.cluster.dbr.DBR
Message', action=PUT, key=DBR, value == null ? false, replicatePutsViaCopy=true, creationTimeInMillis=1627387257441} from cache replication queue: [queueId=queue_Node1_9_400f9eeb84980be1750162a139bd36fc_put
, queuePath=/opt/atlassian/application-data/jira/localq/queue_Node1_9_400f9eeb84980be1750162a139bd36fc_put], failuresCount: 1/1. Removing from queue. Error: java.rmi.UnmarshalException: Error unmarshaling r
eturn header; nested exception is:
java.net.SocketTimeoutException: Read timed out
com.atlassian.jira.cluster.distribution.localq.LocalQCacheOpSender$UnrecoverableFailure: java.rmi.UnmarshalException: Error unmarshaling return header; nested exception is:
java.net.SocketTimeoutException: Read timed out
at com.atlassian.jira.cluster.distribution.localq.rmi.LocalQCacheOpRMISender.send(LocalQCacheOpRMISender.java:90)
at com.atlassian.jira.cluster.distribution.localq.LocalQCacheOpReader.run(LocalQCacheOpReader.java:96)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2021-07-27 17:23:31,026+0430 RMI TCP Connection(54913)-10.x.x.1xx ERROR[c.a.j.issue.index.DefaultIndexManager] Wait attempt timed out - waited 30000 milliseconds
com.atlassian.jira.issue.index.IndexException: Wait attempt timed out - waited 30000 milliseconds
at com.atlassian.jira.issue.index.DefaultIndexManager.obtain(DefaultIndexManager.java:872)
at com.atlassian.jira.issue.index.DefaultIndexManager.await(DefaultIndexManager.java:843)
(**) please attention to last description
2021-07-27 17:23:31,026+0430 RMI TCP Connection(54913)-1x.x.x.1 ERROR[c.a.j.issue.index.DefaultIndexManager] Wait attempt timed out - waited 30000 milliseconds
com.atlassian.jira.issue.index.IndexException: Wait attempt timed out - waited 30000 milliseconds
at com.atlassian.jira.issue.index.DefaultIndexManager.obtain(DefaultIndexManager.java:872)
at com.atlassian.jira.issue.index.DefaultIndexManager.await(DefaultIndexManager.java:843)
unlike increase timeout 3000 to 9000 was not applied
2021-07-22 00:48:59,599+0430 pool-39-thread-3 WARN [p.c.j.cpsa4j.lucene.AttachmentIndexManager] Wait attempt interrupted. [org.apache.lucene.store.LockObtainFailed
Exception: Lock held by this virtual machine: /opt/atlassian/application-data/jira/caches/indexesV1/attachments/write.lock] (RuntimeIOException).
com.atlassian.jira.util.RuntimeIOException: org.apache.lucene.store.LockObtainFailedException: Lock held by this virtual machine: /opt/atlassian/application-data/jira/c
aches/indexesV1/attachments/write.lock
at com.atlassian.jira.index.WriterWrapper$1.get(WriterWrapper.java:85)
at com.atlassian.jira.index.WriterWrapper$1.get(WriterWrapper.java:76)
at com.atlassian.jira.index.WriterWrapper.<init>(WriterWrapper.java:69)
at com.atlassian.jira.index.WriterWrapper.<init>(WriterWrapper.java:76)
at com.atlassian.jira.index.DefaultIndexEngine$DefaultWriterFactory.apply(DefaultIndexEngine.java:232)
at com.atlassian.jira.index.DefaultIndexEngine$DefaultWriterFactory.apply(DefaultIndexEngine.java:227)
at com.atlassian.jira.index.DefaultIndexEngine$WriterReference.doCreate(DefaultIndexEngine.java:212)
at com.atlassian.jira.index.DefaultIndexEngine$WriterReference.doCreate(DefaultIndexEngine.java:189)
at com.atlassian.jira.index.DefaultIndexEngine$ReferenceHolder$2.get(DefaultIndexEngine.java:272)
at com.atlassian.jira.concurrent.ResettableLazyReference.getOrCreateUnderLock(ResettableLazyReference.java:97)
at com.atlassian.jira.concurrent.ResettableLazyReference.getOrCreate(ResettableLazyReference.java:89)
at com.atlassian.jira.index.DefaultIndexEngine$ReferenceHolder.apply(DefaultIndexEngine.java:269)
at com.atlassian.jira.index.DefaultIndexEngine.write(DefaultIndexEngine.java:142)
at com.atlassian.jira.index.DefaultIndex.perform(DefaultIndex.java:28)
at com.atlassian.jira.index.QueueingIndex$Task.perform(QueueingIndex.java:132)
at com.atlassian.jira.index.QueueingIndex$Task.index(QueueingIndex.java:145)
at com.atlassian.jira.index.QueueingIndex$Task.run(QueueingIndex.java:111)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.lucene.store.LockObtainFailedException: Lock held by this virtual machine: /opt/atlassian/application-data/jira/caches/indexesV1/attachments/write
.lock
at org.apache.lucene.store.NativeFSLockFactory.obtainFSLock(NativeFSLockFactory.java:139)
at org.apache.lucene.store.FSLockFactory.obtainLock(FSLockFactory.java:41)
at org.apache.lucene.store.BaseDirectory.obtainLock(BaseDirectory.java:45)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:948)
at com.atlassian.jira.index.MonitoringIndexWriter.<init>(MonitoringIndexWriter.java:40)
at com.atlassian.jira.index.WriterWrapper$1.get(WriterWrapper.java:83)
2021-07-27 16:28:13,526+0430 ISSUE-indexQueue:thread-1 WARN administrator 160x25392x1 lztjsx xx.xx.xx.xx /secure/admin/IndexReIndex!reindex.jspa [c.a.jira.index.MonitoringIndexWriter] Detected frequent flushes (every 536 millis) of lucene index which is below warning limit: jira.index.warn.flush.min.interval.millis=1000 millis. This may affect indexing performance. Please visit https://confluence.atlassian.com/x/w0VwOQ for more information.
2021-07-27 16:28:23,369+0430 COMMENT-indexQueue:thread-1 INFO administrator 160x25392x1 lztjsx xx.xx.xx.xx /secure/admin/IndexReIndex!reindex.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2706, totalCount=93806, periodSec=300, flushIntervalMillis=110, snapshotNoDocs=0, totalNoDocs=0, indexDirectory=/opt/atlassian/application-
Hi!
If it's Full GC error. could you share info about your GC strategy, heap memory and Java version, please?
Please, be aware for G1GC I do recommend to use Java 11.
Thank you @Gonchik Tsymzhitov for the reply. All I know about that information might be useful is :
java version "1.8.0_66"
Java(TM) SE Runtime Environment (build 1.8.0_66-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.66-b17, mixed mode)
# If the limit of files that Jira can open is too low, it will be set to this value.
#
MIN_NOFILES_LIMIT=16384
#
# One way to set the JIRA HOME path is here via this variable. Simply uncomment it and set a valid path like /jira/home. You can of course set it outside in the command terminal. That will also work.
#
#JIRA_HOME=""
#
# Occasionally Atlassian Support may recommend that you set some specific JVM arguments. You can use this variable below to do that.
#
JVM_SUPPORT_RECOMMENDED_ARGS=""
#
# You can use variable below to modify garbage collector settings.
# For Java 8 we recommend default settings
# For Java 11 and relatively small heaps we recommend: -XX:+UseParallelGC
# For Java 11 and larger heaps we recommend: -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent
#
JVM_GC_ARGS="-XX:+ExplicitGCInvokesConcurrent"
#
# The following 2 settings control the minimum and maximum given to the JIRA Java virtual machine. In larger JIRA instances, the maximum amount will need to be increased.
#
JVM_MINIMUM_MEMORY="1G"
JVM_MAXIMUM_MEMORY="8G"
#
# The following setting configures the size of JVM code cache. A high value of reserved size allows Jira to work with more installed apps.
#
JVM_CODE_CACHE_ARGS='-XX:InitialCodeCacheSize=32m -XX:ReservedCodeCacheSize=512m'
#
# The following are the required arguments for Jira.
#
JVM_REQUIRED_ARGS='-Djava.awt.headless=true -Datlassian.standalone=JIRA -Dorg.apache.jasper.runtime.BodyContentImpl.LIMIT_BUFFER=true -Dmail.mime.decodeparameters=true -Dorg.dom4j.factory=com.atlassian.core.xml.InterningDocumentFactory -Dplugin.resource.directories=/opt/jira-sharedhome/scripts/'
Also ,we have 32GB memory per server
And what do you mean by GC strategy? Is above information adequate for you?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
Hi @Saleh Houshangi ,
on your server you have 32GB RAM, but for heap memory you set:
JVM_MAXIMUM_MEMORY="8G"
Could you adjust based for now ?
JVM_MINIMUM_MEMORY="8G"
JVM_MAXIMUM_MEMORY="12G"
Also, I do recommend you update the JVM.
As that one
1.8.0_66
is quite old release.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
Good. But my question is which one of the latest version of JDK is suitable figure 8.13?
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.