Repeatedly corrupt database

[meichthys]

Environment: I am currently running zoneminder in docker which is a VM running in a proxmox virtual environment for a few months now but every couple weeks i seem to get a corrupted database that results in the following mysql log (/var/log/mysql/error.log). So far i have not been able to recover from this and have needed to rebuild from scratch each time :(

root@399ac6fdf550:/# tail -100 /var/log/mysql/error.log
2021-03-10  0:36:42 0 [ERROR] InnoDB: Page [page id: space=0, page number=299] log sequence number 802575815 is in the future! Current system log sequence number 308713493.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Page [page id: space=0, page number=475] log sequence number 802575815 is in the future! Current system log sequence number 308713493.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Page [page id: space=0, page number=300] log sequence number 802575859 is in the future! Current system log sequence number 308713493.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Page [page id: space=0, page number=323] log sequence number 802575859 is in the future! Current system log sequence number 308713493.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Page [page id: space=0, page number=0] log sequence number 802575683 is in the future! Current system log sequence number 308713493.
2021-03-10  0:36:42 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
2021-03-10  0:36:42 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-03-10  0:36:42 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2021-03-10  0:36:42 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-03-10  0:36:42 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-03-10  0:36:42 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2021-03-10  0:36:42 0 [Note] InnoDB: Waiting for purge to start
2021-03-10 00:36:42 0x7f957affd700  InnoDB: Assertion failure in file /build/mariadb-10.3-dx4Qbh/mariadb-10.3-10.3.25/storage/innobase/include/fut0lst.ic line 85
InnoDB: Failing assertion: addr.page == FIL_NULL || addr.boffset >= FIL_PAGE_DATA
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
210310  0:36:42 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

Server version: 10.3.25-MariaDB-0ubuntu0.20.04.1
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=4
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467424 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f9560000c48
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f957affcd78 thread_stack 0x49000
/usr/sbin/mysqld(my_print_stacktrace+0x32)[0x55b19fee2c52]
/usr/sbin/mysqld(handle_fatal_signal+0x55d)[0x55b19f9e007d]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0)[0x7f95ad9e63c0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7f95ad4f518b]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x12b)[0x7f95ad4d4859]
/usr/sbin/mysqld(+0x4e7890)[0x55b19f700890]
/usr/sbin/mysqld(+0x4e4320)[0x55b19f6fd320]
/usr/sbin/mysqld(+0xa5b61d)[0x55b19fc7461d]
/usr/sbin/mysqld(+0xa5bfb0)[0x55b19fc74fb0]
/usr/sbin/mysqld(+0xa48d48)[0x55b19fc61d48]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x9609)[0x7f95ad9da609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7f95ad5d1293]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0): is an invalid pointer
Connection ID (thread ID): 2
Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on

The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
information that should help you find out what is causing the crash.

We think the query pointer is invalid, but we will try to print it anyway. 
Query: 

Writing a core file...
Working directory at /config/mysql
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             unlimited            unlimited            processes 
Max open files            1048576              1048576              files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       23440                23440                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport %p %s %c %d %P %E

root@399ac6fdf550:/# 

The docker container log looks like:

Building dependency tree...,
Reading state information...,
Calculating upgrade...,
The following packages have been kept back:,
  php-mysql php8.0-apcu,
0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded.,
Reading package lists...,
Building dependency tree...,
Reading state information...,
0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded.,
*** Running /etc/my_init.d/30_gen_ssl_keys.sh...,
using existing keys in "/config/keys",
*** Running /etc/my_init.d/40_firstrun.sh...,
Using existing conf folder,
File zm.conf already copied,
Error: Cannot download the ES server bundle,
File zmeventnotification.ini already moved,
File secrets.ini already moved,
File opencv.sh already moved,
File debug_opencv.sh already moved,
Event notification server already moved,
Pushover api already moved,
Using existing ssmtp folder,
Using existing mysql database folder,
Copy /config/control/ scripts to /usr/share/perl5/ZoneMinder/Control/,
Copy /config/conf/ scripts to /etc/zm/conf.d/,
Creating symbolink links,
usermod: no changes,
usermod: no changes,
usermod: no changes,
Using existing data directory for events,
Using existing data directory for images,
Using existing data directory for temp,
Using existing data directory for cache,
no crontab for root,
Starting services...,
 * Starting Apache httpd web server apache2,
 * ,
 * Starting MariaDB database server mysqld,
   ...fail!,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
Can't call method "prepare_cached" on an undefined value at /usr/share/perl5/ZoneMinder/Config.pm line 96.,
BEGIN failed--compilation aborted at /usr/share/perl5/ZoneMinder/Config.pm line 147.,
Compilation failed in require at /usr/bin/zmupdate.pl line 73.,
BEGIN failed--compilation aborted at /usr/bin/zmupdate.pl line 73.,
Mar 10 00:39:48 399ac6fdf550 zmupdate[1059]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
Mar 10 00:39:48 399ac6fdf550 zmupdate[1059]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
Mar 10 00:39:48 399ac6fdf550 zmupdate[1060]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
Can't call method "prepare_cached" on an undefined value at /usr/share/perl5/ZoneMinder/Config.pm line 96.,
BEGIN failed--compilation aborted at /usr/share/perl5/ZoneMinder/Config.pm line 147.,
Compilation failed in require at /usr/bin/zmupdate.pl line 73.,
BEGIN failed--compilation aborted at /usr/bin/zmupdate.pl line 73.,
Mar 10 00:39:48 399ac6fdf550 zmupdate[1060]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
Starting ZoneMinder:,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
Mar 10 00:39:48 399ac6fdf550 zmpkg[1070]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
DBI connect('database=zm;host=localhost','zmuser',...) failed: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) at /usr/share/perl5/ZoneMinder/Database.pm line 110.,
Can't call method "prepare_cached" on an undefined value at /usr/share/perl5/ZoneMinder/Config.pm line 96.,
BEGIN failed--compilation aborted at /usr/share/perl5/ZoneMinder/Config.pm line 147.,
Compilation failed in require at /usr/share/perl5/ZoneMinder.pm line 33.,
BEGIN failed--compilation aborted at /usr/share/perl5/ZoneMinder.pm line 33.,
Compilation failed in require at /usr/bin/zmpkg.pl line 34.,
BEGIN failed--compilation aborted at /usr/bin/zmpkg.pl line 34.,
Mar 10 00:39:48 399ac6fdf550 zmpkg[1070]: ERR [Error reconnecting to db: errstr:Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) error val:],
neMinder failed to start,
,
*** /etc/my_init.d/40_firstrun.sh failed with status 255,
,
*** Killing all processes...,
Mar 10 00:39:48 399ac6fdf550 syslog-ng[19]: syslog-ng shutting down; version='3.25.1',
*** Running /etc/my_init.d/00_regen_ssh_host_keys.sh...,
*** Running /etc/my_init.d/05_set_the_time.sh...,
*** Running /etc/my_init.d/06_set_php_time.sh...,
*** Running /etc/my_init.d/07_set_dri_permissions.sh...,
Granting permissions on /dev/dri/* devices...,
*** Running /etc/my_init.d/10_syslog-ng.init...,
[2021-03-10T00:39:49.812038] WARNING: With use-dns(no), dns-cache() will be forced to 'no' too!;,
Mar 10 00:39:49 399ac6fdf550 syslog-ng[19]: syslog-ng starting up; version='3.25.1',
*** Running /etc/my_init.d/20_apt_update.sh...,
Performing updates...,
Hit:1 http://archive.ubuntu.com/ubuntu focal InRelease,
Hit:2 http://ppa.launchpad.net/iconnor/zoneminder-1.34/ubuntu focal InRelease,
Hit:3 http://security.ubuntu.com/ubuntu focal-security InRelease,
Hit:4 http://archive.ubuntu.com/ubuntu focal-updates InRelease,
Hit:5 http://archive.ubuntu.com/ubuntu focal-backports InRelease,
Hit:6 http://ppa.launchpad.net/ondrej/php/ubuntu focal InRelease,
Reading package lists...,
Reading package lists...,
Building dependency tree...,
Reading state information...,
Calculating upgrade...,
The following packages have been kept back:,
  php-mysql php8.0-apcu,
0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded.,
Reading package lists...,
Building dependency tree...,
Reading state information...,
0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded.,
*** Running /etc/my_init.d/30_gen_ssl_keys.sh...,
using existing keys in "/config/keys",
*** Running /etc/my_init.d/40_firstrun.sh...,
Using existing conf folder,
File zm.conf already copied,
Error: Cannot download the ES server bundle,
File zmeventnotification.ini already moved,
File secrets.ini already moved,
File opencv.sh already moved,
File debug_opencv.sh already moved,
Event notification server already moved,
Pushover api already moved,
Using existing ssmtp folder,
Using existing mysql database folder,
Copy /config/control/ scripts to /usr/share/perl5/ZoneMinder/Control/,
Copy /config/conf/ scripts to /etc/zm/conf.d/,
Creating symbolink links,
usermod: no changes,
usermod: no changes,
usermod: no changes,
Using existing data directory for events,
Using existing data directory for images,
Using existing data directory for temp,
Using existing data directory for cache,
no crontab for root,
Starting services...,
 * Starting Apache httpd web server apache2,
 * ,
 * Starting MariaDB database server mysqld,

Any help would be greatly appreciated. If there's any other information i can provide, please let me know.

[meichthys]

To add a little to this, the first time the mysql error shows up in the log, it is preceded by the following. It appears that the issue happened after InnoDB created a new log file:

2021-03-08 10:20:18 0 [Note] InnoDB: Using Linux native AIO
2021-03-08 10:20:18 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-03-08 10:20:18 0 [Note] InnoDB: Uses event mutexes
2021-03-08 10:20:18 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2021-03-08 10:20:18 0 [Note] InnoDB: Number of pools: 1
2021-03-08 10:20:19 0 [Note] InnoDB: Using generic crc32 instructions
2021-03-08 10:20:19 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2021-03-08 10:20:19 0 [Note] InnoDB: Completed initialization of buffer pool
2021-03-08 10:20:19 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-03-08 10:20:19 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 50331648 bytes
2021-03-08 10:20:19 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 50331648 bytes
2021-03-08 10:20:23 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2021-03-08 10:20:23 0 [Note] InnoDB: New log files created, LSN=308713331
2021-03-08 10:20:24 0 [ERROR] InnoDB: Page [page id: space=0, page number=2] log sequence number 801972590 is in the future! Current system log sequence number 308713493.
2021-03-08 10:20:24 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.

[dlandon]

The docker you are using is deprecated and not supported.

[meichthys]

Ok @dlandon, Thanks! Is there a migration path to the new docker image? I'm currently using dlandon/zoneminder as shown in the docker-compose.yaml file on this repo.

Should I be using dlandon/zoneminder.machine.learning? If so, it doesn't seem to be available on docker hub 🤷‍♂️.

[dlandon]

I've updated the docker compose files. The zoneminder.machine.learning docker is Private and not available yet. We are trying to fund the further development of the machine learning docker. I refer you to the read me.