[MDEV-24468] mariadb crashes when converting a large table to innodb Created: 2020-12-22  Updated: 2023-02-20  Resolved: 2023-02-20

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

Type: Bug Priority: Major
Reporter: Philip orleans Assignee: Marko Mäkelä
Resolution: Cannot Reproduce Votes: 2
Labels: None
Environment:

Linux

Attachments: Zip Archive mariadb.zip     Zip Archive mariadb1.zip    
Issue Links:
Duplicate
duplicates MDEV-24375 Semaphore wait has lasted > 600 seconds Closed

 Description    

[ 5623.361638] mariadbd[3596]: segfault at fffffffffffffffd ip 000055a847115d2b sp 00007f3b75630570 error 5 in mariadbd[55a846472000+158c000]
 
[ 5623.361650] Code: 87 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 41 57 41 56 41 55 41 54 49 89 f4 53 48 89 fb 48 83 ec 28 48 8b 76 18 <0f> b6 47 fd f6 46 40 01 74 23 83 e0 07 3c 04 0f 87 cd 06 00 00 48

I have table like this:

CREATE TABLE `shortxxx` (
 
  `zzz` bigint(20) unsigned NOT NULL,
 
  `xxx` int(11) unsigned DEFAULT NULL,
 
  PRIMARY KEY (`zzz`),
 
  KEY `IDX_shortxxx_xxx` (`xxx`)
 
) ENGINE=ROCKSDB DEFAULT CHARSET=latin1 AVG_ROW_LENGTH=12 ROW_FORMAT=FIXED

it has 600 M rows.
I issue an alter table shortxxx engine=innodb
and it crashes after an hour.
Before that I tried to insert the data (813MM rows) into a new innodb table, and it crashed many times loading.
The box has 256 GB

innodb_adaptive_flushing = 1
 
innodb_adaptive_hash_index=1
 
innodb_buffer_pool_dump_at_shutdown=OFF
 
innodb_buffer_pool_load_at_startup=OFF
 
innodb_buffer_pool_size=20G
 
innodb_compression_algorithm=zlib
 
innodb_compression_level=6
 
innodb_doublewrite=0
 
innodb_file_per_table=1
 
innodb_flush_log_at_timeout=10
 
innodb_flush_log_at_trx_commit=0
 
innodb_flush_method=O_DIRECT_NO_FSYNC
 
innodb_flush_neighbors = 0
 
innodb_force_recovery=0
 
innodb_io_capacity=5000
 
innodb_io_capacity_max=10000
 
innodb_log_buffer_size=64M
 
innodb_lru_scan_depth=1024
 
innodb_max_dirty_pages_pct=90
 
innodb_open_files=4000
 
innodb_page_size=4096
 
innodb_purge_threads=4
 
innodb_read_io_threads = 64
 
innodb_stats_persistent = 1
 
innodb_strict_mode=0
 
innodb_thread_concurrency=0
 
innodb_use_atomic_writes=1
 
innodb_use_native_aio=1
 
innodb_write_io_threads = 64
 
 
 
connect_timeout=200
 
datadir=/var/lib/mysql
 
default-storage-engine = rocksdb
 
event_scheduler = 1
 
extra_max_connections=10
 
extra_port=9433
 
general-log-file=queries.log
 
general-log=0
 
general_log_file=mariadb.log
 
interactive_timeout=3000000
 
join_buffer_size=256K
 
join_buffer_size=8M
 
large_pages=1
 
log-output=file
 
log_error=/var/lib/mysql/mariadb.err
 
log_output='FILE'
 
log_warnings= 0
 
lower_case_table_names=1
 
max_allowed-packet=1G
 
max_connections=5000
 
max_heap_table_size=72M
 
memlock=1
 
net_read_timeout=2000
 
net_write_timeout=2000
 
open_files_limit=65535
 
plugin-load-add=ha_rocksdb.so
 
plugin_load_add = ha_blackhole
 
port =3306 
query_cache_size=0
 
query_cache_type=0
 
skip-innodb=0
 
skip_name_resolve=1
 
slave_load_tmpdir=/data/temp
 
slave_net_timeout=3600
 
socket=/var/lib/mysql/mysql.sock
 
sort_buffer_size=256K
 
sort_buffer_size=8M
 
symbolic_links=0
 
table_open_cache=3000
 
table_open_cache_instances=24
 
thread-pool-size=32
 
thread_cache_size=256
 
thread_handling=pool-of-threads
 
thread_stack=192K
 
tmp_table_size=64M
 
tmpdir=/large/temp
 
wait_timeout=6000
 
 
 
rocksdb-table-stats-sampling-pct=15
 
rocksdb_allow_concurrent_memtable_write=1
 
rocksdb_blind_delete_primary_key=1
 
rocksdb_block_cache_size=25G
 
rocksdb_block_size=16384
 
rocksdb_bulk_load_allow_unsorted=1
 
rocksdb_bulk_load_size=10000
 
rocksdb_bytes_per_sync=16777216
 
rocksdb_commit_in_the_middle=1
 
rocksdb_compaction_readahead_size=16m
 
rocksdb_compaction_sequential_deletes=199999
 
rocksdb_compaction_sequential_deletes_count_sd=1
 
rocksdb_compaction_sequential_deletes_window=200000
 
rocksdb_default_cf_options=write_buffer_size=256m;target_file_size_base=64m;max_bytes_for_level_base=512m;level0_file_num_compaction_trigger=4;level0_slowdown_writes_trigger=256;level0_stop_writes_trigger=256;max_write_buffer_number=16;compression_per_level=kNoCompression:kNoCompression:kNoCompression:kZlibCompression:kZlibCompression:kZlibCompression;bottommost_compression=kZlibCompression;compression_opts=-14:1:0;block_based_table_factory={cache_index_and_filter_blocks=1;filter_policy=bloomfilter:10:false;whole_key_filtering=1};level_compaction_dynamic_level_bytes=true;optimize_filters_for_hits=true
 
rocksdb_enable_ttl=1
 
rocksdb_flush_log_at_trx_commit=2
 
rocksdb_max_background_jobs=24
 
rocksdb_max_open_files=-1
 
rocksdb_max_row_locks=1073741824
 
rocksdb_max_subcompactions=16
 
rocksdb_max_total_wal_size=14G
 
rocksdb_strict_collation_check=off
 
rocksdb_table_cache_numshardbits=19
 
rocksdb_tmpdir=/data/temp
 
rocksdb_use_direct_io_for_flush_and_compaction=ON
 
rocksdb_use_direct_reads=OFF
 
rocksdb_wal_bytes_per_sync=4194304
 
rocksdb_write_disable_wal=1



 Comments   
Comment by Alice Sherepa [ 2020-12-22 ]

Could you please provide the error.log?

Comment by Philip orleans [ 2020-12-22 ]

I attached the file.
Also I can do the same again if you give me instructions to set up a version with symbols, etc.
It will blow up again

Comment by Alice Sherepa [ 2020-12-22 ]

from the error log:

2020-12-22  5:59:15 120 [ERROR] InnoDB: preallocating 26554138624 bytes for file ./lrn/#sql-alter-3b0-78.ibd failed with error 28
 
2020-12-22  5:59:15 120 [ERROR] InnoDB: preallocating 26554138624 bytes for file ./lrn/#sql-alter-3b0-78.ibd failed with error 28
 
2020-12-22  5:59:15 120 [ERROR] InnoDB: preallocating 26554138624 bytes for file ./lrn/#sql-alter-3b0-78.ibd failed with error 28
 
2020-12-22  5:59:15 120 [ERROR] InnoDB: preallocating 26554138624 bytes for file ./lrn/#sql-alter-3b0-78.ibd failed with error 28
 
201222  5:59:15 [ERROR] mysqld got signal 11 ;
 
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.8-MariaDB-1:10.5.8+maria~bionic
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=84
 
max_threads=65546
 
thread_count=85
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 25427982 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f34cc0197b8
 
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 = 0x7f3b75636cb8 thread_stack 0x30000
 
??:0(my_print_stacktrace)[0x55a84736d25e]
 
??:0(handle_fatal_signal)[0x55a846d7b715]
 
??:0(__restore_rt)[0x7f3c05399980]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x55a847115d2b]
 
??:0(std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_erase(std::_Rb_tree_node<unsigned int>*))[0x55a8471ffbf3]
 
??:0(std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_erase(std::_Rb_tree_node<unsigned int>*))[0x55a8471edc05]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x55a84712fb5f]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x55a847133fa7]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x55a847134a9c]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x55a847147824]
 
??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55a847080409]
 
??:0(handler::ha_write_row(unsigned char const*))[0x55a846d878cf]
 
/usr/sbin/mariadbd(+0x5f656f)[0x55a846a6856f]
 
??:0(mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool))[0x55a846c15a2b]
 
??:0(Sql_cmd_alter_table::execute(THD*))[0x55a846c706d1]
 
??:0(mysql_execute_command(THD*))[0x55a846b7a439]
 
??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55a846b8109c]
 
??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55a846b762f5]
 
??:0(do_command(THD*))[0x55a846b74614]
 
??:0(tp_callback(TP_connection*))[0x55a846cfde3f]
 
??:0(get_event(worker_thread_t*, thread_group_t*, timespec*))[0x55a846f07aa0]
 
??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x55a846fbbada]
 
??:0(start_thread)[0x7f3c0538e6db]
 
??:0(clone)[0x7f3c0478c71f]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f34cc02d050): alter table shortlrn engine=innodb

InnoDB returned errors "failed with error 28" which means no space left on device

Comment by Philip orleans [ 2020-12-23 ]

I doubled the space and doubled the memory, then I did this
create table table engine=innodb as select * from table_original;
And it crashed after few hours
I am uploading the log.

I measured the hard dis performance and it is very good
Writing Speed
2048+0 records in
2048+0 records out
2147483648 bytes (2.1 GB, 2.0 GiB) copied, 4.1901 s, 513 MB/s
Reading Speed without Cache
2048+0 records in
2048+0 records out
2147483648 bytes (2.1 GB, 2.0 GiB) copied, 3.55175 s, 605 MB/s
Reading Cached Speed
2048+0 records in
2048+0 records out
2147483648 bytes (2.1 GB, 2.0 GiB) copied, 0.769342 s, 2.8 GB/s

also, my fstab shows that for 60 seconds we keep changes in RAM

UUID=f0064792-ae71-11ea-a045-005056ab3905 / ext4 noatime,relatime,barrier=0,commit=60,defaults 0 0
/swap.img none swap sw 0 0

What I mean to show is that hardware is fine. This is a problem with innodb.
Can somebody show me how to capture a full trace?

Comment by Alice Sherepa [ 2020-12-23 ]

This looks similar to the MDEV-24375, where it is said to be fixed in 10.5.9 (unreleased). 10.5.5 is claimed to be unaffected, but I did not tried it by myself.

2020-12-23  9:23:53 0 [Note] InnoDB: A semaphore wait:
 
--Thread 140638436468480 has waited at btr0cur.cc line 148 0for 611.00 seconds the semaphore:
 
SX-lock on RW-latch at 0x7fe110036100 created in file dict0dict.cc line 2161
 
a writer (thread id 140604587624192) has reserved it in mode  SX
 
number of readers 0, waiters flag 1, lock_word: 10000000
 
Last time write locked in file dict0stats.cc line 1969
 
InnoDB: ###### Starts InnoDB Monitor for 30 secs to print diagnostic info:
 
InnoDB: Pending reads 1, writes 0
 
InnoDB: ###### Diagnostic info printed to the standard error stream
 
2020-12-23  9:23:53 0 [ERROR] [FATAL] InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.
 
201223  9:23:53 [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.8-MariaDB-1:10.5.8+maria~bionic
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=52
 
max_threads=65546
 
thread_count=53
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 25302259 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 0x30000
 
??:0(my_print_stacktrace)[0x5647b8aa825e]
 
??:0(handle_fatal_signal)[0x5647b84b6715]
 
??:0(__restore_rt)[0x7fe908d0a980]
 
??:0(gsignal)[0x7fe90801afb7]
 
??:0(abort)[0x7fe90801c921]
 
??:0(std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_erase(std::_Rb_tree_node<unsigned int>*))[0x5647b890d9d1]
 
??:0(std::unique_lock<std::mutex>::unlock())[0x5647b88b7589]
 
??:0(tpool::thread_pool_generic::timer_generic::execute(void*))[0x5647b8a2f685]
 
??:0(tpool::task::execute())[0x5647b8a305bc]
 
??:0(tpool::thread_pool_generic::worker_main(tpool::worker_data*))[0x5647b8a2f0ef]
 
??:0(std::error_code::default_error_condition() const)[0x7fe9088286df]
 
??:0(start_thread)[0x7fe908cff6db]
 
??:0(clone)[0x7fe9080fd71f]

https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/

gdb --batch --eval-command="thread apply all bt" <path to mysqld> <path to core file>

Comment by Philip orleans [ 2020-12-24 ]

I installed the version in
http://hasky.askmonty.org/archive/10.5/build-37001/kvm-deb-focal-amd64/debs/binary/
and it works, I converted the table just fine
I had to dist-upgrade my ubuntu version to focal, because bionic did no have the version of libc required, so the packages in
http://hasky.askmonty.org/archive/10.5/build-37001/kvm-deb-bionic-amd64/debs/binary/
would not install. So you cannot release the version called bionic because of this issue.
Thanks for helping me overcome this roadblock.

Comment by Sergei Golubchik [ 2021-01-28 ]

I've just tried to install packages from http://hasky.askmonty.org/archive/10.5/build-37564/kvm-deb-bionic-amd64/debs/binary/ on a clean bionic VM image, it installed successfully. It depends on libc6 (>= 2.27) and bionic has 2.27 (https://packages.ubuntu.com/bionic/libc6).

What did you see? What libc did you have, what libc did mariadb packages require, and what error did you see?
Just asking, in case you still have this information, I suspect you no longer do.

Generated at Thu Feb 08 09:30:13 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.