Adding more logging to help diagnose Tyre Kicking failure

Also update the upgradeId component of StoreId as part of the restore
process

enterprise/core-edge/src/main/java/org/neo4j/coreedge/convert/ConvertClassicStoreToCoreCommand.java

@@ -133,8 +133,10 @@ public static ClusterSeed changeStoreId( File storeDir, ClusterSeed conversionId
 
             long lastTxId = MetaDataStore.getRecord( pageCache, metadataStore, LAST_TRANSACTION_ID );
 
-            Long upgradeTime = conversionId == null ? System.currentTimeMillis() : conversionId.after().getUpgradeTime();
+            long upgradeTime = conversionId.after().getUpgradeTime();
+            long upgradeId = conversionId.after().getUpgradeId();
             MetaDataStore.setRecord( pageCache, metadataStore, UPGRADE_TIME, upgradeTime );
+            MetaDataStore.setRecord( pageCache, metadataStore, UPGRADE_TRANSACTION_ID, upgradeId );
 
             StoreId after = readStoreId( metadataStore, pageCache );
             return new ClusterSeed( before, after, lastTxId );

enterprise/core-edge/src/main/java/org/neo4j/coreedge/convert/GenerateClusterSeedCommand.java

@@ -49,19 +49,19 @@ private ClusterSeed metadata( File storeDir ) throws IOException
         File metadataStore = new File( storeDir, MetaDataStore.DEFAULT_NAME );
         try ( PageCache pageCache = StandalonePageCacheFactory.createPageCache( fs ) )
         {
-            StoreId before = storeId( metadataStore, pageCache, getRecord( pageCache, metadataStore, UPGRADE_TIME ) );
-            StoreId after = storeId( metadataStore, pageCache, System.currentTimeMillis() );
             long lastTxId = getRecord( pageCache, metadataStore, LAST_TRANSACTION_ID );
+            StoreId before = storeId( metadataStore, pageCache, getRecord( pageCache, metadataStore, UPGRADE_TIME ),
+                    getRecord( pageCache, metadataStore, UPGRADE_TRANSACTION_ID ) );
+            StoreId after = storeId( metadataStore, pageCache, System.currentTimeMillis(), lastTxId );
 
             return new ClusterSeed( before, after, lastTxId );
         }
     }
 
-    public static StoreId storeId( File metadataStore, PageCache pageCache, long upgradeTime ) throws IOException
+    public static StoreId storeId( File metadataStore, PageCache pageCache, long upgradeTime, long upgradeId ) throws IOException
     {
         long creationTime = getRecord( pageCache, metadataStore, TIME );
         long randomNumber = getRecord( pageCache, metadataStore, RANDOM_NUMBER );
-        long upgradeId = getRecord( pageCache, metadataStore, UPGRADE_TRANSACTION_ID );
         return new StoreId( creationTime, randomNumber, upgradeTime, upgradeId );
     }
 

enterprise/core-edge/src/main/java/org/neo4j/coreedge/raft/BatchingMessageHandler.java

@@ -109,12 +109,14 @@ public void run()
             {
                 if ( localDatabase.isEmpty() )
                 {
+                    log.info( "StoreId mismatch but store was empty so downloading new store from %s. Expected: " +
+                            "%s, Encountered: %s. ", innerMessage.from(), storeId, localDatabase.storeId() );
                     raftStateMachine.downloadSnapshot( innerMessage.from() );
                 }
                 else
                 {
-                    log.info( "Discarding message owing to mismatched storeId and non-empty store. " +
-                            "Expected: %s, Encountered: %s", storeId, localDatabase.storeId() );
+                    log.info( "Discarding message[%s] owing to mismatched storeId and non-empty store. " +
+                            "Expected: %s, Encountered: %s", innerMessage,  storeId, localDatabase.storeId() );
                     listeners.forEach( l -> {
                         MismatchedStoreIdException ex = new MismatchedStoreIdException( storeId, localDatabase.storeId() );
                         l.onMismatchedStore( ex );

enterprise/core-edge/src/main/java/org/neo4j/coreedge/raft/replication/session/GlobalSessionTrackerState.java

@@ -106,6 +106,12 @@ public GlobalSessionTrackerState newInstance()
         return copy;
     }
 
+    @Override
+    public String toString()
+    {
+        return String.format( "GlobalSessionTrackerState{sessionTrackers=%s, logIndex=%d}", sessionTrackers, logIndex );
+    }
+
     public static class Marshal extends SafeStateMarshal<GlobalSessionTrackerState>
     {
         private final ChannelMarshal<CoreMember> memberMarshal;
@@ -242,5 +248,12 @@ public LocalSessionTracker newInstance()
         {
             return new LocalSessionTracker( globalSessionId, new HashMap<>( lastSequenceNumberPerSession ) );
         }
+
+        @Override
+        public String toString()
+        {
+            return String.format( "LocalSessionTracker{globalSessionId=%s, lastSequenceNumberPerSession=%s}",
+                    globalSessionId, lastSequenceNumberPerSession );
+        }
     }
 }

enterprise/core-edge/src/main/java/org/neo4j/coreedge/raft/state/CoreSnapshot.java

@@ -27,6 +27,8 @@
 import org.neo4j.storageengine.api.ReadableChannel;
 import org.neo4j.storageengine.api.WritableChannel;
 
+import static java.lang.String.format;
+
 public class CoreSnapshot
 {
     private final long prevIndex;
@@ -105,4 +107,10 @@ public CoreSnapshot unmarshal0( ReadableChannel channel ) throws IOException, En
             return coreSnapshot;
         }
     }
+
+    @Override
+    public String toString()
+    {
+        return format( "CoreSnapshot{prevIndex=%d, prevTerm=%d, snapshotCollection=%s}", prevIndex, prevTerm, snapshotCollection );
+    }
 }

enterprise/core-edge/src/main/java/org/neo4j/coreedge/raft/state/CoreStateDownloader.java

@@ -77,14 +77,18 @@ synchronized void downloadSnapshot( CoreMember source, CoreState coreState ) thr
             }
 
             localDatabase.copyStoreFrom( source, storeFetcher ); // this deletes the current store
+            log.info( "Replaced store with one downloaded from %s", source );
 
             /* We install the snapshot after the store has been downloaded,
              * so that we are not left with a state ahead of the store. */
             coreState.installSnapshot( coreSnapshot );
+            log.info( "Core snapshot installed: " + coreSnapshot );
 
             /* Starting the database will invoke the commit process factory in
              * the EnterpriseCoreEditionModule, which has important side-effects. */
+            log.info( "Restarting local database", source );
             localDatabase.start();
+            log.info( "Restarted local database", source );
         }
         catch ( IOException | ExecutionException e )
         {

enterprise/core-edge/src/main/java/org/neo4j/coreedge/raft/state/id_allocation/IdAllocationState.java

@@ -166,4 +166,11 @@ public long ordinal( IdAllocationState state )
             return state.logIndex();
         }
     }
+
+    @Override
+    public String toString()
+    {
+        return String.format( "IdAllocationState{firstUnallocated=%s, logIndex=%d}",
+                Arrays.toString( firstUnallocated ), logIndex );
+    }
 }

enterprise/core-edge/src/test/java/org/neo4j/coreedge/TestStoreId.java

@@ -26,6 +26,7 @@
 import java.util.Objects;
 import java.util.Set;
 
+import org.neo4j.coreedge.server.StoreId;
 import org.neo4j.io.fs.DefaultFileSystemAbstraction;
 import org.neo4j.io.fs.FileSystemAbstraction;
 import org.neo4j.io.pagecache.PageCache;
@@ -41,58 +42,10 @@
 
 public class TestStoreId
 {
-    private final long creationTime;
-    private final long randomNumber;
-    private final long upgradeTime;
-    private final long upgradeId;
-
-    public TestStoreId( long creationTime, long randomNumber, long upgradeTime, long upgradeId )
-    {
-        this.creationTime = creationTime;
-        this.randomNumber = randomNumber;
-        this.upgradeTime = upgradeTime;
-        this.upgradeId = upgradeId;
-    }
-
-    @Override
-    public boolean equals( Object o )
-    {
-        if ( this == o )
-        {
-            return true;
-        }
-        if ( o == null || getClass() != o.getClass() )
-        {
-            return false;
-        }
-        TestStoreId storeId = (TestStoreId) o;
-        return creationTime == storeId.creationTime &&
-                randomNumber == storeId.randomNumber &&
-                upgradeTime == storeId.upgradeTime &&
-                upgradeId == storeId.upgradeId;
-    }
-
-    @Override
-    public int hashCode()
-    {
-        return Objects.hash( creationTime, randomNumber, upgradeTime, upgradeId );
-    }
-
-    @Override
-    public String toString()
-    {
-        return "TestStoreId{" +
-                "creationTime=" + creationTime +
-                ", randomNumber=" + randomNumber +
-                ", upgradeTime=" + upgradeTime +
-                ", upgradeId=" + upgradeId +
-                '}';
-    }
-
     public static void assertAllStoresHaveTheSameStoreId( List<File> coreStoreDirs, FileSystemAbstraction fs )
             throws IOException
     {
-        Set<TestStoreId> storeIds = new HashSet<>();
+        Set<StoreId> storeIds = new HashSet<>();
         try ( PageCache pageCache = StandalonePageCacheFactory.createPageCache( fs ) )
         {
             for ( File coreStoreDir : coreStoreDirs )
@@ -103,15 +56,15 @@ public static void assertAllStoresHaveTheSameStoreId( List<File> coreStoreDirs,
         assertEquals( "Store Ids " + storeIds, 1, storeIds.size() );
     }
 
-    public static TestStoreId readStoreId( File coreStoreDir, DefaultFileSystemAbstraction fs ) throws IOException
+    public static StoreId readStoreId( File coreStoreDir, DefaultFileSystemAbstraction fs ) throws IOException
     {
         try ( PageCache pageCache = StandalonePageCacheFactory.createPageCache( fs ) )
         {
             return doReadStoreId( coreStoreDir, pageCache );
         }
     }
 
-    private static TestStoreId doReadStoreId( File coreStoreDir, PageCache pageCache ) throws IOException
+    private static StoreId doReadStoreId( File coreStoreDir, PageCache pageCache ) throws IOException
     {
         File metadataStore = new File( coreStoreDir, MetaDataStore.DEFAULT_NAME );
 
@@ -120,6 +73,6 @@ private static TestStoreId doReadStoreId( File coreStoreDir, PageCache pageCache
         long upgradeTime = MetaDataStore.getRecord( pageCache, metadataStore, UPGRADE_TIME );
         long upgradeId = MetaDataStore.getRecord( pageCache, metadataStore, UPGRADE_TRANSACTION_ID );
 
-        return new TestStoreId( creationTime, randomNumber, upgradeTime, upgradeId );
+        return new StoreId( creationTime, randomNumber, upgradeTime, upgradeId );
     }
 }

enterprise/core-edge/src/test/java/org/neo4j/coreedge/backup/BackupCoreIT.java

@@ -39,6 +39,7 @@
 import org.neo4j.coreedge.discovery.Cluster;
 import org.neo4j.coreedge.discovery.CoreServer;
 import org.neo4j.coreedge.server.CoreEdgeClusterSettings;
+import org.neo4j.coreedge.server.StoreId;
 import org.neo4j.coreedge.server.core.CoreGraphDatabase;
 import org.neo4j.graphdb.Node;
 import org.neo4j.graphdb.factory.GraphDatabaseSettings;
@@ -141,7 +142,7 @@ public void makeSureCoreClusterCanBeRestoredFromABackup() throws Throwable
 
         cluster.shutdown();
         assertAllStoresHaveTheSameStoreId( dbPaths, fs );
-        TestStoreId storeId = TestStoreId.readStoreId( dbPaths.get( 0 ), fs );
+        StoreId storeId = TestStoreId.readStoreId( dbPaths.get( 0 ), fs );
 
         // when
 
@@ -172,7 +173,7 @@ public void makeSureCoreClusterCanBeRestoredFromABackup() throws Throwable
         cluster.shutdown();
 
         assertAllStoresHaveTheSameStoreId( afterRestoreDbPaths, fs );
-        TestStoreId afterRestoreStoreId = TestStoreId.readStoreId( afterRestoreDbPaths.get( 0 ), fs );
+        StoreId afterRestoreStoreId = TestStoreId.readStoreId( afterRestoreDbPaths.get( 0 ), fs );
         assertNotEquals( storeId, afterRestoreStoreId );
     }
 

enterprise/core-edge/src/test/java/org/neo4j/restore/RestoreClusterCliTest.java

@@ -58,6 +58,7 @@
 import static org.neo4j.coreedge.convert.GenerateClusterSeedCommand.storeId;
 import static org.neo4j.kernel.impl.store.MetaDataStore.Position.LAST_TRANSACTION_ID;
 import static org.neo4j.kernel.impl.store.MetaDataStore.Position.UPGRADE_TIME;
+import static org.neo4j.kernel.impl.store.MetaDataStore.Position.UPGRADE_TRANSACTION_ID;
 import static org.neo4j.kernel.impl.store.MetaDataStore.getRecord;
 import static org.neo4j.restore.RestoreExistingClusterCli.settings;
 
@@ -117,10 +118,11 @@ private StoreMetadata metadataFor( File classicNeo4jStore ) throws IOException
 
         try ( PageCache pageCache = StandalonePageCacheFactory.createPageCache( fs ) )
         {
-            StoreId classicStoreId = storeId( metadataStore, pageCache, getRecord( pageCache, metadataStore,
-                    UPGRADE_TIME ) );
-            long lastTransactionId = getRecord( pageCache, metadataStore, LAST_TRANSACTION_ID );
-            return new StoreMetadata( classicStoreId, lastTransactionId );
+            long lastTxId = getRecord( pageCache, metadataStore, LAST_TRANSACTION_ID );
+            long upgradeTime = getRecord( pageCache, metadataStore, UPGRADE_TIME );
+            long upgradeId = getRecord( pageCache, metadataStore, UPGRADE_TRANSACTION_ID );
+            StoreId classicStoreId = storeId( metadataStore, pageCache, upgradeTime, upgradeId );
+            return new StoreMetadata( classicStoreId, lastTxId );
         }
     }