"Error closing database" every time the server is stopped #1230
Description
ArcadeDB Version:
v23.6.1 (build 0eba746/1688529087201/main)
OS and JDK Version:
Windows 10 10.0 - OpenJDK 64-Bit Server VM 11.0.20.1 (Corretto-11.0.20.9.1)
Expected behavior
Stopping the server closes cleanly all open databases, like it did in previous versions.
Actual behavior
Since v23.6.1, every time I stop the server, I get the following messages in the log file:
2023-09-05 08:49:17.552 INFO [ArcadeDBServer] <ArcadeDB_0> Shutting down ArcadeDB Server...
2023-09-05 08:49:17.562 SEVER [CodeUtils] <ArcadeDB_0> Error closing database 'test'
2023-09-05 08:49:17.562 INFO [ArcadeDBServer] <ArcadeDB_0> - Stop JMX Metrics
2023-09-05 08:49:17.562 INFO [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server is down
and the database directory still contains the .lck file.
If I do this in production, after non-trivial operations have been done on the database, I get additional errors when re-starting the server, e.g.:
2023-09-03 08:52:58.256 INFO [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server v23.6.1 (build 0eba746edfdf65b4a2dc483bfc5435bca397e55f/1688529087201/main) is starting up...
2023-09-03 08:52:58.269 INFO [ArcadeDBServer] <ArcadeDB_0> Running on Linux 2.6.32-754.35.1.el6.x86_64 - OpenJDK 64-Bit Server VM 11.0.20 (Corretto-11.0.20.8.1)
2023-09-03 08:52:58.280 INFO [ArcadeDBServer] <ArcadeDB_0> Starting ArcadeDB Server in development mode with plugins [Orchestrator] ...
2023-09-03 08:52:58.709 WARNI [EmbeddedDatabase] <ArcadeDB_0> Database 'csrsdb' was not closed properly last time
2023-09-03 08:52:58.710 WARNI [TransactionManager] <ArcadeDB_0> Started recovery of database 'csrsdb'
2023-09-03 08:52:58.722 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 51
2023-09-03 08:52:58.724 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 52
2023-09-03 08:52:58.731 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 53
2023-09-03 08:52:58.733 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 54
2023-09-03 08:52:58.737 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 55
2023-09-03 08:52:58.740 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 56
2023-09-03 08:52:58.746 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 57
2023-09-03 08:52:58.747 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 58
2023-09-03 08:52:58.751 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 59
2023-09-03 08:52:58.753 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 60
2023-09-03 08:52:58.756 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 61
2023-09-03 08:52:58.757 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 62
2023-09-03 08:52:58.758 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 63
2023-09-03 08:52:58.763 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 64
2023-09-03 08:52:58.765 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 65
2023-09-03 08:52:58.767 WARNI [TransactionManager] <ArcadeDB_0> Error on restoring transaction: received operation on deleted file 66
2023-09-03 08:52:58.845 WARNI [TransactionManager] <ArcadeDB_0> Recovery of database 'csrsdb' completed
Steps to reproduce
Execute the attached testCreateDatabaseThenStartAndStopServer test case, which performs the following operations:
- create a database
- start the server
- stop the server
After the test has run, the log file contains the error Error closing database 'test' and the .lck file has not been deleted.
It is also interesting to note that when I execute the test case in Intellij IDEA, the IDE shows that the test is still running even after the server has shut down.
testCreateDatabaseThenStartAndStopServer.zip