As seen in section 3.3 of this paper, MonetDB is supposed to clean write ahead logs with regular frequency:
During a server session, the MonetDB server will clean up the log files at a regular time interval (currently, 30 seconds) and if there are sufficient number of changes (currently, 1 million ).
I have a repeating problem occurring every few months where MonetDB fails and then during restart there is a large number of write ahead logs to process. Below is a directory listing showing these files (apologies for the order, I had to manually format this):
ls sql/
log log.106086 log.106095 log.106104 log.106113 log.106122 log.106131 log.106140
log.106149 log.106078 log.106087 log.106096 log.106105 log.106114 log.106123 log.106132
log.106141 log.106150 log.106079 log.106088 log.106097 log.106106 log.106115 log.106124
log.106133 log.106142 log.106151 log.106080 log.106089 log.106098 log.106107 log.106116
log.106125 log.106134 log.106143 log.106152 log.106081 log.106090 log.106099 log.106108
log.106117 log.106126 log.106135 log.106144 log.106082 log.106091 log.106100 log.106109
log.106118 log.106127 log.106136 log.106145 log.106083 log.106092 log.106101 log.106110
log.106119 log.106128 log.106137 log.106146 log.106084 log.106093 log.106102 log.106111
log.106120 log.106129 log.106138 log.106147 log.106085 log.106094 log.106103 log.106112
log.106121 log.106130 log.106139 log.106148
When starting the monetdbd database loading all these files routinely fails with the following messages seen in merovingian.log:
2022-06-03 11:06:02 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106078"
(70% done)
2022-06-03 11:06:13 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106078" (97% done)
2022-06-03 11:06:25 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106079" (38% done)
2022-06-03 11:06:36 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106079" (77% done)
2022-06-03 11:06:54 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106080" (15% done)
2022-06-03 11:07:05 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106080" (52% done)
2022-06-03 11:07:16 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106080" (76% done)
2022-06-03 11:07:38 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106081" (40% done)
2022-06-03 11:07:49 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106081" (64% done)
2022-06-03 11:08:00 MSG warehouse[3172]: # still reading write-ahead log "/home/warehouse/warehouse/sql_logs/sql/log.106081" (93% done)
2022-06-03 11:08:07 ERR warehouse[3172]: #main thread: GDKmmap: !ERROR: requested too much virtual memory; memory requested: 31587172352, memory in use: 243815472, virtual memory in use: 4371382228016
2022-06-03 11:08:07 ERR warehouse[3172]: #main thread: mvc_init: !ERROR: Unable to create system tables
2022-06-03 11:08:07 ERR warehouse[3172]: #main thread: createExceptionInternal: !ERROR: SQLException:SQLinit:42000!Catalogue initialization failed
2022-06-03 11:08:07 ERR warehouse[3172]: #main thread: SQLprelude: !ERROR: Fatal error during initialization: SQLException:SQLinit:42000!Catalogue initialization failed
2022-06-03 11:08:09 MSG merovingian[2681]: database 'warehouse' (-1) has exited with exit status 1
2022-06-03 11:08:10 ERR control[2681]: !monetdbd: an internal error has occurred 'database 'warehouse' has crashed after starting, manual intervention needed, check monetdbd's logfile (merovingian.log) for details'
2022-06-03 11:08:14 ERR merovingian[2681]: client error: database 'warehouse' has crashed after starting, manual intervention needed, check monetdbd's logfile (merovingian.log) for details
This can be resolved by manually removing files to avoid them being processed and accepting the resulting data loss but is the only way I'm aware of to start the database once in this condition (see related question here).
My question is, is there a way to prevent this, maybe in config somewhere? If I could tell MonetDB to clean these logs more frequently and save the data to the database this would prevent the issue. Alternatively, is there a manual command that could be used? Currently cleaning sql logs is happening on a scale of every few weeks or possibly not at all, far from the 30 seconds mentioned in the paper linked at the beginning of this post.
Thanks,
James
In your comment you mention that you are running MonetDB Oct2020-SP5. That's a rather old, unsupported version.
The accumulation of log files is probably due to MonetDB not being able to get 'time to breath' and apply the changes in the log to its stable storage. In the Jul2021 release, MonetDB's transaction layer has been completely revised and this should be much less of a problem.
I recommend upgrading to a more recent version such as the Jan2022-SP3 release and checking the behavior of that version under your workload.