[MDEV-19033] "InnoDB: We intentionally generate a memory trap." Created: 2019-03-23  Updated: 2019-03-25  Resolved: 2019-03-23

Status: Closed
Project: MariaDB Server
Component/s: Configuration
Affects Version/s: 10.1.38
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Jan Bludau Assignee: Unassigned
Resolution: Not a Bug Votes: 0
Labels: need_feedback
Environment:

CentOS



 Description   

mail:~# journalctl -u mariadb

Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: 200 kB * innodb_thread_concurrency.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: 2019-03-19 23:58:46 7f99c2959900 InnoDB: Assertion failure in thread 140298371307776 in file ha_innodb.cc line 22061
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: We intentionally generate a memory trap.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: If you get repeated assertion failures or crashes, even
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: immediately after the mysqld startup, there may be
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: corruption in the InnoDB tablespace. Please refer to
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: about forcing recovery.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: 190319 23:58:46 [ERROR] mysqld got signal 6 ;
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: This could be because you hit a bug. It is also possible that this binary
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: or one of the libraries it was linked against is corrupt, improperly built,
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: or misconfigured. This error can also be caused by malfunctioning hardware.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: We will try our best to scrape up some info that will hopefully help
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: diagnose the problem, but since we have already crashed,
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: something is definitely wrong and this may fail.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: Server version: 10.1.38-MariaDB
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: key_buffer_size=134217728
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: read_buffer_size=131072
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: max_used_connections=0
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: max_threads=3002
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: thread_count=0
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: It is possible that mysqld could use up to
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 25170006 K bytes of memory
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: Hope that's ok; if not, decrease some variables in the equation.
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: Thread pointer: 0x0
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: Attempting backtrace. You can use the following information to find out
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: where mysqld died. If you see no messages after this, something went
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: terribly wrong...
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: stack_bottom = 0x0 thread_stack 0x48400
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: mysys/stacktrace.c:268(my_print_stacktrace)[0x556e0fb6fb2e]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/signal_handler.cc:168(handle_fatal_signal)[0x556e0f692355]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sigaction.c:0(__restore_rt)[0x7f99c25475d0]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: :0(__GI_raise)[0x7f99c05e6207]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: :0(__GI_abort)[0x7f99c05e78f8]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: handler/ha_innodb.cc:22061(ib_logf(ib_log_level_t, char const*, ...))[0x556e0f8e04bf]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: log/log0log.cc:885(log_calc_max_ages)[0x556e0f91e6b7]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: srv/srv0start.cc:2489(innobase_start_or_create_for_mysql())[0x556e0f9c75c0]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: handler/ha_innodb.cc:4528(innobase_init(void*))[0x556e0f8e4a0d]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/handler.cc:522(ha_initialize_handlerton(st_plugin_int*))[0x556e0f694604]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/sql_plugin.cc:1409(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x556e0f519bb0]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/sql_plugin.cc:1686(plugin_init(int*, char**, int))[0x556e0f51b49a]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/mysqld.cc:5167(init_server_components())[0x556e0f470611]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: sql/mysqld.cc:5760(mysqld_main(int, char**))[0x556e0f4744c0]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f99c05d23d5]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: /usr/sbin/mysqld(+0x396b5d)[0x556e0f467b5d]
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: information that should help you find out what is causing the crash.
Mär 19 23:58:46 mail.bludau-media.de systemd[1]: mariadb.service: main process exited, code=killed, status=6/ABRT
Mär 19 23:58:46 mail.bludau-media.de systemd[1]: Failed to start MariaDB 10.1.38 database server.
Mär 19 23:58:46 mail.bludau-media.de systemd[1]: Unit mariadb.service entered failed state.
Mär 19 23:58:46 mail.bludau-media.de systemd[1]: mariadb.service failed.



 Comments   
Comment by Elena Stepanova [ 2019-03-23 ]

Please paste or attach your cnf file(s).

You skipped the first line of the error message, the full text is

[ERROR] InnoDB: The combined size of ib_logfiles should be bigger than
InnoDB: 200 kB * innodb_thread_concurrency.

Comment by Jan Bludau [ 2019-03-23 ]

i found the solution, but the error message is confusing....

Comment by Elena Stepanova [ 2019-03-23 ]

Which part of it is confusing?

Comment by Jan Bludau [ 2019-03-23 ]

thats the whole file, the essential part
??

  1. * Fine Tuning
    #
    key_buffer = 256M
    key_buffer_size = 1332M
    max_allowed_packet = 500M
  2. Bessere CPU-Auslastung mittels pool-of-threads statt one-thread-per-connection
    thread_handling = pool-of-threads
  3. Die soll MariaDB selbstständig auf die Anzahl der Cores einstellen
    thread_pool_size = 8
  4. Nach wie viel ms soll ein neuer Thread in einem Pool generiert werden, wenn der aktive Thread nicht fertig wird
    thread_pool_stall_limit = 20
  5. Wie viele Thread sind pro Pool sind möglich
    thread_pool_max_threads = 300
    thread_stack = 16K
    thread_cache_size = 30
  1. This replaces the startup script and checks MyISAM tables if needed
  2. the first time they are touched
    #myisam-recover = BACKUP
    max_connections = 3000
    max_user_connections = 500
    table_cache = 1024
    table_open_cache = 3072
    table_definition_cache = 4096

thread_cache = 8
thread_concurrency = 8

#

  1. * Query Cache Configuration
    #
    query_cache_limit = 16M
    query_cache_size = 0M
    query_cache_type = 0
    sort_buffer_size = 8M
    #read_rnd_buffer_size = 1M
  1. NEU
    innodb_flush_method=O_DIRECT
    #innodb_log_buffer_size=6M
    innodb_log_file_size=512M
    #innodb_thread_concurrency = 0
    innodb_flush_log_at_trx_commit = 2
    #innodb_read_io_threads=64
    #innodb_write_io_threads=64

query_cache_limit=256M
query_cache_size=300M
query_cache_type=0
#thread_cache = 8
#thread_concurrency = 32

tmp_table_size = 2048M
max_heap_table_size = 2048M
join_buffer_size = 10M

innodb_buffer_pool_size=25G
#innodb_additional_mem_pool_size = 20M

#innodb_log_file_size=3
innodb_log_buffer_size=8M
#innodb_file_per_table = ON
#transaction-isolation=READ-COMMITTED
#innodb_flush_log_at_trx_commit=1
#innodb_lock_wait_timeout = 300
#innodb_max_dirty_pages_pct = 90
#innodb_thread_concurrency=8
#innodb_flush_method=O_DIRECT
wait_timeout=60
interactive_timeout = 1080
#innodb_read_io_threads = 8
#innodb_write_io_threads = 8
innodb_buffer_pool_instances=8

??

Comment by Jan Bludau [ 2019-03-23 ]

this Part:

"Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: If you get repeated assertion failures or crashes, even
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: immediately after the mysqld startup, there may be
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: corruption in the InnoDB tablespace. Please refer to
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Mär 19 23:58:46 mail.bludau-media.de mysqld[1772]: InnoDB: about forcing recovery."

it makes me fearing because it's repeatable

Comment by Elena Stepanova [ 2019-03-23 ]

Well, users are supposed to read the whole message. If one reads only selected parts of it, it will be confusing no matter what. I think in your case the first reported error is perfectly clear:

[ERROR] InnoDB: The combined size of ib_logfiles should be bigger than
InnoDB: 200 kB * innodb_thread_concurrency.

Now, your config has many commented values so I'm not sure what was in force at the time when the problem occurred, but if it was innodb_log_file_size=3, it would certainly cause a problem.

Comment by Jan Bludau [ 2019-03-24 ]

do you patch this?

Comment by Marko Mäkelä [ 2019-03-25 ]

Horus Sirius, I have cleaned up the InnoDB startup and shutdown code in MySQL 5.7 and later in MariaDB Server 10.2 onwards.

In MariaDB 10.1, the parameter validation is crude. Even when InnoDB does not intentionally crash, it would not free all resources when it aborts startup, and the server could crash on shutdown. Back in 2016, I did not think that this is feasible to fix in the (already then) GA 10.1 or older versions. If you want a more pleasant experience of using InnoDB, you should upgrade to a newer MariaDB Server.

Comment by Jan Bludau [ 2019-03-25 ]

great job!

i'm CEO and SYS-ADMIN and DEVELOPER of bludau-media.de and shopste.com and also of tsecurity.de

All on the same Server

Never seen this error after changing configuration. I had panik!

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