Forums

Articles
Create
cancel
Showing results for 
Search instead for 
Did you mean: 

full gc problem in Jira 8.13

Saleh Houshangi July 31, 2021

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.

 

  • We usually see this Error in our atlassian-jira.log:

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)

 

  • Also after reindex each node we have some error like this:

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.

 

 

 

 

 

  • Also we  have some problem might relate to structure but we are not sure:

 

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"}

 

  • We have frequently Error like below in the all nodes:

 

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

 

 

  • Before Jira fall into Full-GC until to become a slow and unusable Jira server, we have frequently Error same this:

 

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-

 

  • Furthermore, every time we restart our service due failure. Jira notifies that it needs to re-index again. ( We recommend that you perform a re-index, as configuration changes were made to 'Plugins' at 2021/07/31 11:55 AM. Get help! .  If you have other changes to make, complete them first so that you don't perform multiple re-indexes)  But we know we have not changed our plugin.
  • We have to mention for “Wait attempt timed out “we have increased time out from 3000 to 9000 but was not applied and have not affected. (**)

1 answer

0 votes
Gonchik Tsymzhitov
Community Champion
July 31, 2021

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. 

https://community.atlassian.com/t5/Data-Center-articles/Why-do-you-need-to-use-the-JDK-11-instead-of-8/ba-p/1666278

Saleh Houshangi August 1, 2021

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?

Gonchik Tsymzhitov
Community Champion
August 2, 2021

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.

Saleh Houshangi August 3, 2021

Good. But my question is which one of the latest version of JDK is suitable figure 8.13?

Suggest an answer

Log in or Sign up to answer