Problem

Reindexing is progressing very slowly when using JIRA Software on PostgreSQL after an XML import. The issue is more apparent for large enterprise customers (e.g. more than 500K issues) and can take up to 10 minutes per 1% completed.

Steps to induce issue:

• Setup a JIRA Software instance on PostgreSQL 
• Import a large XML backup that has at least 500k issues
• Reindex

Notice the time it takes for indexing to progress. The following appears in the atlassian-jira.log.

2016-12-09 23:13:45,067 JiraTaskExectionThread-1 INFO jiraadmin 1393x2199x2 1wxpixk 0:0:0:0:0:0:0:1 /secure/admin/IndexReIndex.jspa [c.a.j.w.a.admin.index.IndexAdminImpl] Re-indexing is 0% complete. Current index: Issue
2016-12-09 23:21:45,665 IssueIndexer:thread-4 INFO jiraadmin 1393x2199x2 1wxpixk 0:0:0:0:0:0:0:1 /secure/admin/IndexReIndex.jspa [c.a.j.w.a.admin.index.IndexAdminImpl] Re-indexing is 1% complete. Current index: Issue

Diagnosis

Environment

• This seems to only happen with PostgreSQL and cannot be easily replicated in other database flavors. 

Diagnostic Steps

• Run the following query on the PostgreSQL database while the slow reindex is happening. Notice there are various queries hitting the "AO_60DB71_LEXORANK" table that take some time to complete.

  SELECT *  FROM pg_stat_activity ;

  "SELECT "FIELD_ID","ID","ISSUE_ID","LOCK_HASH","LOCK_TIME","RANK","TYPE" FROM public."AO_60DB71_LEXORANK" WHERE "FIELD_ID" = $1 AND "ISSUE_ID" = $2 AND "TYPE" = $3"

• Perform a PostgreSQL vacuum analyze on the "AO_60DB71_LEXORANK" table. Notice the total query runtime is close to 1 second.
  
  

  INFO:  analyzing "public.AO_60DB71_LEXORANK"
  INFO:  "AO_60DB71_LEXORANK": scanned 7444 of 7444 pages, containing 795559 live rows and 0 dead rows; 30000 rows in sample, 795559 estimated total rows
  Total query runtime: 1040 ms.

• OR, perform vacuum analyze on the "AO_60DB71_LEXORANK" table via command line psql. As an example (noticed REINDEX time is >6s):

  => \timing
  Timing is on.
  => ANALYZE VERBOSE "AO_60DB71_LEXORANK";
  INFO:  analyzing "public.AO_60DB71_LEXORANK"
  INFO:  "AO_60DB71_LEXORANK": scanned 3337 of 3337 pages, containing 354648 live rows and 2237 dead rows; 30000 rows in sample, 354648 estimated total rows
  ANALYZE
  Time: 414.466 ms
  => REINDEX TABLE "AO_60DB71_LEXORANK";
  REINDEX
  Time: 6101.467 ms
  => VACUUM "AO_60DB71_LEXORANK";
  VACUUM
  Time: 60.089 ms
  => ANALYZE VERBOSE "AO_60DB71_LEXORANK";
  INFO:  analyzing "public.AO_60DB71_LEXORANK"
  INFO:  "AO_60DB71_LEXORANK": scanned 3337 of 3337 pages, containing 354648 live rows and 0 dead rows; 30000 rows in sample, 354648 estimated total rows
  ANALYZE
  Time: 157.566 ms

Cause

The "AO_60DB71_LEXORANK" is being referenced during the indexing process. Due to the large size of the table and the table not being indexed/vacuumed, the queries hitting the table take close to 1 second to process. This will add up over the indexing process.

Resolution

Perform routine maintenance on the database tables, specifically the "AO_60DB71_LEXORANK" table in this case. 

• 1. Turn off JIRA
  2. Reindex the "AO_60DB71_LEXORANK" table. You can do this by opening PGAdmin, going to the table, right-clicking and click Maintenance. Select Index and click ok.
  3. On the same menu, click on Vacuum and let the process complete.
  4. Turn on JIRA and try the indexing again

  5. To validate, run the vacuum analyze again and notice the drop in execution time.

     INFO:  analyzing "public.AO_60DB71_LEXORANK"
     INFO:  "AO_60DB71_LEXORANK": scanned 7444 of 7444 pages, containing 795559 live rows and 0 dead rows; 30000 rows in sample, 795559 estimated total rows
     Total query runtime: 690 ms.