What is the importance of the Acknowledge button after re-index?

[Chris Solgat]

We have noticed some behaviors from JIRA after running a reindex over the weekend.  Most notably, the occurrences of 

Tried to reopen the IndexReader, but it threw AlreadyClosedException. Opening a fresh IndexReader.

have been increasing.  With the way that we roll our log file, we keep 30 days worth of catalina.out files, that roll every restart.  The past three weeks, we have initiated the re-index through a script that runs at 3am.  We have noticed that the log reference above has increased from 25 times for the week ending 3/29/15, to 94 entries for the week ending 4/5/15, to 369 entries for a log file that ended 4/7/15, and our current log file that started on 4/7 has 541 entries. 

The script that we run uses the API to login and start the reindex.  The question I ask is about the Acknowledge button that appears when a re-index completes.  What does it do?  Does it clear some cache or processes that are holding onto the index readers?  I'm pretty sure that the Acknowledgement is not happening in the script.  We believe that this is causing performance problems for our environment.

[crf · Accepted solution]

None.  Well, almost none.

Long running tasks get registered in a component called the TaskManager (funnily enough).  Multiple users could potentially be watching the same task's progress – for example, if another administrator went to the indexing page after you had kicked one off, then they would join you in watching its progress rather than be offered the choice to kick off one of their own while yours was already running.  Each of your web browsers would regularly refresh the page so you could entertain yourself with the progress bar.

But what about when it finishes?  If we threw away the data as soon as we showed you that it had reached 100%, then only one of the user's would see the information.

The "Acknowledge" button tells JIRA that the TaskManager doesn't need to hold onto the results anymore.  Once you have acknowledged them, they are discarded and other requests to that URL will not be able to display them.  But it does not actually do anything that "completes" the indexing; that is long since done.

The message about reopening an index reader may sound alarming, but it isn't usually anything to worry about.  It is an artifact of how JIRA's indexing code handles the Lucene index reader.  There is a sort of cache of the current index reader, but this can be closed at any time by a new write to the index.  We check for whether or not this has happened before trying to use the existing reader, but there is no way to do that check and request that the index reader be reopened in a single, atomic operation, so we can get unlucky and lose this race.  The message is reporting that this happened, but most of the time it is completely innocuous.

It is a little surprising that you are seeing that message with increasing frequency, but I would not be too worried about it unless you have another symptom that something is wrong, such as leaked file handles, increasing use of disk space well beyond the reported size of the index files, and so on.

[crf]

As for performance problems, are you using JDK 7? We have fairly strong anecdotal evidence that JIRA 6.2 and later degrade in performance over time on heavily used instances due to how certain synchronization structures are implemented in JDK 7 and that moving to JDK 8 invariably solves this (for 6.3+ only, as 6.2 can't run on JDK 8). This has been reported by several of our Premier Support customers, and the move to JDK 8 has, to my knowledge, had a 100% success rate in addressing it thus far. Note: If you decide to do this, use 1.8.0_40; the earlier 1.8 releases have a SIGSEGV bug that you would want to avoid.

[Chris Solgat]

Yes we are using JDK 7. As we are currently on Jira 6.1.6, there's not much that we can do yet. We are scheduled to upgrade to 6.3.15 around May 2nd. There was one other item that we found that made me look into the Re-indexing process. We found that this query (@P0 bigint, @P1 nvarchar (4000)) SELECT CG.ID, CG.issueid, CG.AUTHOR, CG.CREATED, CI.ID, CI.groupid, CI.FIELDTYPE, CI.FIELD, CI.OLDVALUE, CI.OLDSTRING, CI.NEWVALUE, CI.NEWSTRING FROM dbo.changegroup CG INNER JOIN dbo.changeitem CI ON CG.ID = CI.groupid WHERE CG.issueid = @P0 AND CI.FIELD = @P1 ORDER BY CG.CREATED ASC, CI.ID ASC was being run by a total of 14 sessions (usually 5 of them were active at any given time). 4 of the 5 biggest sessions started at 3am Sunday morning, which is when our Re-indexing is scheduled to start. When we identified this query Tuesday morning, it had over 45,000 executions with 11 billion logical reads. When we looked at it 4 hours later, it was up to 185,597 executions and over 21 billion logical reads. Now I don't know what that query is tied to exactly, but it does look like a lot of the same items that would be looked at during a re-index.

[Chris Solgat]

The reason I started looking into the "Tried to open index reader" is that I noticed that the timeline on a few different "weird" behaviors all seem to have started around the time we started using the scheduled re-indexes again. March 29 was the first week that we ran the scheduled re-index. On Tuesday, March 31, it was noticed that Kanban boards were not loading. After opening a support ticket and checking on the Kanban boards periodically, I noticed that they started loading more consistently on Tuesday afternoon of this week, after we had to restart the JVM. One behavior I noticed in particular, was that the initial board in question (only had 43 issues on it) loaded beautifully after the project had been re-indexed. So it leads me to believe that some of the board loading problems could be related to re-indexes.

[crf]

The query you specified comes from DefaultChangeHistoryManager.getChangeItemsForField(Issue,String): final List<GenericValue> changeItemsForFieldGVs = ofBizDelegator.findByAnd("ChangeGroupChangeItemView", ImmutableMap.of("issue", issue.getId(), "field", changeItemFieldName), ImmutableList.of("created ASC", "changeitemid ASC")); I would generate a thread dump (see https://confluence.atlassian.com/display/JIRA/Generating+a+Thread+Dump ) to see what is calling this so frequently. The only two uses I see for this are retrieving the assignee history for the purpose of suggesting new assignees for an issue and in the project import service to fix up issue links, but I'm looking at 6.4-level code at the moment, and it is possible that plugins (whether built-in ones like activity streams or third-party ones) might also use this service. If you want to pursue the stack traces, it would probably be best to open a support request on support.atlassian.com -- it's more suited to 1-on-1 troubleshooting, especially when potentially sensitive information about your system might be needed to diagnose the problem.

[Nic Brough -Adaptavist-]

None.  It's just there to tell you it's done if you've left the session running in the foreground.

What ever is causing your issues, I'm afraid it's not as simple as "not pressing the acknowledge button".  You shouldn't be getting that error at all, you need to trace that down!

[john.pfotzer@verizonwireless.com]

Nic, I couldn't agree with you more. I have been frustrated with the situation. I am open to any suggestions of what may be causing the system to re-index almost every night.

thanks

John

[Nic Brough -Adaptavist-]

JIRA does not re-index itself, it needs a human to click "go"

[john.pfotzer@verizonwireless.com]

Chris, what script are you using? I am trying to find a good one that I can put in Jenkins so an off shore user that we choose can remotely reindex at night when we get errors. So I don't have to be woken at 4a.

thanks

John

[Chris Solgat]

https://answers.atlassian.com/questions/92800/answers/2824872/comments/16388866 I have used both the perl script and the bash script written by Jason in this link. I have used the perl script with Jira 5.4 and Jira 6.1.6. I have used the bash script with Jira 6.3.15. Also, farther down the page, I placed my modified script that adds a little bit of logging information as well as handles the "Acknowledgment" to clear out the Task ID. We have a cron-type job trigger the re-index to run around 1am.

[Nic Brough -Adaptavist-]

PLEASE remember to treat this as "plastering over the cracks" and NOT a long term fix. You really need to stop doing it and work out what the root cause of the problem is and deal with that.

[Chris Solgat]

This is just for the re-indexing. The Acknowledgment is mostly just for me, to make me feel better. As I've said in other posts, it will hold on to the new task id's until someone clears them out. They will survive restarts and additional re-indexes. Like I said, this leads me to believe that it's holding onto something more than nothing. Either way, I put in the Acknowledgement because it was driving me nuts knowing that there were open task managers just sitting there. As for the the problem that I think you are referring to, we have upgraded both Jira and Agile. That along with the migration to new servers with better hardware seem to have cleared up the problem.

[Chris Solgat]

I forgot which page this was on. Yes the problem with the Index readers has not been showing up since we have upgraded.