[MDEV-13689] [Draft] 10.1.10 : InnoDB: Failing assertion: addr.page == FIL_NULL || addr.boffset >= FIL_PAGE_DATA Created: 2017-08-31  Updated: 2023-12-19  Resolved: 2021-04-26

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.1.10, 10.2.7
Fix Version/s: N/A

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Cannot Reproduce Votes: 3
Labels: None

Attachments: File data.7z     File error.log     File error.log.1     File error.log.3     File etc_mysql.tar.gz    
Issue Links:
Relates
relates to MDEV-22341 Waiting for page_cleaner to finish fl... Closed

 Description   

IMPORTANT NOTE: This was observed on 10.1.10, while the current latest release is 10.1.26. Unless it also happens on recent versions, there is nothing to be done here – many things have changed since 10.1.10, so the problem might be long gone. However, I want to have it filed, to make it searchable in case it's ever encountered again, in an old or a new version.

10.1.10 non-debug build

2017-08-31 05:06:27 7f4c9012c7c0  InnoDB: Assertion failure in thread 139966811391936 in file fut0lst.ic line 83
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 http://bugs.mysql.com.
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: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
170831  5:06:27 [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 http://kb.askmonty.org/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.1.10-MariaDB-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467105 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0x0
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 0x48000
mysys/stacktrace.c:247(my_print_stacktrace)[0x564a9807542b]
sql/signal_handler.cc:160(handle_fatal_signal)[0x564a97bd6b05]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7f4c8f29a330]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f4c8e8edc37]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f4c8e8f1028]
include/mem0mem.ic:559(trx_undo_mem_create_at_db_start)[0x564a97e3d056]
trx/trx0rseg.cc:212(trx_rseg_mem_create)[0x564a97e2f6e3]
trx/trx0rseg.cc:289(trx_rseg_create_instance)[0x564a97e303b5]
trx/trx0sys.cc:660(trx_sys_init_at_db_start())[0x564a97e31986]
srv/srv0start.cc:2566(innobase_start_or_create_for_mysql())[0x564a97e17e8b]
handler/ha_innodb.cc:4157(innobase_init)[0x564a97d3d84d]
sql/handler.cc:513(ha_initialize_handlerton(st_plugin_int*))[0x564a97bd9068]
sql/sql_plugin.cc:1408(plugin_initialize)[0x564a97a7a0a5]
sql/sql_plugin.cc:1685(plugin_init(int*, char**, int))[0x564a97a7b052]
sql/mysqld.cc:5201(init_server_components)[0x564a979dbee2]
sql/mysqld.cc:5821(mysqld_main(int, char**))[0x564a979de90b]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7f4c8e8d8f45]
/home/travis/build/elenst/mariadb-tests/old/bin/mysqld(+0x3b7f9d)[0x564a979d2f9d]
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.
Writing a core file
Aborted (core dumped)

Preceding errors in the log:

BROKEN: block: 32281 checkpoint: 10 05106c5e c43ad2d4
BROKEN: block: 32281 checkpoint: 10 05106c5e c43ad2d4
InnoDB: Log block no 32281 at lsn 16527360 has
InnoDB: ok header, but checksum field contains 3292189396, should be 84962398
2017-08-31  5:06:27 139966811391936 [ERROR] InnoDB: We scanned the log up to 16527360. A checkpoint was at 16527379 and the maximum LSN on a database page was 0. It is possible that the database is now corrupt!
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 5 log sequence number 22754386
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 6 log sequence number 21943099
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 301 log sequence number 28609071
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 408 log sequence number 21943099
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 45 log sequence number 28076008
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 410 log sequence number 22390699
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 552 log sequence number 23370532
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 309 log sequence number 29211640
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 474 log sequence number 27011973
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 310 log sequence number 20727980
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 475 log sequence number 27275525
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 617 log sequence number 22748331
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 311 log sequence number 29211914
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 582 log sequence number 28703498
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 312 log sequence number 29188686
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 623 log sequence number 26119943
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 624 log sequence number 24769756
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 313 log sequence number 29230424
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 411 log sequence number 24256803
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 314 log sequence number 29212334
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 412 log sequence number 23935477
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 315 log sequence number 26220229
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 600 log sequence number 29681793
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 316 log sequence number 27796434
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 530 log sequence number 19294861
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-08-31 05:06:27 7f4c9012c7c0 InnoDB: Error: page 54 log sequence number 28035648
InnoDB: is in the future! Current system log sequence number 16527379.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.



 Comments   
Comment by TAO ZHOU [ 2017-10-23 ]

I am running 10.2.7 and now getting this same error.

Comment by Johnny Oskarsson [ 2020-02-09 ]

I just got this in 10.3.22 as well.

Also, how on earth is this a "Minor" bug? It crashes on startup for me, making MariaDB and all that depends on it (in my case: Nextcloud) completely unusable!

Any ideas on how to recover from this? I tried the InnoDB recovery modes without success.

Comment by Elena Stepanova [ 2020-02-09 ]

joskar, it was "Minor" on the reason explained at the very beginning of the description: it was only observed on very old versions and there was no indication it still existed. If you encountered it on 10.3.22, it will make a difference. Please attach the error log, stack traces from the coredump if you have it, and server config file(s). Thanks.

Comment by Elena Stepanova [ 2020-02-09 ]

marko, do you have any advice on "how to recover from it" part?

Comment by Johnny Oskarsson [ 2020-02-09 ]

I managed to recover from it just now, I finally got mysqld --innodb-force-recovery=5 working. I did a mysqldump --all-tables >mysql.backup, killed mysqld, removed everything in /var/lib/mysql, ran mysql_install_db and started mysqld anew and then did a mysql -u root <mysql.backup. Now it seems to work again, but I don't know if this was the best way to go about it.

But I was a bit worried when I did not get any recovery working, but this was mostly because I interpreted the "server system variable" in the recovery documentation as an environment variable.

Attached is an error log (of "one crash cycle"). The config files in /etc/mysql are the default Debian 10 configs, which are pretty much empty. Previously today I did some changes to the Nextcloud database (I was Enabling MySQL 4-byte support), in case that could be related.

error.log

Sorry about the tone in my previous post, my frustration levels has been a bit too high today.

Comment by Elena Stepanova [ 2020-02-09 ]

joskar, thanks. Yes, such problems are frustrating for us too, as there isn't much we can do when it happens once in two years and cannot be reproduced. Maybe marko will come up with some idea, though.

Meanwhile, do you happen to still have the error log from the very first such crash and, importantly, the previous server session before it? It might be important to see what happened there before the problems started, maybe there were errors or warnings (or even notes) which will shed some light on it.

Comment by Johnny Oskarsson [ 2020-02-12 ]

elenst, here are the logs I had on that day until the first assertion, which is to my knowledge the first such crash I have seen.

error.log.3

On that note, it is completely possible that my problems originates from malfunctioning hardware. Any help in narrowing this down would be appreciated.

Comment by Alice Sherepa [ 2020-11-03 ]

Server crashed as in MDEV-24096 and after that refused to restart (it started after--innodb_force_recovery=1 helps)
I attached datadir in data.7z - to reproduce: start mysqld with it.

10.5 44836bcd12e3974e79c928be74

2020-11-03 11:24:47 0 [ERROR] InnoDB: Not applying UNDO_APPEND due to corruption on [page id: space=0, page number=384]
2020-11-03 11:24:47 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
2020-11-03 11:24:47 0x7f165541c880  InnoDB: Assertion failure in file /10.5/src/storage/innobase/include/fut0lst.h line 127
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.
201103 11:24:47 [ERROR] mysqld got signal 6 ;
 
sigaction.c:0(__restore_rt)[0x7f16578553c0]
linux/raise.c:51(__GI_raise)[0x7f165734318b]
stdlib/abort.c:81(__GI_abort)[0x7f1657322859]
ut/ut0dbg.cc:60(_sub_D_00099_0)[0x55c4cf4e1e61]
include/fut0lst.h:128(flst_read_addr(unsigned char const*))[0x55c4cf102aa2]
include/fut0lst.h:142(flst_get_last(unsigned char const*))[0x55c4cf102bb2]
trx/trx0undo.cc:905(trx_undo_mem_create_at_db_start(trx_rseg_t*, unsigned long, unsigned int, unsigned long&))[0x55c4cf4dac41]
trx/trx0rseg.cc:433(trx_undo_lists_init(trx_rseg_t*, unsigned long&, buf_block_t const*))[0x55c4cf4a77a3]
trx/trx0rseg.cc:508(trx_rseg_mem_restore(trx_rseg_t*, unsigned long&, mtr_t*))[0x55c4cf4a7fa2]
trx/trx0rseg.cc:619(trx_rseg_array_init())[0x55c4cf4a8ed2]
trx/trx0trx.cc:743(trx_lists_init_at_db_start())[0x55c4cf4b6899]
srv/srv0start.cc:1479(srv_start(bool))[0x55c4cf409771]
handler/ha_innodb.cc:3939(innodb_init(void*))[0x55c4cef66a91]
sql/handler.cc:645(ha_initialize_handlerton(st_plugin_int*))[0x55c4ce116a97]
sql/sql_plugin.cc:1459(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x55c4cd9524c0]
sql/sql_plugin.cc:1751(plugin_init(int*, char**, int))[0x55c4cd95444e]
sql/mysqld.cc:4915(init_server_components())[0x55c4cd60f230]
sql/mysqld.cc:5496(mysqld_main(int, char**))[0x55c4cd61122f]
sql/main.cc:25(main)[0x55c4cd5fac2d]
csu/libc-start.c:342(__libc_start_main)[0x7f16573240b3]

Comment by Julian Rilli [ 2020-11-07 ]

Hey, the same thing happened to me yesterday (mariadb-server-10.3 10.3.25-0+deb10u1; Linux Debian 10; Nextcloud 18.0.10.2; PHP 7.3.23). But the repair didn't work, with `--innodb-force-recovery=5` the mysql service came up again, but then mysql tables were missing in the engine. Well, I finally deleted the data folder, recreated the mysql user and restored the backup from the day before.

Comment by Marko Mäkelä [ 2020-12-17 ]

alice, what is the history of data.7z? Was that data directory at any point touched by MariaDB 10.5.7? If yes, then the corruption could have been introduced by the bug that was fixed in MDEV-24096.

Comment by Alice Sherepa [ 2020-12-17 ]

marko, yes, data.7z is exactly the datadir after hitting bug from MDEV-24096, so it might be unrelated to the bug in the description, sorry for mixing it/

Comment by Marko Mäkelä [ 2021-04-26 ]

We have daily internal testing that involves killing and restarting the server, or running Mariabackup concurrently with a write workload, and restoring the data. If this type of errors would occur in any way regularly, we would detect it.

Two known sources of this type of problems are innodb_scrub_log (deprecated and ignored in MDEV-21870) and the scrubbing of InnoDB tables (reimplemented in MDEV-8139).

Bad things can also happen if the server is being run on an unreliable file system, such as some implementations of NFS. Also, in the case of a power outage, one may learn in the hard way that some storage devices are cheating with volatile caches or by reordering writes. The messages "log sequence number is in the future" basically mean that you have to treat all InnoDB data as seriously corrupted.

Generated at Thu Feb 08 08:07:35 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.