XMLWordPrintable

    Details

    • Type: Bug
    • Status: Gathering Impact (View Workflow)
    • Priority: Low
    • Resolution: Unresolved
    • Affects Version/s: 8.5.0, 8.5.1, 8.6.1, 8.5.3
    • Fix Version/s: None
    • Labels:
      None

      Description

      Issue Summary

      XML Restore gets stuck at 90% and does not progress further.

      Environment

      JIRA Data Center 8.5 with JSD 4.5
      Database : MS SQL/ Oracle/ PostgreSQL

      Expected Results

      Restoration completed at 100% and user is prompted to log in again.

      Actual Results

      • Problem is regularly observed in DC environment.
      • Restore progresses to 90%, but never goes past 90%.
      • Restore progressed to 90% within minutes, but hours pass with no progress past 90%.
      • Logs corresponding to the from the DC environment (PostgreSQL 9.4):
        2019-09-26 21:28:26,595 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Importing data is 88% complete...
        2019-09-26 21:28:26,596 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Importing data is 89% complete...
        2019-09-26 21:28:26,597 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Importing data is 90% complete...
        2019-09-26 21:28:26,655 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Finished storing Generic Values.
        2019-09-26 21:28:26,655 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Finished storing Generic Values.
        2019-09-26 21:28:26,689 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:26,695 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:26,696 localq-reader-0 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:26,829 JiraImportTaskExecutionThread-1 DEBUG admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.activeobjects.osgi.ActiveObjectsServiceFactory] startCleaning
        2019-09-26 21:28:26,833 JiraImportTaskExecutionThread-1 DEBUG admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.activeobjects.osgi.ActiveObjectsServiceFactory] stopCleaning
        2019-09-26 21:28:27,028 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,029 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,029 localq-reader-1 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_0_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,030 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,030 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,030 localq-reader-2 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_1_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,032 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,032 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,032 localq-reader-3 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_3_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,033 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,033 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,033 localq-reader-4 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_4_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,035 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,035 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,035 localq-reader-5 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_5_be4ee67b71729bbfa51fef35601226c5] 2019-09-26 21:28:27,036 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,036 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,036 localq-reader-6 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_6_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,037 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c52019-09-26 
        21:28:27,038 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,038 localq-reader-7 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_7_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,039 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,039 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,039 localq-reader-8 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_8_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:27,041 cluster-watchdog-0 INFO      [c.a.j.c.d.localq.tape.TapeLocalQCacheOpQueue] Created persistent cache replication queue for node: mycluster2 with id: queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5 in : /Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5
        2019-09-26 21:28:27,041 cluster-watchdog-0 INFO      [c.a.j.c.distribution.localq.LocalQCacheManager] Created cache replication queue: [queueId=queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5] with queue reader running: true
        2019-09-26 21:28:27,041 localq-reader-9 INFO      [c.a.j.c.distribution.localq.LocalQCacheOpReader] Started listening for cache replication queue: [queueId=queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_9_be4ee67b71729bbfa51fef35601226c5] 
        2019-09-26 21:28:28,737 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=2, periodSec=341, flushIntervalMillis=170828, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/comments, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@3174eaca, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/comments lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,740 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=4, periodSec=0, flushIntervalMillis=1, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/comments, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@3174eaca, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/comments lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,747 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=2, periodSec=341, flushIntervalMillis=170648, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/issues, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@552d82fe, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/issues lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,750 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=4, periodSec=0, flushIntervalMillis=1, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/issues, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@552d82fe, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/issues lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,757 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=2, periodSec=341, flushIntervalMillis=170609, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/changes, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@73dc8b73, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/changes lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,760 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=4, periodSec=0, flushIntervalMillis=1, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/changes, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@73dc8b73, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/changes lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,765 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=2, periodSec=341, flushIntervalMillis=170592, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/worklogs, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@65e32b49, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/worklogs lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,766 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=2, totalCount=4, periodSec=0, flushIntervalMillis=0, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/worklogs, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@65e32b49, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/worklogs lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,769 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.index.ha.DefaultNodeReindexService] Pausing node re-index service2019-09-26 21:28:28,771 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.cluster.lock.HeartbeatScheduledExecutorFactory] Heartbeat scheduler shutdown
        2019-09-26 21:28:28,771 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.cluster.ClusterWatchdogService] ClusterWatchdogJob shutting down2019-09-26 21:28:28,780 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.plugin.manager.DefaultPluginManager] Preparing to shut down the plugin system
        2019-09-26 21:28:28,793 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.i.m.processor.bootstrap.MailPluginLifeCycleAware] JIRA Email Processor is stopping...2019-09-26 21:28:28,795 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.i.m.processor.bootstrap.MailPluginLifeCycleAware] JIRA Email Processor is stopped.
        2019-09-26 21:28:28,800 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=4, totalCount=4, periodSec=88, flushIntervalMillis=22018, indexDirectory=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/plugins/servicedeskcannedresponses, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@43ebbc5f, indexDirectoryId=MMapDirectory@/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/caches/indexesV1/plugins/servicedeskcannedresponses lockFactory=org.apache.lucene.store.NativeFSLockFactory@7c67d6fb
        2019-09-26 21:28:28,808 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.p.internal.bootstrap.Launcher] PSMQ is stopping...
        2019-09-26 21:28:28,812 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.p.internal.bootstrap.Launcher] PSMQ is stopped.2019-09-26 21:28:28,814 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.p.w.i.bootstrap.lifecycle.WorkingHoursPluginLauncher] JIRA (SD) Working Hours Plugin stopping...
        2019-09-26 21:28:28,814 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.p.w.i.bootstrap.lifecycle.WorkingHoursPluginLauncher] JIRA (SD) Working Hours Plugin stopped
        2019-09-26 21:28:28,828 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [atlassian.servicedesk.lifecycle] stopping...2019-09-26 21:28:28,829 JiraImportTaskExecutionThread-1 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [atlassian.servicedesk.lifecycle] Server Plugin LifeCycle - Stopping Service Desk
        2019-09-26 21:28:31,716 localq-reader-0 INFO admin 1288x1035x1 1o9fs2d 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.c.distribution.localq.LocalQCacheOpReader] Checked exception: RecoverableFailure occurred when processing: LocalQCacheOp{cacheName='com.atlassian.jira.propertyset.CachingOfBizPropertyEntryStore.cache', action=REMOVE_ALL, key=null, value=null, creationTimeInMillis=1569497306656} from cache replication queue: [queueId=queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5, queuePath=/Users/allewellyn/jira-home/atlassian-jira-software-8.3.3/localq/queue_mycluster2_2_be4ee67b71729bbfa51fef35601226c5], failuresCount: 1. Will retry indefinitely.com.atlassian.jira.cluster.distribution.localq.LocalQCacheOpSender$RecoverableFailure: java.rmi.ConnectIOException: Exception creating connection to: 10.217.3.111; nested exception is:  java.net.SocketTimeoutException: connect timed out
        
      • Logs from another DC environment (PostgreSQL 9.6):
        2019-10-18 16:08:28,589 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Importing data is 90% complete...
        2019-10-18 16:08:28,797 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.bc.dataimport.DefaultDataImportService] Finished storing Generic Values.
        2019-10-18 16:08:28,892 JiraImportTaskExecutionThread-1 DEBUG admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.activeobjects.osgi.ActiveObjectsServiceFactory] startCleaning
        2019-10-18 16:08:28,900 JiraImportTaskExecutionThread-1 DEBUG admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.activeobjects.osgi.ActiveObjectsServiceFactory] stopCleaning
        2019-10-18 16:08:31,440 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=5, totalCount=5, periodSec=137, flushIntervalMillis=27469, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/comments, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@4c7874a8, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/comments lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,443 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=7, totalCount=7, periodSec=138, flushIntervalMillis=19849, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/issues, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@35f8f457, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/issues lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,451 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=5, totalCount=5, periodSec=137, flushIntervalMillis=27472, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/changes, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@3cb92cc6, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/changes lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,455 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=4, totalCount=4, periodSec=137, flushIntervalMillis=34359, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/worklogs, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@5b518463, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/worklogs lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,458 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=5, totalCount=5, periodSec=137, flushIntervalMillis=27469, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/entities/portalpage, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@54037695, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/entities/portalpage lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,459 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.index.ha.DefaultNodeReindexService] Pausing node re-index service
        2019-10-18 16:08:31,461 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.cluster.lock.HeartbeatScheduledExecutorFactory] Heartbeat scheduler shutdown
        2019-10-18 16:08:31,461 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.cluster.ClusterWatchdogService] ClusterWatchdogJob shutting down
        2019-10-18 16:08:31,474 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.plugin.manager.DefaultPluginManager] Preparing to shut down the plugin system
        2019-10-18 16:08:31,481 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.i.m.processor.bootstrap.MailPluginLifeCycleAware] JIRA Email Processor is stopping...
        2019-10-18 16:08:31,482 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.i.m.processor.bootstrap.MailPluginLifeCycleAware] JIRA Email Processor is stopped.
        2019-10-18 16:08:31,483 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.p.w.i.bootstrap.lifecycle.WorkingHoursPluginLauncher] JIRA (SD) Working Hours Plugin stopping...
        2019-10-18 16:08:31,483 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.j.p.w.i.bootstrap.lifecycle.WorkingHoursPluginLauncher] JIRA (SD) Working Hours Plugin stopped
        2019-10-18 16:08:31,484 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.p.internal.bootstrap.Launcher] PSMQ is stopping...
        2019-10-18 16:08:31,486 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.p.internal.bootstrap.Launcher] PSMQ is stopped.
        2019-10-18 16:08:31,488 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.p.a.internal.bootstrap.AutomationPluginLauncher] AutomationPlugin onStop() - Service Desk Automation Plugin is stopping...
        2019-10-18 16:08:31,518 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.p.a.internal.bootstrap.AutomationPluginLauncher] AutomationPlugin onStop() - Service Desk Automation Plugin is stopped.
        2019-10-18 16:08:31,522 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.t.internal.bootstrap.TimedPromiseLauncher] Timed Promises spring context is stopping...
        2019-10-18 16:08:31,523 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.t.internal.bootstrap.TimedPromiseLauncher] Timed Promises spring context is stopped.
        2019-10-18 16:08:31,537 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.jira.index.MonitoringIndexWriter] [lucene-stats] flush stats: snapshotCount=4, totalCount=4, periodSec=140, flushIntervalMillis=35234, indexDirectory=/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/plugins/servicedeskcannedresponses, indexWriterId=com.atlassian.jira.index.MonitoringIndexWriter@2877524, indexDirectoryId=MMapDirectory@/Users/kwong2/jira-home/atlassian-jira-software-8.5.0-m0005/caches/indexesV1/plugins/servicedeskcannedresponses lockFactory=org.apache.lucene.store.NativeFSLockFactory@5ff83778
        2019-10-18 16:08:31,545 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [atlassian.servicedesk.lifecycle] stopping...
        2019-10-18 16:08:31,546 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [atlassian.servicedesk.lifecycle] Server Plugin LifeCycle - Stopping Service Desk
        2019-10-18 16:08:31,557 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.b.lifecycle.server.ServerPluginLifeCycle] Unschedule job to periodically ensure SD mail channels are enabled
        2019-10-18 16:08:31,558 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.b.lifecycle.server.ServerPluginLifeCycle] Finished unscheduling job to periodically ensure SD mail channels are enabled
        2019-10-18 16:08:31,558 JiraImportTaskExecutionThread-1 INFO admin 968x192x1 ri8cs7 0:0:0:0:0:0:0:1 /secure/admin/XmlRestore.jspa [c.a.s.b.lifecycle.server.ServerPluginLifeCycle] Disabling ServiceDesk mail channels...
        
      • With Oracle database, following exception is logged:
        com.atlassian.activeobjects.spi.ActiveObjectsImportExportException: There was an error during import/export with plugin JIRA Service Desk(com.atlassian.servicedesk) #4.5.0-REL-0026 (table AO_54307E_SERIES):
        	at com.atlassian.activeobjects.backup.ImportExportErrorServiceImpl.newImportExportSqlException(ImportExportErrorServiceImpl.java:26)
        
      • No active sessions found in DB.

      Workaround

      1. Restart the JIRA node when the restoration is stuck at 90% for a long time.
      2. If the restart does not help, follow the steps below:
        • Install a fresh Jira instance with an older version (It's tested with Jira 8.0.3)
        • Connect Jira 8.0.3 instance to the destination database
        • Login Jira 8.0.3 and restore XML backup to the destination database
        • Stop Jira 8.0.3
        • Edit connection settings and validation query in the dbconfig.xml for the instance where XML restore is stuck and set it to connect the destination database.
        • Start Jira where XML restore is stuck

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              Unassigned
              Reporter:
              kwong2@atlassian.com KellyW
              Votes:
              7 Vote for this issue
              Watchers:
              8 Start watching this issue

                Dates

                Created:
                Updated: