evolvedbinary/fusiondb-server

Journal files not removed on Windows

Closed this issue · 2 comments

  • FusionDB Server 1.0.0-ALPHA2 (installed as a service)
  • Windows Server 2012 R2 Standard
  • As the Administrator
  1. Generate a 10GB XMark dataset using:

    xmlgen /f 68 /i /s 10000 /o output\output.xml
    

    Make sure the files have .xml file extensions

    find output/ -name \*.xml* -exec mv {} {}.xml \;
    
  2. Load the XML files using the JAC in embedded mode.

  3. Examine the C:\Users\Administrator\AppData\Roaming\FusionDB Server\data\rocks directory. You will see very many .log files, which take up much more space than the .sst files.


Restarting the FusionDB-Server service, leads to recovery running:

Determining the recovery process is in-progress can be seen by looking in C:\Users\Administrator\AppData\Roaming\FusionDB Server\logs\fusiondb-server-stdout.2019-09-09.log and seeing the end of the log looking like:

09 Sep 2019 12:09:49,800 [main] INFO  (JettyStart.java [run]:186) - [Operating System : Windows Server 2012 R2 6.3 amd64] 
09 Sep 2019 12:09:50,457 [main] INFO  (JettyStart.java [run]:200) - Configuring FusionDB eXist component from C:\Program Files\FusionDB Server\etc\conf.xml 

You can observe the recovery process by looking in C:\Users\Administrator\AppData\Roaming\FusionDB Server\logs\rocksdb.log and seeing:

2019-09-09 12:16:14,963 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #176 mode 2 
2019-09-09 12:16:23,961 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #181 mode 2 
2019-09-09 12:16:33,197 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #182 mode 2 
2019-09-09 12:16:42,366 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #187 mode 2 
2019-09-09 12:16:51,631 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #188 mode 2 
2019-09-09 12:17:00,692 [main] INFO  (RocksLoggerAdapter.java [log]:79) - [db_impl\db_impl_open.cc:676] Recovering log #193 mode 2 

The numbers #176, #181, etc. correspond to .log files in the C:\Users\Administrator\AppData\Roaming\FusionDB Server\data\rocks folder. They will be processed incrementally and a log line written for each. When each has completed, back in fusiondb-server-stdout.2019-09-09.log you should see the startup complete, once it says:

07 Sep 2019 12:21:01,265 [main] INFO  (JettyStart.java [run]:286) - FusionDB Server has started, listening on: 
07 Sep 2019 12:21:01,265 [main] INFO  (JettyStart.java [run]:288) - http://172.31.27.186:4059/ 
07 Sep 2019 12:21:01,265 [main] INFO  (JettyStart.java [run]:288) - https://172.31.27.186:5059/

At least in our test instance, we are not quite sure why there are so many outstanding Journal logs, each one should be cleared once the corresponding SST file has been fsync'd to disk.

I was also able to reproduce this on Ubuntu 18.04.

Seems to be a bigger issue though -facebook/rocksdb#5789 (comment)

Fixed Sept 13th 2019 by setting:

<maxTotalWalSize>1073741824</maxTotalWalSize> <!--  1GB -->

in the file: fusiondb-server-distribution/fusiondb-server-distribution-parent/src/main/config/DBOptions.xml