Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
11.4.1
-
None
Description
While experimenting with Data-at-rest and the HashiCorp Vault key management plugin, trying to add a new key version I by accident deleted one hex letter, issuing
vault kv put /test/1 data="0123456789ABCDEF0123456789ABCDB"
|
instead of the intended
vault kv put /test/1 data="0123456789ABCDEF0123456789ABCDEB"
|
Note the missing / additional E near the end of the key string.
The vault command succeeded just fine, but the mariadb server almost immediately with
2024-04-24 13:05:52 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-24 13:05:52 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-24 13:05:52 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-24 13:05:52 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-24 13:05:52 0x7f7f027fc700 InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-11.4.1/storage/innoba>
|
InnoDB: Failing assertion: key_version != ENCRYPTION_KEY_VERSION_INVALID
|
I'm seeing multiple problems here:
- IMHO the server should not crash upon seeing a new key version that it can't process
- The error message should mention the key ID and version for easier debugging
- "extra character in the key data" is a bit misleading as I actually missed a character, but I assume that's just telling that a single character is not a valid hex sequence and that it considers that as invalid addition after 31 valid two-character pairs?
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
2024-04-30 22:15:03 0 [Note] /usr/sbin/mariadbd: ready for connections.
|
Version: '11.4.1-MariaDB-1:11.4.1+maria~ubu2004-log' socket: '/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution
|
Started MariaDB 11.4.1 database server.
|
2024-04-30 22:36:35 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-30 22:36:35 0x7f5fe2dff700 InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-11.4.1/storage/innobase/fil/fil0crypt.cc line 521
|
InnoDB: Failing assertion: key_version != ENCRYPTION_KEY_VERSION_INVALID
|
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 mariadbd 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.
|
240430 22:36:35 [ERROR] mysqld got signal 6 ;
|
Sorry, we probably made a mistake, and this is a bug.
|
Your assistance in bug reporting will enable us to fix this for the next release.
|
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: 11.4.1-MariaDB-1:11.4.1+maria~ubu2004-log source revision: fa69b085b10f19a3a8b6e7adab27c104924333ae
|
key_buffer_size=134217728
|
read_buffer_size=131072
|
max_used_connections=2
|
max_threads=153
|
thread_count=1
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 468064 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
Thread pointer: 0x0
|
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 = 0x0 thread_stack 0x49000
|
addr2line: DWARF error: section .debug_info is larger than its filesize! (0xccb4c7e vs 0x7f306d0)
|
/usr/sbin/mariadbd(my_print_stacktrace+0x32)[0x558ca859ce72]
|
/usr/sbin/mariadbd(handle_fatal_signal+0x475)[0x558ca806ff05]
|
sigaction.c:0(__restore_rt)[0x7f600b588420]
|
addr2line: DWARF error: section .debug_info is larger than its filesize! (0x93f189 vs 0x530f70)
|
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7f600b08c00b]
|
/lib/x86_64-linux-gnu/libc.so.6(abort+0x12b)[0x7f600b06b859]
|
addr2line: DWARF error: section .debug_info is larger than its filesize! (0xccb4c7e vs 0x7f306d0)
|
/usr/sbin/mariadbd(+0x6d62a7)[0x558ca7c732a7]
|
/usr/sbin/mariadbd(+0x6e6ee1)[0x558ca7c83ee1]
|
/usr/sbin/mariadbd(+0xf3b9f1)[0x558ca84d89f1]
|
/usr/sbin/mariadbd(+0xefdf56)[0x558ca849af56]
|
/usr/sbin/mariadbd(+0xeff394)[0x558ca849c394]
|
/usr/sbin/mariadbd(+0xeff8f7)[0x558ca849c8f7]
|
/usr/sbin/mariadbd(+0xf01a80)[0x558ca849ea80]
|
/usr/sbin/mariadbd(+0xf030aa)[0x558ca84a00aa]
|
/lib/x86_64-linux-gnu/libstdc++.so.6(+0xd6df4)[0x7f600b462df4]
|
nptl/pthread_create.c:478(start_thread)[0x7f600b57c609]
|
addr2line: DWARF error: section .debug_info is larger than its filesize! (0x93f189 vs 0x530f70)
|
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7f600b168353]
|
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mariadbd/ contains
|
information that should help you find out what is causing the crash.
|
Writing a core file...
|
Working directory at /var/lib/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 15540 15540 processes
|
Max open files 32768 32768 files
|
Max locked memory 65536 65536 bytes
|
Max address space unlimited unlimited bytes
|
Max file locks unlimited unlimited locks
|
Max pending signals 15540 15540 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: core
|
Kernel version: Linux version 5.4.0-164-generic (buildd@bos03-amd64-056) (gcc version 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04.2)) #181-Ubuntu SMP Fri Sep 1 13:41:22 UTC 2023
|
mariadb.service: Main process exited, code=killed, status=6/ABRT
|
mariadb.service: Failed with result 'signal'.
|
mariadb.service: Scheduled restart job, restart counter is at 1.
|
Stopped MariaDB 11.4.1 database server.
|
Not sure why the backtrace has no symbolds resolved, I have dbgsym packages installed for mariadb-server-core, mariadb-server and mariadb-plugin-hashicorp-key.management. Platform is Debian 12. GDB backtrace further down below can use the dbgsym info just fine. Ever since we changed to addr2line for this odd things seem to happen ... but that's a different story.
On restart things fail right away then during InnoDB initialization due to the invalid key:
Starting MariaDB 11.4.1 database server...
|
2024-04-30 22:36:41 0 [Note] Starting MariaDB 11.4.1-MariaDB-1:11.4.1+maria~ubu2004-log source revision fa69b085b10f19a3a8b6e7adab27c104924333ae as process 4336
|
2024-04-30 22:36:41 0 [Warning] No argument was provided to --log-bin and neither --log-basename or --log-bin-index where used; This may cause repliction to break when this server acts as a master and has its hostname changed! Please use '--log-basename=ubuntu-focal' or '--log-bin=mysqld-bin' to avoid this problem.
|
2024-04-30 22:36:41 0 [ERROR] mariadbd: hashicorp: Syntax error - extra character in the key data
|
2024-04-30 22:36:41 0 [ERROR] InnoDB: cannot enable encryption, encryption plugin is not available
|
2024-04-30 22:36:41 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
|
2024-04-30 22:36:41 0 [Note] Plugin 'FEEDBACK' is disabled.
|
2024-04-30 22:36:41 0 [Note] Plugin 'wsrep-provider' is disabled.
|
2024-04-30 22:36:41 0 [Note] Using encryption key id 2 for temporary files
|
2024-04-30 22:36:41 0 [ERROR] Unknown/unsupported storage engine: InnoDB
|
2024-04-30 22:36:41 0 [ERROR] Aborting
|
mariadb.service: Main process exited, code=exited, status=1/FAILURE
|
GDB backtrace
(gdb) bt
|
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
|
#1 0x0000558ca859cc4f in my_write_core (sig=sig@entry=6) at ./mysys/stacktrace.c:424
|
#2 0x0000558ca806ff20 in handle_fatal_signal (sig=6) at ./sql/signal_handler.cc:357
|
#3 <signal handler called>
|
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
|
#5 0x00007f600b06b859 in __GI_abort () at abort.c:79
|
#6 0x0000558ca7c732a7 in ut_dbg_assertion_failed (expr=expr@entry=0x558ca885bdb0 "key_version != ENCRYPTION_KEY_VERSION_INVALID", file=file@entry=0x558ca885bd60 "/home/buildbot/buildbot/build/mariadb-11.4.1/storage/innobase/fil/fil0crypt.cc",
|
line=line@entry=521) at ./storage/innobase/ut/ut0dbg.cc:60
|
#7 0x0000558ca7c83ee1 in fil_encrypt_buf_for_full_crc32 (dst_frame=0x7f5fa8010000 "", src_frame=0x7f5fe790c000 <error: Cannot access memory at address 0x7f5fe790c000>, lsn=<optimized out>, offset=<optimized out>, space=<optimized out>,
|
crypt_data=0x7f5f90081308) at ./storage/innobase/fil/fil0crypt.cc:521
|
#8 fil_encrypt_buf (crypt_data=0x7f5f90081308, space=<optimized out>, offset=<optimized out>, src_frame=0x7f5fe790c000 <error: Cannot access memory at address 0x7f5fe790c000>, zip_size=<optimized out>, dst_frame=0x7f5fa8010000 "",
|
use_full_checksum=<optimized out>) at ./storage/innobase/fil/fil0crypt.cc:568
|
#9 0x0000558ca84d89f1 in fil_space_encrypt (space=space@entry=0x7f5f900813f8, offset=<optimized out>, src_frame=src_frame@entry=0x7f5fe790c000 <error: Cannot access memory at address 0x7f5fe790c000>, dst_frame=<optimized out>)
|
at ./storage/innobase/include/fil0fil.h:701
|
#10 0x0000558ca849af56 in buf_page_encrypt (space=0x7f5f900813f8, bpage=<optimized out>, s=0x7f5fe790c000 <error: Cannot access memory at address 0x7f5fe790c000>, slot=0x7f5fe2dfeb58, size=0x7f5fe2dfeb50) at ./storage/innobase/buf/buf0flu.cc:637
|
#11 0x0000558ca849c394 in buf_page_t::flush (this=0x7f5fe78028a0, evict=<optimized out>, space=0x7f5f900813f8) at ./storage/innobase/buf/buf0flu.cc:851
|
#12 0x0000558ca849c8f7 in buf_flush_try_neighbors (space=<optimized out>, page_id=..., bpage=0x0, contiguous=<optimized out>, evict=<optimized out>, n_flushed=<optimized out>, n_to_flush=<optimized out>) at ./storage/innobase/buf/buf0flu.cc:1121
|
#13 0x0000558ca849ea80 in buf_do_flush_list_batch (lsn=<optimized out>, max_n=<optimized out>) at ./storage/innobase/buf/buf0flu.cc:1517
|
#14 buf_flush_list_holding_mutex (lsn=<optimized out>, max_n=<optimized out>) at ./storage/innobase/buf/buf0flu.cc:1590
|
#15 buf_flush_list_holding_mutex (max_n=<optimized out>, lsn=<optimized out>) at ./storage/innobase/buf/buf0flu.cc:1571
|
#16 0x0000558ca84a00aa in buf_flush_page_cleaner () at ./storage/innobase/buf/buf0flu.cc:2635
|
#17 0x00007f600b462df4 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
|
#18 0x00007f600b57c609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#19 0x00007f600b168353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
There are two different issues here. Unhelpful error message from the hashicorp plugin and InnoDB crash.
As this MDEV has stack traces for the crash, let's keep it about InnoDB. Please, create another issue to about unhelpful error reporting in the hashicorp plugin.
Can someone provide precise steps for reproducing this bug? It is not clear to me how to set up Hashicorp based encryption in a development environment.
Judging from buildbot logs, e.g. https://buildbot.mariadb.net/buildbot/builders/kvm-fulltest/builds/51010/steps/mtr-hashicorp/logs/stdio, you need to run hashicorp-setup.sh script from https://github.com/MariaDB/mariadb.org-tools/blob/master/buildbot/steps/hashicorp-setup.sh
Could you please paste more context?
Characters beyond Assertion failure in file /home/buildbot/buildbot/build/mariadb-11.4.1/storage/innoba>
and lines below InnoDB: Failing assertion: key_version != ENCRYPTION_KEY_VERSION_INVALID.