[MDEV-33176] Assertion failure in /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.9 Created: 2024-01-04  Updated: 2024-01-09

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.5
Fix Version/s: None

Type: Bug Priority: Critical
Reporter: suhas Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-24035 Failing assertion: UT_LIST_GET_LEN(lo... Open

 Description   

The MariaDB service restarts every 10 minutes with the error:

InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.9/storage/innobase/trx/trx0trx.cc line 1346



 Comments   
Comment by suhas [ 2024-01-04 ]

The cnf details :

#
# This group is read both both by the client and the server
# use it for options that affect everything
#
[client-server]
 
#
# include all files from the config directory
#
!includedir /etc/my.cnf.d
 
[mysqld\]
max_allowed_packet=64M
 
 
[mariadb]
skip-grant-tables=false
local-infile=0
plugin-load-add=file_key_management.so
file_key_management
file_key_management_filename=/opt/sanovi/installconfig/mariadbencryption/keys.txt
innodb_default_encryption_key_id=1
skip_symbolic_links=yes
secure_file_priv=/var/lib/mysql
log-raw = OFF
slow_query_log_file=/var/log/mysqld_slow.log
server-id=1
master_info_repository=Table
allow-suspicious-udfs=false
socket=/var/lib/mysql/mysql.sock
log_bin_trust_function_creators=1
 
log_output=FILE
slow_query_log
slow_query_log_file=/var/log/mariadb/slow-queries.log
long_query_time=1.0
 
ssl
ssl-ca=/opt/sanovi/installconfig/mariadbencryption/ca-cert.pem
ssl-cert=/opt/sanovi/installconfig/mariadbencryption/server-cert.pem
ssl-key=/opt/sanovi/installconfig/mariadbencryption/server-key.pem
 
#include all files from the config directory #
!includedir /etc/my.cnf.d
[mysqld]
innodb_strict_mode=OFF
sql_mode="NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"
sql_mode="NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"
log-error=/var/lib/mysql/mysqld.log
log_warnings = 2
net_read_timeout=28890
net_write_timeout=28890
connect_timeout=28890
max_connections=1500
log-bin-trust-function-creators=1
wait_timeout=300
interactive_timeout=300
default_authentication_plugin=caching_sha2_password
 
plugin-load-add=simple_password_check.so
simple_password_check_digits=1
simple_password_check_letters_same_case=1
simple_password_check_minimal_length=14
simple_password_check_other_characters=1
#plugin-load=validate_password.so
#validate-password=FORCE_PLUS_PERMANENT
#validate_password_length=14
#validate_password_mixed_case_count=1
#validate_password_number_count=1
#validate_password_special_char_count=1
#validate_password_policy=MEDIUM
#log-bin-trust-function-creators=500
innodb_buffer_pool_size=32G
innodb_lock_wait_timeout=100

Comment by Alice Sherepa [ 2024-01-04 ]

Could you please add the full error log? And 10.5.9 is quite an old version, the current release is 10.5.23 - is it possible for you to upgrade and check if the error remains?

Comment by suhas [ 2024-01-04 ]

Hello Alice, thanks for checking on this. Please find the errorlog as below

2023-12-07 08:01:49 0x7f87e9e51700 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.9/storage/innobase/trx/trx0trx.cc line 1346

InnoDB: Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0

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.

231207 8:01: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.5.9-MariaDB-log

key_buffer_size=134217728

read_buffer_size=131072

max_used_connections=443

max_threads=1502

thread_count=305

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3437582 K bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f85780009b8

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 = 0x7f87e9e50c90 thread_stack 0x49000

??:0(my_print_stacktrace)[0x56146ddd47fe]

??:0(handle_fatal_signal)[0x56146d7d8a37]

sigaction.c:0(__restore_rt)[0x7f90a2c27630]

:0(__GI_raise)[0x7f90a0c80387]

:0(__GI_abort)[0x7f90a0c81a78]

/usr/sbin/mariadbd(+0x64bdd9)[0x56146d4b3dd9]

??:0(std::pair<std::_Rb_tree_iterator<unsigned int>, bool> std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_insert_unique<unsigned int const&>(unsigned int const&))[0x56146dc1b28a]

??:0(std::pair<std::_Rb_tree_iterator<unsigned int>, bool> std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_insert_unique<unsigned int const&>(unsigned int const&))[0x56146dc18f9e]

??:0(std::pair<std::_Rb_tree_iterator<unsigned int>, bool> std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_insert_unique<unsigned int const&>(unsigned int const&))[0x56146dc192e4]

??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x56146dabe7a4]

??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x56146dac7fb9]

??:0(handler::ha_external_lock(THD*, int))[0x56146d7e49b1]

??:0(CacheWriter::write(unsigned char*, unsigned long))[0x56146d8d81da]

??:0(mysql_unlock_read_tables(THD*, st_mysql_lock*))[0x56146d8d89f2]

??:0(JOIN::join_free())[0x56146d61a6a5]

??:0(JOIN::exec_inner())[0x56146d6356bc]

??:0(JOIN::exec())[0x56146d635973]

??:0(mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x56146d633b4e]

??:0(handle_select(THD*, LEX*, select_result*, unsigned long))[0x56146d634694]

/usr/sbin/mariadbd(+0x631909)[0x56146d499909]

??:0(mysql_execute_command(THD*))[0x56146d5da014]

??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x56146d5dcdb5]

??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x56146d5def6c]

??:0(do_command(THD*))[0x56146d5e037b]

??:0(do_handle_one_connection(CONNECT*, bool))[0x56146d6caac2]

??:0(handle_one_connection)[0x56146d6cad84]

??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x56146da2611d]

pthread_create.c:0(start_thread)[0x7f90a2c1fea5]

??:0(__clone)[0x7f90a0d48b0d]

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x7f8578022890): select i_id, i_objClass,i_raise_condition from incident where i_name='BCSMGR_RPORTO3' limit 1

Connection ID (thread ID): 1401

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=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off

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.

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 0 unlimited bytes

Max resident set unlimited unlimited bytes

Max processes 769961 769961 processes

Max open files 49152 49152 files

Max locked memory 65536 65536 bytes

Max address space unlimited unlimited bytes

Max file locks unlimited unlimited locks

Max pending signals 769961 769961 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/libexec/abrt-hook-ccpp %s %c %p %u %g %t e %P %I %h

2023-12-07 8:02:05 0 [Note] InnoDB: Uses event mutexes

2023-12-07 8:02:05 0 [Note] InnoDB: Compressed tables use zlib 1.2.7

2023-12-07 8:02:05 0 [Note] InnoDB: Number of pools: 1

2023-12-07 8:02:05 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

2023-12-07 8:02:05 0 [Note] InnoDB: Using Linux native AIO

2023-12-07 8:02:05 0 [Note] InnoDB: Initializing buffer pool, total size = 34359738368, chunk size = 134217728

2023-12-07 8:02:05 0 [Note] InnoDB: Completed initialization of buffer pool

2023-12-07 8:02:05 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2023-12-07 8:02:05 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=7830033122294,7830033882846

2023-12-07 8:02:06 0 [Note] InnoDB: Transaction 2963088389 was in the XA prepared state.

2023-12-07 8:02:06 0 [Note] InnoDB: Transaction 2963088396 was in the XA prepared state.

2023-12-07 8:02:06 0 [Note] InnoDB: 11 transaction(s) which must be rolled back or cleaned up in total 19 row operations to undo

2023-12-07 8:02:06 0 [Note] InnoDB: Trx id counter is 2963088397

2023-12-07 8:02:06 0 [Note] InnoDB: Starting final batch to recover 7257 pages from redo log.

2023-12-07 8:02:07 0 [Note] InnoDB: Last binlog file './panacesprimary_binlog.000220', position 613250860

2023-12-07 8:02:07 0 [Note] InnoDB: 128 rollback segments are active.

2023-12-07 8:02:07 0 [Note] InnoDB: Starting in background the rollback of recovered transactions

2023-12-07 8:02:07 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"

2023-12-07 8:02:07 0 [Note] InnoDB: Creating shared tablespace for temporary tables

2023-12-07 8:02:07 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2023-12-07 8:02:07 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2023-12-07 8:02:07 0 [Note] InnoDB: 10.5.9 started; log sequence number 7830100074265; transaction id 2963088398

2023-12-07 8:02:07 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool

2023-12-07 8:02:07 0 [Note] Plugin 'FEEDBACK' is disabled.

2023-12-07 8:02:07 0 [ERROR] mariadbd: Plugin 'simple_password_check' already installed

2023-12-07 8:02:07 0 [Warning] 'log-raw' is MySQL 5.6 / 5.7 compatible option. Not used or needed in MariaDB.

2023-12-07 8:02:07 0 [Warning] 'master-info-repository' is MySQL 5.6 / 5.7 compatible option. Not used or needed in MariaDB.

2023-12-07 8:02:07 0 [Warning] 'default-authentication-plugin' is MySQL 5.6 / 5.7 compatible option. To be implemented in later versions.

2023-12-07 8:02:07 0 [ERROR] mariadbd: File '/var/log/mariadb/slow-queries.log' not found (Errcode: 13 "Permission denied")

2023-12-07 8:02:07 0 [ERROR] Could not use /var/log/mariadb/slow-queries.log for logging (error 13). Turning logging off for the whole duration of the MariaDB server process. To turn it on again: fix the cause, shutdown the MariaDB server and restart it.

2023-12-07 8:02:07 0 [Note] Recovering after a crash using panacesprimary_binlog

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963088351

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963088392

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963083774

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963088331

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963088339

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963087507

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963081713

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963088393

2023-12-07 8:02:07 0 [Note] InnoDB: Rolled back recovered transaction 2963085389

2023-12-07 8:02:07 0 [Note] InnoDB: Rollback of non-prepared transactions completed

2023-12-07 8:02:07 0 [Note] Starting crash recovery...

2023-12-07 8:02:07 0 [Note] InnoDB: Starting recovery for XA transactions...

2023-12-07 8:02:07 0 [Note] InnoDB: Transaction 2963088389 in prepared state after recovery

2023-12-07 8:02:07 0 [Note] InnoDB: Transaction contains changes to 5 rows

2023-12-07 8:02:07 0 [Note] InnoDB: Transaction 2963088396 in prepared state after recovery

2023-12-07 8:02:07 0 [Note] InnoDB: Transaction contains changes to 1 rows

2023-12-07 8:02:07 0 [Note] InnoDB: 2 transactions in prepared state after recovery

2023-12-07 8:02:07 0 [Note] Found 2 prepared transaction(s) in InnoDB

2023-12-07 8:02:07 0 [Note] Crash recovery finished.

2023-12-07 8:02:07 0 [Warning] Failed to create a socket for IPv6 '::': errno: 97.

2023-12-07 8:02:07 0 [Note] Server socket created on IP: '0.0.0.0'.

2023-12-07 8:02:07 0 [Note] Reading of all Master_info entries succeeded

2023-12-07 8:02:07 0 [Note] Added new Master_info '' to hash table

2023-12-07 8:02:07 0 [Note] /usr/sbin/mariadbd: ready for connections.

Version: '10.5.9-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server

2023-12-07 8:02:25 0 [Note] InnoDB: Buffer pool(s) load completed at 231207 8:02:25

2023-12-07 8:02:59 245 [Warning] IP address 'x.x.x.x' could not be resolved: Name or service not known

2023-12-07 8:03:00 245 [Note] Start binlog_dump to slave_server(2), pos(panacesprimary_binlog.000220, 613251167), using_gtid(0), gtid('')

2023-12-07 8:07:12 41 [Warning] Aborted connection 41 to db: 'panaces' user: 'panaces' host: 'localhost' (Got timeout reading communication packets)
System Dashboard - Jira

Generated at Thu Feb 08 10:36:57 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.