Uploaded image for project: 'Jira Data Center'
  1. Jira Data Center
  2. JRASERVER-68483

Improve logging for Jira Lucene reindexing

XMLWordPrintable

    • 4
    • 1
    • We collect Jira feedback from various sources, and we evaluate what we've collected when planning our product roadmap. To understand how this piece of feedback will be reviewed, see our Implementation of New Features Policy.

      Problem

      Jira has full reindex process. If any error happends during this time, error is accumulated and showed at the end, eg:

      2018-11-13 10:00:27,704 IssueIndexer:thread-31 INFO admin 1139x124894x1 1s 127.0.0.1 /secure/admin/IndexReIndex.jspa [c.a.j.w.a.admin.index.IndexAdminImpl] Re-indexing is 98% complete. Current index: Issue
2018-11-13 10:01:07,436 JiraTaskExectionThread-1 ERROR admin 1139x124894x1 1s 127.0.0.1 /secure/admin/IndexReIndex.jspa [c.a.j.util.index.CompositeIndexLifecycleManager] Reindex All FAILED. Indexer: DefaultIndexManager: paths: [/jira/caches/indexes/comments, /jira/caches/indexes/issues, /jira/caches/indexes/changes, /jira/caches/indexes/worklogs, /jira/caches/indexes/plugins/jira-git-files, /jira/caches/indexes/plugins/jira-git-pullrequestinfos, /jira/caches/indexes/plugins/jira-git-revisions]
com.atlassian.jira.index.IndexingFailureException: Indexing completed with 2 errors
at com.atlassian.jira.index.AccumulatingResultBuilder$CompositeResult.await(AccumulatingResultBuilder.java:150)
at com.atlassian.jira.issue.index.DefaultIndexManager.doIndexIssuesInBatchMode(DefaultIndexManager.java:1016)
at com.atlassian.jira.issue.index.DefaultIndexManager.doStopTheWorldReindex(DefaultIndexManager.java:991)
at com.atlassian.jira.issue.index.DefaultIndexManager.lambda$reIndexAll$0(DefaultIndexManager.java:328)
at com.atlassian.jira.issue.index.DefaultIndexManager.withReindexLock(DefaultIndexManager.java:377)
at com.atlassian.jira.issue.index.DefaultIndexManager.reIndexAll(DefaultIndexManager.java:328)
at com.atlassian.jira.issue.index.DefaultIndexManager.reIndexAll(DefaultIndexManager.java:260)
...

      The problem is that the error just says: Indexing completed with 2 errors without providing more details, so it doesn't help with troubleshooting and it's quite hard to find the cause.

      Actual problem could be many hours (logs files) before, eg:

      2018-11-12 23:21:25,468 JiraTaskExectionThread-1 WARN admin 1139x124894x1 1s 127.0.0.1 /secure/admin/IndexReIndex.jspa [c.a.jira.index.AccumulatingResultBuilder] Indexing failed for Issue - '1847432'
2018-11-12 23:21:25,469 JiraTaskExectionThread-1 WARN admin 1139x124894x1 1s 127.0.0.1 /secure/admin/IndexReIndex.jspa [c.a.jira.index.AccumulatingResultBuilder] com.atlassian.jira.exception.DataAccessException: org.ofbiz.core.entity.GenericDataSourceException: SQL Exception while executing the following:SELECT ID, issueid, AUTHOR, actiontype, actionlevel, rolelevel, actionbody, CREATED, UPDATEAUTHOR, UPDATED, actionnum FROM jiraaction WHERE issueid=? AND actiontype=? (No more data to read from socket)
java.lang.RuntimeException: com.atlassian.jira.exception.DataAccessException: org.ofbiz.core.entity.GenericDataSourceException: SQL Exception while executing the following:SELECT ID, issueid, AUTHOR, actiontype, actionlevel, rolelevel, actionbody, CREATED, UPDATEAUTHOR, UPDATED, actionnum FROM jiraaction WHERE issueid=? AND actiontype=? (No more data to read from socket)

      Suggestion

      Improve logging and accumulate actual error.

      Workaround

      If the atlassian-jira.log files cover the entire full reindex process, retroactively searching for AccumulatingResultBuilder entries should indicate which errors affected the reindex process.
      Sometimes these errors are logged as WARN.

              Unassigned Unassigned
              ayakovlev@atlassian.com Andriy Yakovlev [Atlassian]
              Votes:
              9 Vote for this issue
              Watchers:
              12 Start watching this issue

                Created:
                Updated: