Page 1 of 1

InnoDB: Corruption of an index tree: table `zm`.`Logs` index `GEN_CLUST_INDEX'

Posted: Sun Jan 13, 2019 2:24 am
by SkippyDo
I had been streaming a camera for a while and then my database connection dropped out. ZM was still running. Can't recall if mysql was still running (I suspect not). Went to restart ZM thinking that that might wake it up, but it then failed to start. Traced it down to a problem with the database server. I'm no DB admin, so no clue as to how to proceed: I've rebooted the Debian [9] server in case there's a caching issue, but no resolution. Here's what I found in mysql error.log (had a ton of these entries):
TRANSACTION 12718105, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 42, OS thread handle 140112322582272, query id 799354 localhost zmuser Updating
DELETE FROM Logs
WHERE TimeKey < unix_timestamp(now() - interval 7 day) LIMIT 10

InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
2019-01-12 9:10:18 42 [ERROR] InnoDB: Clustered record for sec rec not found index `TimeKey` of table `zm`.`Logs`
InnoDB: sec index record PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 8; hex 812094f0670cd563; asc g c;;
1: len 6; hex 000000054530; asc E0;;

InnoDB: clust index record PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 696e66696d756d00; asc infimum ;;
I tried forcing an innodb recover and was able to start the DB server but it appears I've got a serious corruption. Following is, I think, where the problem is:
2019-01-12 14:41:49 1 [ERROR] InnoDB: Corruption of an index tree: table `zm`.`Logs` index `GEN_CLUST_INDEX`, father ptr page no 198, child page no 887
PHYSICAL RECORD: n_fields 12; compact format; info bits 0
0: len 6; hex 00000105cda0; asc ;;
1: len 6; hex 000000000000; asc ;;
2: len 7; hex 80000000000000; asc ;;
3: len 8; hex 8120966732047e4d; asc g2 ~M;;
4: len 6; hex 7a6d635f6d31; asc zmc_m1;;
5: len 4; hex 00000000; asc ;;
6: len 4; hex 80006b5a; asc kZ;;
7: len 1; hex 80; asc ;;
8: len 3; hex 494e46; asc INF;;
9: len 30; hex 44726976657761793a20696d616765733a333638313030202d2043617074; asc Driveway: images:368100 - Capt; (total 84 bytes);
10: len 14; hex 7a6d5f6d6f6e69746f722e637070; asc zm_monitor.cpp;;
11: len 2; hex 09ad; asc ;;
2019-01-12 14:41:49 1 [Note] InnoDB: n_owned: 0; heap_no: 9; next rec: 1251
PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 6; hex 000000092983; asc ) ;;
1: len 4; hex 000000c6; asc ;;
2019-01-12 14:41:49 1 [Note] InnoDB: n_owned: 0; heap_no: 170; next rec: 112
2019-01-12 14:41:49 1 [ERROR] [FATAL] InnoDB: You should dump + drop + reimport the table to fix the corruption. If the crash happens at database startup. Please refer to https://mariadb.com/kb/en/library/xtrad ... ery-modes/ for information about forcing recovery. Then dump + drop + reimport.
190112 14:41:49 [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.11-MariaDB-3
key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=30
max_threads=153
thread_count=29
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 352701 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f6e24000c08
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 = 0x7f6e39ffad58 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x559e65f6abae]
/usr/sbin/mysqld(handle_fatal_signal+0x505)[0x559e65adc8e5]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12670)[0x7f6e76456670]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x10b)[0x7f6e756c585b]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7f6e756b0535]
/usr/sbin/mysqld(+0x4bd681)[0x559e65829681]
/usr/sbin/mysqld(+0x4bde28)[0x559e65829e28]
/usr/sbin/mysqld(+0xa000c8)[0x559e65d6c0c8]
/usr/sbin/mysqld(+0xa0d029)[0x559e65d79029]
/usr/sbin/mysqld(+0xa0f868)[0x559e65d7b868]
/usr/sbin/mysqld(+0x9969ba)[0x559e65d029ba]
/usr/sbin/mysqld(+0x998961)[0x559e65d04961]
/usr/sbin/mysqld(+0x9993c5)[0x559e65d053c5]
/usr/sbin/mysqld(+0x95f110)[0x559e65ccb110]
/usr/sbin/mysqld(+0x9d0010)[0x559e65d3c010]
/usr/sbin/mysqld(+0x9bcdde)[0x559e65d28dde]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7f6e7644bfa3]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f6e7578789f]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0):
Connection ID (thread ID): 1
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 http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
2019-01-12 14:41:55 0 [Note] InnoDB: Using Linux native AIO
2019-01-12 14:41:55 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-01-12 14:41:55 0 [Note] InnoDB: Uses event mutexes
2019-01-12 14:41:55 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-01-12 14:41:55 0 [Note] InnoDB: Number of pools: 1
2019-01-12 14:41:55 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-01-12 14:41:55 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2019-01-12 14:41:55 0 [Note] InnoDB: Completed initialization of buffer pool
2019-01-12 14:41:55 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2019-01-12 14:41:55 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=404780237
2019-01-12 14:41:55 0 [Note] InnoDB: Starting final batch to recover 23 pages from redo log.
2019-01-12 14:41:57 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2019-01-12 14:41:57 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-01-12 14:41:57 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-01-12 14:41:57 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-01-12 14:41:57 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2019-01-12 14:41:57 0 [Note] InnoDB: Waiting for purge to start
2019-01-12 14:41:57 4 [ERROR] InnoDB: Corruption of an index tree: table `zm`.`Logs` index `GEN_CLUST_INDEX`, father ptr page no 198, child page no 887
PHYSICAL RECORD: n_fields 12; compact format; info bits 0
1: len 6; hex 000000000000; asc ;;
2: len 7; hex 80000000000000; asc ;;
3: len 8; hex 8120966732047e4d; asc g2 ~M;;
4: len 6; hex 7a6d635f6d31; asc zmc_m1;;
5: len 4; hex 00000000; asc ;;
6: len 4; hex 80006b5a; asc kZ;;
7: len 1; hex 80; asc ;;
8: len 3; hex 494e46; asc INF;;
9: len 30; hex 44726976657761793a20696d616765733a333638313030202d2043617074; asc Driveway: images:368100 - Capt; (total 84 bytes);
10: len 14; hex 7a6d5f6d6f6e69746f722e637070; asc zm_monitor.cpp;;
11: len 2; hex 09ad; asc ;;
2019-01-12 14:41:57 4 [Note] InnoDB: n_owned: 0; heap_no: 9; next rec: 1251
PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 6; hex 000000092983; asc ) ;;
1: len 4; hex 000000c6; asc ;;
2019-01-12 14:41:57 4 [Note] InnoDB: n_owned: 0; heap_no: 170; next rec: 112

1: len 6; hex 000000000000; asc ;;
2: len 7; hex 80000000000000; asc ;;
3: len 8; hex 8120966732047e4d; asc g2 ~M;;
4: len 6; hex 7a6d635f6d31; asc zmc_m1;;
5: len 4; hex 00000000; asc ;;
6: len 4; hex 80006b5a; asc kZ;;
7: len 1; hex 80; asc ;;
8: len 3; hex 494e46; asc INF;;
9: len 30; hex 44726976657761793a20696d616765733a333638313030202d2043617074; asc Driveway: images:368100 - Capt; (total 84 bytes);
10: len 14; hex 7a6d5f6d6f6e69746f722e637070; asc zm_monitor.cpp;;
11: len 2; hex 09ad; asc ;;
2019-01-12 14:41:57 4 [Note] InnoDB: n_owned: 0; heap_no: 9; next rec: 1251
PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 6; hex 000000092983; asc ) ;;
1: len 4; hex 000000c6; asc ;;
2019-01-12 14:41:57 4 [Note] InnoDB: n_owned: 0; heap_no: 170; next rec: 112
I have backups, in which case I should be spared having to reconfigure: don't care about any event data.

Just had major shoulder surgery (my dominate arm, of course!) and am fairly constrained.

This is a very vanilla installation (do have event hooks for yolo)

Also tried pulling in Debian updates and it looks like mariadb updates spewed an error. Ugh!

Re: InnoDB: Corruption of an index tree: table `zm`.`Logs` index `GEN_CLUST_INDEX'

Posted: Thu Jan 17, 2019 1:22 am
by SkippyDo
Not sure what was the source of all this, but I suspect it might have been due to running mariaDB 10.3 (had 10.3.11 running and after doing an update it tried pulling in version 10.3.12 after which the config and install would fail no matter what I did; so, I ended up installing mariaDB 10.1.37 and it appears to running properly [at least it would install!]).

Oh yeah, I also discovered that my OS version is now sid, so no wonder, I guess, that things were unstable (going to refrain from wholesales updates!)