Repository: diennea/herddb (java)

Issue:
Drop TABLE does not unload pages from the policy
In case of "DROP TABLE" we are not unloading all of the loaded pages and so the policy keeps references to them and it can potentially require an "unload".

This error has been reported in production (HerdDB Collections Framework, that uses a lot the DROP TABLE feature)


```
java.lang.RuntimeException: herddb.collections.CollectionsException: herddb.model.StatementExecutionException: herddb.storage.DataStorageManagerException: java.nio.file.NoSuchFileException: /xxxxxxxxtmp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at magnews.statsengine.proc.ProcEngine.lambda$scanHUserLogForClassicAccount$6(ProcEngine.java:3615)
        at magnews.statsengine.StatEngineDBConnection._visitNotifEventsFromSql(StatEngineDBConnection.java:7334)
        at magnews.statsengine.StatEngineDBConnection.visitNotifEvents(StatEngineDBConnection.java:7033)
        at magnews.statsengine.StatEngineDBConnection.visitNotifEvents(StatEngineDBConnection.java:6879)
        at magnews.statsengine.proc.ProcEngine.scanHUserLogForClassicAccount(ProcEngine.java:3611)
        at magnews.statsengine.proc.DailyAggregator.executeDailyAggregation(DailyAggregator.java:186)
        at magnews.statsengine.proc.DailyAggregator.work(DailyAggregator.java:98)
        at magnews.statsengine.proc.DailyAggregator.work(DailyAggregator.java:75)
        at magnews.statsengine.proc.DailyAggregator.run(DailyAggregator.java:231)
        at magnews.threads.locks.DistributedLockController.executeOnlyOnce(DistributedLockController.java:87)
        at magnews.statsengine.proc.DailyAggregatorTokenProcessor.process(DailyAggregatorTokenProcessor.java:52)
        at magnews.node.MajorodoTaskExecutorAdapter$LocalTaskExecutor.run(MajorodoTaskExecutorAdapter.java:167)
        at magnews.majorodo.worker.MajordodoWorkerService$TaskExecutorImpl.executeTask(MajordodoWorkerService.java:179)
        at majordodo.worker.ExecutorRunnable.run(ExecutorRunnable.java:59)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:835)
Caused by: java.lang.RuntimeException: herddb.collections.CollectionsException: herddb.model.StatementExecutionException: herddb.storage.DataStorageManagerException: java.nio.file.NoSuchFileException: /xxxxxxnode/tmp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at magnews.io.BoundedCollectionsManager$TmpMapWrapper.put(BoundedCollectionsManager.java:197)
        at magnews.statsengine.proc.ProcEngine$2.execute(ProcEngine.java:3604)
        at magnews.g0.util.BatchActionExecutor.execute(BatchActionExecutor.java:34)
        at magnews.statsengine.proc.ProcEngine.lambda$scanHUserLogForClassicAccount$6(ProcEngine.java:3613)
        ... 18 more
Caused by: herddb.collections.CollectionsException: herddb.model.StatementExecutionException: herddb.storage.DataStorageManagerException: java.nio.file.NoSuchFileException: /xxxx/mp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at herddb.collections.TmpMapImpl.put(TmpMapImpl.java:157)
        at magnews.io.BoundedCollectionsManager$TmpMapWrapper.put(BoundedCollectionsManager.java:194)
        ... 21 more
Caused by: herddb.model.StatementExecutionException: herddb.storage.DataStorageManagerException: java.nio.file.NoSuchFileException: /data/mn1/node/tmp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at herddb.core.TableSpaceManager.executeStatement(TableSpaceManager.java:1014)
        at herddb.collections.TmpMapImpl.put(TmpMapImpl.java:152)
        ... 22 more
Caused by: herddb.storage.DataStorageManagerException: java.nio.file.NoSuchFileException: /xxxxxxp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at herddb.file.FileDataStorageManager.writePage(FileDataStorageManager.java:889)
        at herddb.core.TableManager.flushNewPage(TableManager.java:914)
        at herddb.core.TableManager.flushNewPageForUnload(TableManager.java:792)
        at herddb.core.TableManager.lambda$unload$2(TableManager.java:714)
        at java.base/java.util.concurrent.ConcurrentHashMap.computeIfPresent(ConcurrentHashMap.java:1822)
        at herddb.core.TableManager.unload(TableManager.java:707)
        at herddb.core.TableManager.allocateLivePage(TableManager.java:633)
        at herddb.core.TableManager.applyInsert(TableManager.java:1948)
        at herddb.core.TableManager.apply(TableManager.java:1582)
        at herddb.core.TableManager.lambda$executeInsertAsync$4(TableManager.java:1101)
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:642)
        at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)
        at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:261)
        at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:677)
        at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
        at java.base/java.util.concurrent.CompletableFuture.thenApplyAsync(CompletableFuture.java:2175)
        at herddb.core.TableManager.executeInsertAsync(TableManager.java:1100)
        at herddb.core.TableManager.executeStatementAsync(TableManager.java:545)
        at herddb.core.TableSpaceManager.executeTableAwareStatement(TableSpaceManager.java:1176)
        at herddb.core.TableSpaceManager.executeStatementAsyncInternal(TableSpaceManager.java:1080)
        at herddb.core.TableSpaceManager.executeStatementAsync(TableSpaceManager.java:1060)
        at herddb.core.TableSpaceManager.executeStatement(TableSpaceManager.java:1003)
        ... 23 more
Caused by: java.nio.file.NoSuchFileException: /xxxxxxxtmp/swap/1d98e62e17d44834a7920f2db7dea569.tablespace/0a86b120-01ab-4cd0-9b8b-31d1a9a244ab.table/1.page
        at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
        at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116)
        at java.base/sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:182)
        at java.base/java.nio.channels.FileChannel.open(FileChannel.java:292)
        at java.base/java.nio.channels.FileChannel.open(FileChannel.java:345)
        at herddb.utils.ManagedFile.open(ManagedFile.java:78)
        at herddb.file.FileDataStorageManager.writePage(FileDataStorageManager.java:880)
        ... 44 more
```


Pull request:
Ensure that pages are unloaded on table drop
Fixes #434


Patch:
diff --git a/herddb-core/src/main/java/herddb/core/TableManager.java b/herddb-core/src/main/java/herddb/core/TableManager.java
index 3f08154d..0aff7121 100644
--- a/herddb-core/src/main/java/herddb/core/TableManager.java
+++ b/herddb-core/src/main/java/herddb/core/TableManager.java
@@ -707,19 +707,23 @@ public final class TableManager implements AbstractTableManager, Page.Owner {
         pages.computeIfPresent(pageId, (k, remove) -> {
 
             unloadedPagesCount.increment();
-            LOGGER.log(Level.FINER, "table {0} removed page {1}, {2}", new Object[]{table.name, pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
+            if (LOGGER.isLoggable(Level.FINER)) {
+                LOGGER.log(Level.FINER, "table {0} removed page {1}, {2}", new Object[]{table.name, pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
+            }
 
             boolean dataFlushed = false;
             if (!remove.immutable) {
                 dataFlushed = flushNewPageForUnload(remove);
             }
 
-            if (dataFlushed) {
-                LOGGER.log(Level.FINER, "table {0} remove and save 'new' page {1}, {2}",
-                        new Object[]{table.name, remove.pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
-            } else {
-                LOGGER.log(Level.FINER, "table {0} unload page {1}, {2}",
-                        new Object[]{table.name, pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
+            if (LOGGER.isLoggable(Level.FINER)) {
+                if (dataFlushed) {
+                    LOGGER.log(Level.FINER, "table {0} remove and save 'new' page {1}, {2}",
+                            new Object[]{table.name, remove.pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
+                } else {
+                    LOGGER.log(Level.FINER, "table {0} unload page {1}, {2}",
+                            new Object[]{table.name, pageId, remove.getUsedMemory() / (1024 * 1024) + " MB"});
+                }
             }
 
             return null;
@@ -1383,13 +1387,7 @@ public final class TableManager implements AbstractTableManager, Page.Owner {
             }
         }
 
-        /* Do not unload the current working page not known to replacement policy */
-        final long currentDirtyPageId = currentDirtyRecordsPage.get();
-        final List<DataPage> unload = pages.values().stream()
-                .filter(page -> page.pageId != currentDirtyPageId)
-                .collect(Collectors.toList());
-
-        pageReplacementPolicy.remove(unload);
+        unloadAllPagesForTruncate();
 
         pageSet.truncate();
 
@@ -1408,6 +1406,16 @@ public final class TableManager implements AbstractTableManager, Page.Owner {
 
     }
 
+    private void unloadAllPagesForTruncate() {
+        /* Do not unload the current working page not known to replacement policy */
+        final long currentDirtyPageId = currentDirtyRecordsPage.get();
+        final List<DataPage> unload = pages.values().stream()
+                .filter(page -> page.pageId != currentDirtyPageId)
+                .collect(Collectors.toList());
+
+        pageReplacementPolicy.remove(unload);
+    }
+
     @Override
     public void onTransactionCommit(Transaction transaction, boolean recovery) throws DataStorageManagerException {
         if (transaction == null) {
@@ -1823,6 +1831,7 @@ public final class TableManager implements AbstractTableManager, Page.Owner {
                 indexManager.dropIndexData();
             }
         }
+        unloadAllPagesForTruncate();
     }
 
     @Override


Test patch:
diff --git a/herddb-core/src/test/java/herddb/core/DropTablespaceTest.java b/herddb-core/src/test/java/herddb/core/DropTablespaceTest.java
index 0bfcdf11..d50d965d 100644
--- a/herddb-core/src/test/java/herddb/core/DropTablespaceTest.java
+++ b/herddb-core/src/test/java/herddb/core/DropTablespaceTest.java
@@ -20,6 +20,10 @@
 package herddb.core;
 
 import static herddb.core.TestUtils.execute;
+import herddb.core.stats.TableManagerStats;
+import herddb.file.FileCommitLogManager;
+import herddb.file.FileDataStorageManager;
+import herddb.file.FileMetadataStorageManager;
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertTrue;
 
@@ -36,14 +40,22 @@ import herddb.model.StatementEvaluationContext;
 import herddb.model.TransactionContext;
 import herddb.model.commands.CreateTableSpaceStatement;
 import herddb.model.commands.DropTableSpaceStatement;
+import herddb.server.ServerConfiguration;
+import java.nio.file.Path;
+import org.apache.bookkeeper.stats.NullStatsLogger;
+import org.junit.Rule;
+import org.junit.rules.TemporaryFolder;
 
 /**
- * Drop Tablespace Tests
+ * Drop Tablespace and Tables Tests
  *
  * @author enrico.olivelli
  */
 public class DropTablespaceTest {
 
+    @Rule
+    public TemporaryFolder folder = new TemporaryFolder();
+
     @Test
     public void test() throws Exception {
         String nodeId = "localhost";
@@ -87,4 +99,57 @@ public class DropTablespaceTest {
             }
         }
     }
+
+    @Test
+    public void testCleanPolicyOnDropTable() throws Exception {
+        String nodeId = "localhost";
+        ServerConfiguration serverConfig = new ServerConfiguration();
+        // very low memory
+        serverConfig.set(ServerConfiguration.PROPERTY_MAX_DATA_MEMORY, 2_000_000);
+        serverConfig.set(ServerConfiguration.PROPERTY_MAX_PK_MEMORY, 2_000_000);
+        Path dataPath = folder.newFolder("data").toPath();
+        Path logsPath = folder.newFolder("logs").toPath();
+        Path metadataPath = folder.newFolder("metadata").toPath();
+        Path tmoDir = folder.newFolder("tmoDir").toPath();
+
+        try (DBManager manager = new DBManager(nodeId,
+                new FileMetadataStorageManager(metadataPath),
+                new FileDataStorageManager(dataPath),
+                new MemoryCommitLogManager(false),
+                tmoDir, null, serverConfig, NullStatsLogger.INSTANCE)) {
+            manager.start();
+            CreateTableSpaceStatement st1 = new CreateTableSpaceStatement("tblspace1", Collections.singleton(nodeId), nodeId, 1, 0, 0);
+            manager.executeStatement(st1, StatementEvaluationContext.DEFAULT_EVALUATION_CONTEXT(), TransactionContext.NO_TRANSACTION);
+            manager.waitForTablespace("tblspace1", 10000);
+            execute(manager, "CREATE TABLE tblspace1.tsql (k1 string primary key,n1 int,s1 string)", Collections.emptyList());
+            execute(manager, "CREATE TABLE tblspace1.tsql2 (k1 string primary key,n1 int,s1 string)", Collections.emptyList());
+
+            for (int i = 0; i < 10000; i++) {
+                execute(manager, "INSERT INTO tblspace1.tsql (k1 ,n1 ,s1 ) values(?,?,?)",
+                        Arrays.asList(i, i, "jkhdskfhjdskfhskdjfhksdhfkshfkjhsdlkhflksjhfklshdkljhsdlkf"
+                        + "ksdjhfkdsflksdjhfklsdhjflksdhjflksdhjfklsdhjfklsdjhfsd"
+                        + "skjhsdlkfjhdslkfjhsdlkfjhsdlkfhjsklhdfkldshjflksjhdflkhsdf"
+                        + "jsdklfjhdslkfjhsdlkfhjslkjhfdlksjhdfklshjdflkhslkfdhslkfhslkfhslkdjfhklsdhjflkhsfd"
+                        + "jklsdhfksdjhflksdjhflksjhfdlkjhsdlfkhjslkfjhslkdfjhklsdhjfklhsdff"
+                        + "lksdjhflkshdjflkhjsdlkfjhsldkfjhslkfdfoo" + i));
+            }
+            // drop the table, any reference to the pages should be discarded
+            execute(manager, "DROP TABLE tblspace1.tsql", Collections.emptyList());
+
+            // write data to the second table, there will be no more space for table1 and if
+            // any page is still reference we should see the error of
+            // https://github.com/diennea/herddb/issues/434
+            for (int i = 0; i < 3000; i++) {
+                System.out.println("after "+i);
+                execute(manager, "INSERT INTO tblspace1.tsql2 (k1 ,n1 ,s1 ) values(?,?,?)",
+                        Arrays.asList(i, i, "jkhdskfhjdskfhskdjfhksdhfkshfkjhsdlkhflksjhfklshdkljhsdlkf"
+                        + "ksdjhfkdsflksdjhfklsdhjflksdhjflksdhjfklsdhjfklsdjhfsd"
+                        + "skjhsdlkfjhdslkfjhsdlkfjhsdlkfhjsklhdfkldshjflksjhdflkhsdf"
+                        + "jsdklfjhdslkfjhsdlkfhjslkjhfdlksjhdfklshjdflkhslkfdhslkfhslkfhslkdjfhklsdhjflkhsfd"
+                        + "jklsdhfksdjhflksdjhflksjhfdlkjhsdlfkhjslkfjhslkdfjhklsdhjfklhsdff"
+                        + "lksdjhflkshdjflkhjsdlkfjhsldkfjhslkfdfoo" + i));
+            }
+        }
+    }
+
 }