Details
-
Bug
-
Status: Closed (View Workflow)
-
Blocker
-
Resolution: Fixed
-
10.2.9
-
None
-
Ubuntu 16.04 LTS
Description
Upgraded our internal cluster (3 nodes) to 10.2.9 (from 10.1) one day ago and this morning we found that all 3 nodes crashed at the same time. Below is a relevant log entries from one of the nodes. Please let me know if I can help with any additional information.
Oct 6 08:44:36 masha3 mysqld[7310]: 171006 8:44:36 [ERROR] mysqld got signal 11 ;
|
Oct 6 08:44:36 masha3 mysqld[7310]: This could be because you hit a bug. It is also possible that this binary
|
Oct 6 08:44:36 masha3 mysqld[7310]: or one of the libraries it was linked against is corrupt, improperly built,
|
Oct 6 08:44:36 masha3 mysqld[7310]: or misconfigured. This error can also be caused by malfunctioning hardware.
|
Oct 6 08:44:36 masha3 mysqld[7310]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
Oct 6 08:44:36 masha3 mysqld[7310]: We will try our best to scrape up some info that will hopefully help
|
Oct 6 08:44:36 masha3 mysqld[7310]: diagnose the problem, but since we have already crashed,
|
Oct 6 08:44:36 masha3 mysqld[7310]: something is definitely wrong and this may fail.
|
Oct 6 08:44:36 masha3 mysqld[7310]: Server version: 10.2.9-MariaDB-10.2.9+maria~xenial-log
|
Oct 6 08:44:36 masha3 mysqld[7310]: key_buffer_size=134217728
|
Oct 6 08:44:36 masha3 mysqld[7310]: read_buffer_size=2097152
|
Oct 6 08:44:36 masha3 mysqld[7310]: max_used_connections=88
|
Oct 6 08:44:36 masha3 mysqld[7310]: max_threads=202
|
Oct 6 08:44:36 masha3 mysqld[7310]: thread_count=112
|
Oct 6 08:44:36 masha3 mysqld[7310]: It is possible that mysqld could use up to
|
Oct 6 08:44:36 masha3 mysqld[7310]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1376413 K bytes of memory
|
Oct 6 08:44:36 masha3 mysqld[7310]: Hope that's ok; if not, decrease some variables in the equation.
|
Oct 6 08:44:36 masha3 mysqld[7310]: Thread pointer: 0x7ff3040009a8
|
Oct 6 08:44:36 masha3 mysqld[7310]: Attempting backtrace. You can use the following information to find out
|
Oct 6 08:44:36 masha3 mysqld[7310]: where mysqld died. If you see no messages after this, something went
|
Oct 6 08:44:36 masha3 mysqld[7310]: terribly wrong...
|
Oct 6 08:44:36 masha3 mysqld[7310]: stack_bottom = 0x7ff78c3de918 thread_stack 0x49000
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55b3d95957ee]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(handle_fatal_signal+0x305)[0x55b3d902e535]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7ff7ba9ef390]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(+0x402e75)[0x55b3d8ddbe75]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(+0x8bc26f)[0x55b3d929526f]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2b1a)[0x55b3d8f1cb7a]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x5f4)[0x55b3d8f67c94]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x14e7)[0x55b3d8e924f7]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x28a)[0x55b3d8e9a09a]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(_ZN15Query_log_event14do_apply_eventEP14rpl_group_infoPKcj+0x825)[0x55b3d910fab5]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(wsrep_apply_cb+0x5b2)[0x55b3d8fd4c62]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZNK6galera9TrxHandle5applyEPvPF15wsrep_cb_statusS1_PKvmjPK14wsrep_trx_metaERS6_+0x106)[0x7ff7afd23316]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(+0x22e1bf)[0x7ff7afd731bf]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM9apply_trxEPvPNS_9TrxHandleE+0xbe)[0x7ff7afd75d7e]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM11process_trxEPvPNS_9TrxHandleE+0x13e)[0x7ff7afd7867e]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZN6galera15GcsActionSource8dispatchEPvRK10gcs_actionRb+0x1d8)[0x7ff7afd4f848]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZN6galera15GcsActionSource7processEPvRb+0x76)[0x7ff7afd51596]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM10async_recvEPv+0x83)[0x7ff7afd78d63]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/lib/galera/libgalera_smm.so(galera_recv+0x2b)[0x7ff7afd92ddb]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(+0x5fce54)[0x55b3d8fd5e54]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /usr/sbin/mysqld(start_wsrep_THD+0x455)[0x55b3d8fc5355]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7ff7ba9e56ba]
|
Oct 6 08:44:36 masha3 mysqld[7310]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ff7ba0903dd]
|
Oct 6 08:44:36 masha3 mysqld[7310]: Trying to get some variables.
|
Oct 6 08:44:36 masha3 mysqld[7310]: Some pointers may be invalid and cause the dump to abort.
|
Oct 6 08:44:36 masha3 mysqld[7310]: Query (0x7ff3040963fe): ALTER TABLE `AttendDet` DROP COLUMN IF EXISTS `Counter`
|
Oct 6 08:44:36 masha3 mysqld[7310]: Connection ID (thread ID): 18
|
Oct 6 08:44:36 masha3 mysqld[7310]: Status: NOT_KILLED
|
Oct 6 08:44:36 masha3 mysqld[7310]: 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=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
|
Oct 6 08:44:36 masha3 mysqld[7310]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
Oct 6 08:44:36 masha3 mysqld[7310]: information that should help you find out what is causing the crash.
|
Oct 6 08:44:36 masha3 systemd[1]: mariadb.service: Main process exited, code=killed, status=11/SEGV
|
Oct 6 08:44:36 masha3 systemd[1]: mariadb.service: Unit entered failed state.
|
Oct 6 08:44:36 masha3 systemd[1]: mariadb.service: Failed with result 'signal'.
|
Oct 6 08:44:41 masha3 systemd[1]: mariadb.service: Service hold-off time over, scheduling restart.
|
Oct 6 08:44:41 masha3 systemd[1]: Stopped MariaDB database server.
|
Attachments
Issue Links
- blocks
-
-
- Closed
-
- relates to
-
-
- Closed
-
Activity
This our test servers, so databases are constantly being restored, dropped and altered. The database in question has already been dropped and recreated, but as far as I can tell from my investigation, the table schema just before the crash probably looked like this:
CREATE TABLE `AttendDet` ( |
`EmplCode` smallint(6) DEFAULT NULL, |
`Comments` longtext DEFAULT NULL, |
`EmplName` varchar(30) DEFAULT NULL, |
`AttendCode` smallint(6) DEFAULT NULL, |
`SearchDate` smallint(6) DEFAULT NULL, |
`CreatedBy` varchar(12) DEFAULT NULL, |
`ActClockInTime` char(5) DEFAULT NULL, |
`ActClockOutTime` char(5) DEFAULT NULL, |
`AdjClockInTime` char(5) DEFAULT NULL, |
`AdjClockOutTime` char(5) DEFAULT NULL, |
`ActClockInDate` char(8) DEFAULT NULL, |
`ActClockOutDate` char(8) DEFAULT NULL, |
`AdjClockInDate` char(8) DEFAULT NULL, |
`AdjClockOutDate` char(8) DEFAULT NULL, |
`TotActTime` double DEFAULT NULL, |
`TotAdjTime` double DEFAULT NULL, |
`PayRateCode` smallint(6) DEFAULT NULL, |
`PayrollRate` double DEFAULT NULL, |
`Shift` smallint(6) DEFAULT NULL, |
`OverTime` char(1) DEFAULT NULL, |
`Holiday` char(1) DEFAULT NULL, |
`GLAcct` varchar(12) DEFAULT NULL, |
`OTCalcFlag` char(1) DEFAULT NULL, |
`DeviceNo` smallint(6) DEFAULT NULL, |
`AttendDet_ID` int(11) NOT NULL AUTO_INCREMENT, |
`TicketDate` date DEFAULT NULL, |
`Counter` int(11) DEFAULT NULL, |
`LastModDate` datetime DEFAULT NULL, |
`LastModUser` varchar(12) CHARACTER SET utf8 DEFAULT NULL, |
PRIMARY KEY (`AttendDet_ID`), |
KEY `IX_AttendDet_EmplCode_TicketDate` (`EmplCode`,`TicketDate`), |
KEY `IX_AttendDet_EmplCode` (`EmplCode`), |
KEY `IX_AttendDet_AttendCode` (`AttendCode`), |
KEY `IX_AttendDet_CreatedBy` (`CreatedBy`), |
KEY `IX_AttendDet_ActClockInTime` (`ActClockInTime`), |
KEY `IX_AttendDet_EmplCode_Holiday_SearchDate` (`EmplCode`,`Holiday`,`SearchDate`), |
KEY `IX_AttendDet_SearchDate` (`SearchDate`), |
KEY `IX_AttendDet_EmplCode_Holiday` (`EmplCode`,`Holiday`), |
KEY `IX_AttendDet_EmplCode_SearchDate` (`EmplCode`,`SearchDate`), |
KEY `IX_AttendDet_EmplCode_OTCalcFlag` (`EmplCode`,`OTCalcFlag`), |
KEY `IX_AttendDet_Shift` (`Shift`), |
KEY `IX_AttendDet_EmplCode_ActClockOutTime_AttendCode` (`EmplCode`,`ActClockOutTime`,`AttendCode`), |
KEY `IX_AttendDet_EmplCode_ActClockOutTime` (`EmplCode`,`ActClockOutTime`) |
) ENGINE=InnoDB AUTO_INCREMENT=527 DEFAULT CHARSET=utf8mb4 ROW_FORMAT=DYNAMIC |
The log from the node that received the ALTER TABLE statement is:
Oct 6 08:44:36 masha1 mysqld[5005]: 171006 8:44:36 [ERROR] mysqld got signal 11 ;
|
Oct 6 08:44:36 masha1 mysqld[5005]: This could be because you hit a bug. It is also possible that this binary
|
Oct 6 08:44:36 masha1 mysqld[5005]: or one of the libraries it was linked against is corrupt, improperly built,
|
Oct 6 08:44:36 masha1 mysqld[5005]: or misconfigured. This error can also be caused by malfunctioning hardware.
|
Oct 6 08:44:36 masha1 mysqld[5005]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
Oct 6 08:44:36 masha1 mysqld[5005]: We will try our best to scrape up some info that will hopefully help
|
Oct 6 08:44:36 masha1 mysqld[5005]: diagnose the problem, but since we have already crashed,
|
Oct 6 08:44:36 masha1 mysqld[5005]: something is definitely wrong and this may fail.
|
Oct 6 08:44:36 masha1 mysqld[5005]: Server version: 10.2.9-MariaDB-10.2.9+maria~xenial-log
|
Oct 6 08:44:36 masha1 mysqld[5005]: key_buffer_size=134217728
|
Oct 6 08:44:36 masha1 mysqld[5005]: read_buffer_size=2097152
|
Oct 6 08:44:36 masha1 mysqld[5005]: max_used_connections=106
|
Oct 6 08:44:36 masha1 mysqld[5005]: max_threads=202
|
Oct 6 08:44:36 masha1 mysqld[5005]: thread_count=130
|
Oct 6 08:44:36 masha1 mysqld[5005]: It is possible that mysqld could use up to
|
Oct 6 08:44:36 masha1 mysqld[5005]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1376413 K bytes of memory
|
Oct 6 08:44:36 masha1 mysqld[5005]: Hope that's ok; if not, decrease some variables in the equation.
|
Oct 6 08:44:36 masha1 mysqld[5005]: Thread pointer: 0x7f7f245b3e28
|
Oct 6 08:44:36 masha1 mysqld[5005]: Attempting backtrace. You can use the following information to find out
|
Oct 6 08:44:36 masha1 mysqld[5005]: where mysqld died. If you see no messages after this, something went
|
Oct 6 08:44:36 masha1 mysqld[5005]: terribly wrong...
|
Oct 6 08:44:36 masha1 mysqld[5005]: stack_bottom = 0x7f7fa1531cf8 thread_stack 0x49000
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x5636568fe7ee]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(handle_fatal_signal+0x305)[0x563656397535]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f83d7c6a390]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(+0x402e75)[0x563656144e75]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(+0x8bc26f)[0x5636565fe26f]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2b1a)[0x563656285b7a]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x5f4)[0x5636562d0c94]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x14e7)[0x5636561fb4f7]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x28a)[0x56365620309a]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(+0x4c18cf)[0x5636562038cf]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1079)[0x563656204f99]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z10do_commandP3THD+0x13c)[0x56365620671c]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x24a)[0x5636562cde3a]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x5636562cdfad]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f83d7c606ba]
|
Oct 6 08:44:36 masha1 mysqld[5005]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f83d730b3dd]
|
Oct 6 08:44:36 masha1 mysqld[5005]: Trying to get some variables.
|
Oct 6 08:44:36 masha1 mysqld[5005]: Some pointers may be invalid and cause the dump to abort.
|
Oct 6 08:44:36 masha1 mysqld[5005]: Query (0x7f7f245a56f0): ALTER TABLE `AttendDet` DROP COLUMN IF EXISTS `Counter`
|
Oct 6 08:44:36 masha1 mysqld[5005]: Connection ID (thread ID): 92972
|
Oct 6 08:44:36 masha1 mysqld[5005]: Status: NOT_KILLED
|
Oct 6 08:44:36 masha1 mysqld[5005]: 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=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
|
Oct 6 08:44:36 masha1 mysqld[5005]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
Oct 6 08:44:36 masha1 mysqld[5005]: information that should help you find out what is causing the crash.
|
Oct 6 08:45:01 masha1 CRON[19066]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
|
Oct 6 08:54:56 masha1 systemd[1]: mariadb.service: Main process exited, code=killed, status=11/SEGV
|
Oct 6 08:54:56 masha1 systemd[1]: mariadb.service: Unit entered failed state.
|
Oct 6 08:54:56 masha1 systemd[1]: mariadb.service: Failed with result 'signal'.
|
Oct 6 08:55:01 masha1 systemd[1]: mariadb.service: Service hold-off time over, scheduling restart.
|
Oct 6 08:55:01 masha1 systemd[1]: Stopped MariaDB database server.
|
And my.cnf from that node is:
# MariaDB database server configuration file.
|
#
|
# You can copy this file to one of:
|
# - "/etc/mysql/my.cnf" to set global options,
|
# - "~/.my.cnf" to set user-specific options.
|
#
|
# One can use all long options that the program supports.
|
# Run program with --help to get a list of available options and with
|
# --print-defaults to see which it would actually understand and use.
|
#
|
# For explanations see
|
# http://dev.mysql.com/doc/mysql/en/server-system-variables.html
|
|
|
# This will be passed to all mysql clients
|
# It has been reported that passwords should be enclosed with ticks/quotes
|
# escpecially if they contain "#" chars...
|
# Remember to edit /etc/mysql/debian.cnf when changing the socket location.
|
[client]
|
port = 3306
|
socket = /var/run/mysqld/mysqld.sock
|
|
|
# Here is entries for some specific programs
|
# The following values assume you have at least 32M ram
|
|
|
# This was formally known as [safe_mysqld]. Both versions are currently parsed.
|
[mysqld_safe]
|
socket = /var/run/mysqld/mysqld.sock
|
nice = 0
|
|
|
[mysqld]
|
#
|
# * Basic Settings
|
#
|
user = mysql
|
pid-file = /var/run/mysqld/mysqld.pid
|
socket = /var/run/mysqld/mysqld.sock
|
port = 3306
|
basedir = /usr
|
datadir = /var/lib/mysql
|
tmpdir = /tmp
|
lc_messages_dir = /usr/share/mysql
|
lc_messages = en_US
|
skip-external-locking
|
#
|
# Instead of skip-networking the default is now to listen only on
|
# localhost which is more compatible and is not less secure.
|
# KV: bind to all addresses
|
# bind-address = 127.0.0.1
|
#
|
# * Fine Tuning
|
#
|
max_connections = 200
|
connect_timeout = 5
|
wait_timeout = 600
|
max_allowed_packet = 16M
|
thread_cache_size = 128
|
sort_buffer_size = 4M
|
bulk_insert_buffer_size = 16M
|
tmp_table_size = 32M
|
max_heap_table_size = 32M
|
#
|
# * MyISAM
|
#
|
# This replaces the startup script and checks MyISAM tables if needed
|
# the first time they are touched. On error, make copy and try a repair.
|
myisam_recover_options = BACKUP
|
key_buffer_size = 128M
|
#open-files-limit = 2000
|
table_open_cache = 400
|
myisam_sort_buffer_size = 512M
|
concurrent_insert = 2
|
read_buffer_size = 2M
|
read_rnd_buffer_size = 1M
|
#
|
# * Query Cache Configuration
|
#
|
# Cache only tiny result sets, so we can fit more in the query cache.
|
query_cache_limit = 128K
|
query_cache_size = 64M
|
# for more write intensive setups, set to DEMAND or OFF
|
#query_cache_type = DEMAND
|
#
|
# * Logging and Replication
|
#
|
# Both location gets rotated by the cronjob.
|
# Be aware that this log type is a performance killer.
|
# As of 5.1 you can enable the log at runtime!
|
#general_log_file = /var/log/mysql/mysql.log
|
#general_log = 1
|
#
|
# Error logging goes to syslog due to /etc/mysql/conf.d/mysqld_safe_syslog.cnf.
|
#
|
# we do want to know about network errors and such
|
log_warnings = 2
|
#
|
# Enable the slow query log to see queries with especially long duration
|
#slow_query_log[={0|1}]
|
slow_query_log_file = /var/log/mysql/mariadb-slow.log
|
long_query_time = 10
|
#log_slow_rate_limit = 1000
|
log_slow_verbosity = query_plan
|
|
|
#log-queries-not-using-indexes
|
#log_slow_admin_statements
|
#
|
# The following can be used as easy to replay backup logs or for replication.
|
# note: if you are setting up a replication slave, see README.Debian about
|
# other settings you may need to change.
|
server-id = 1
|
#report_host = master1
|
#auto_increment_increment = 2
|
#auto_increment_offset = 1
|
log_bin = /var/log/mysql/mariadb-bin
|
log_bin_index = /var/log/mysql/mariadb-bin.index
|
# not fab for performance, but safer
|
#sync_binlog = 1
|
expire_logs_days = 10
|
max_binlog_size = 100M
|
# slaves
|
#relay_log = /var/log/mysql/relay-bin
|
#relay_log_index = /var/log/mysql/relay-bin.index
|
#relay_log_info_file = /var/log/mysql/relay-bin.info
|
log_slave_updates
|
#read_only
|
#
|
# If applications support it, this stricter sql_mode prevents some
|
# mistakes like inserting invalid dates etc.
|
#sql_mode = NO_ENGINE_SUBSTITUTION,TRADITIONAL
|
#
|
# * InnoDB
|
#
|
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
|
# Read the manual for more InnoDB related options. There are many!
|
default_storage_engine = InnoDB
|
# you can't just change log file size, requires special procedure
|
#innodb_log_file_size = 50M
|
innodb_buffer_pool_size = 15G
|
innodb_log_buffer_size = 8M
|
innodb_file_per_table = 1
|
innodb_open_files = 400
|
innodb_io_capacity = 400
|
innodb_flush_method = O_DIRECT
|
innodb_large_prefix = 1
|
innodb_file_format = 'Barracuda'
|
innodb_strict_mode = 1
|
|
|
#
|
# * Security Features
|
#
|
# Read the manual, too, if you want chroot!
|
# chroot = /var/lib/mysql/
|
#
|
# For generating SSL certificates I recommend the OpenSSL GUI "tinyca".
|
#
|
# ssl-ca=/etc/mysql/cacert.pem
|
# ssl-cert=/etc/mysql/server-cert.pem
|
# ssl-key=/etc/mysql/server-key.pem
|
|
|
#
|
# * Galera-related settings
|
#
|
[galera]
|
# Mandatory settings
|
#wsrep_on=ON
|
#wsrep_provider=
|
#wsrep_cluster_address=
|
#binlog_format=row
|
#default_storage_engine=InnoDB
|
#innodb_autoinc_lock_mode=2
|
#
|
# Allow server to accept connections on all interfaces.
|
#
|
#bind-address=0.0.0.0
|
#
|
# Optional setting
|
#wsrep_slave_threads=1
|
#innodb_flush_log_at_trx_commit=0
|
|
|
[mysqldump]
|
quick
|
quote-names
|
max_allowed_packet = 16M
|
|
|
[mysql]
|
#no-auto-rehash # faster start of mysql but no tab completion
|
|
|
[isamchk]
|
key_buffer = 16M
|
|
|
#
|
# * IMPORTANT: Additional settings that can override those from this file!
|
# The files must end with '.cnf', otherwise they'll be ignored.
|
#
|
!includedir /etc/mysql/conf.d/
|
Thank you.
Just went down again on the same statement. However, we run these updates all the time and sometimes they work fine. Any workaround you can recommend will be very helpful for we have a lot of people relying on these servers being up. Here is the log from just now:
Oct 6 13:21:38 masha1 mysqld[21903]: 171006 13:21:38 [ERROR] mysqld got signal 11 ;
|
Oct 6 13:21:38 masha1 mysqld[21903]: This could be because you hit a bug. It is also possible that this binary
|
Oct 6 13:21:38 masha1 mysqld[21903]: or one of the libraries it was linked against is corrupt, improperly built,
|
Oct 6 13:21:38 masha1 mysqld[21903]: or misconfigured. This error can also be caused by malfunctioning hardware.
|
Oct 6 13:21:38 masha1 mysqld[21903]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
Oct 6 13:21:38 masha1 mysqld[21903]: We will try our best to scrape up some info that will hopefully help
|
Oct 6 13:21:38 masha1 mysqld[21903]: diagnose the problem, but since we have already crashed,
|
Oct 6 13:21:38 masha1 mysqld[21903]: something is definitely wrong and this may fail.
|
Oct 6 13:21:38 masha1 mysqld[21903]: Server version: 10.2.9-MariaDB-10.2.9+maria~xenial-log
|
Oct 6 13:21:38 masha1 mysqld[21903]: key_buffer_size=134217728
|
Oct 6 13:21:38 masha1 mysqld[21903]: read_buffer_size=2097152
|
Oct 6 13:21:38 masha1 mysqld[21903]: max_used_connections=103
|
Oct 6 13:21:38 masha1 mysqld[21903]: max_threads=202
|
Oct 6 13:21:38 masha1 mysqld[21903]: thread_count=127
|
Oct 6 13:21:38 masha1 mysqld[21903]: It is possible that mysqld could use up to
|
Oct 6 13:21:38 masha1 mysqld[21903]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1376413 K bytes of memory
|
Oct 6 13:21:38 masha1 mysqld[21903]: Hope that's ok; if not, decrease some variables in the equation.
|
Oct 6 13:21:38 masha1 mysqld[21903]: Thread pointer: 0x7f52a40c3ef8
|
Oct 6 13:21:38 masha1 mysqld[21903]: Attempting backtrace. You can use the following information to find out
|
Oct 6 13:21:38 masha1 mysqld[21903]: where mysqld died. If you see no messages after this, something went
|
Oct 6 13:21:38 masha1 mysqld[21903]: terribly wrong...
|
Oct 6 13:21:38 masha1 mysqld[21903]: stack_bottom = 0x7f52c81becf8 thread_stack 0x49000
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x561d4ae7f7ee]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(handle_fatal_signal+0x305)[0x561d4a918535]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f57227b7390]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(+0x402e75)[0x561d4a6c5e75]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(+0x8bc26f)[0x561d4ab7f26f]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2b1a)[0x561d4a806b7a]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x5f4)[0x561d4a851c94]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x14e7)[0x561d4a77c4f7]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x28a)[0x561d4a78409a]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(+0x4c18cf)[0x561d4a7848cf]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1079)[0x561d4a785f99]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z10do_commandP3THD+0x13c)[0x561d4a78771c]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x24a)[0x561d4a84ee3a]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x561d4a84efad]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f57227ad6ba]
|
Oct 6 13:21:39 masha1 mysqld[21903]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f5721e583dd]
|
Oct 6 13:21:39 masha1 mysqld[21903]: Trying to get some variables.
|
Oct 6 13:21:39 masha1 mysqld[21903]: Some pointers may be invalid and cause the dump to abort.
|
Oct 6 13:21:39 masha1 mysqld[21903]: Query (0x7f52a40d4cb0): ALTER TABLE `AttendDet` DROP COLUMN IF EXISTS `Counter`
|
Oct 6 13:21:39 masha1 mysqld[21903]: Connection ID (thread ID): 7254
|
Oct 6 13:21:39 masha1 mysqld[21903]: Status: NOT_KILLED
|
Oct 6 13:21:39 masha1 mysqld[21903]: 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=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
|
Oct 6 13:21:39 masha1 mysqld[21903]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
Oct 6 13:21:39 masha1 mysqld[21903]: information that should help you find out what is causing the crash.
|
Oct 6 13:21:39 masha1 systemd[1]: mariadb.service: Main process exited, code=dumped, status=11/SEGV
|
Oct 6 13:21:39 masha1 systemd[1]: mariadb.service: Unit entered failed state.
|
Oct 6 13:21:39 masha1 systemd[1]: mariadb.service: Failed with result 'core-dump'.
|
Oct 6 13:21:44 masha1 systemd[1]: mariadb.service: Service hold-off time over, scheduling restart.
|
Oct 6 13:21:44 masha1 systemd[1]: Stopped MariaDB database server.
|
We will try to reproduce it locally, but if it's a test server, could you maybe install dbgsym packages, configure the server to produce a coredump and acquire all threads' stack trace from it – or, better still, if possible, do the same with a debug binary?
Here are some instructions:
https://mariadb.com/kb/en/library/how-to-produce-a-full-stack-trace-for-mysqld/
I installed debug symbols and enabled coredump and through some experimentation was able to cause the crash. Here is what I think is happening:
1. In MariaDB 10.1 our databases had tables that for historical reasons (don't ask) had "Counter" columns that were defined as VIRTUAL pointing at AUTO_INCREMENT columns like "xxx_ID".
2. 10.2 disallows having virtual columns that point to auto_increment columns.
3. We upgraded to 10.2.
4. We made changes to our app to drop virtual columns that point to auto_increments.
5. When we execute ALTER TABLE xxx DROP COLUMN `virtualColumn`; server crashes.
Backtrace from one such a crash is attached to the ticket.
Any ideas on how we can get rid of these columns without crashing all the nodes?
Thank you.
Thank you for the information, I was able to reproduce the problem as you described.
Any ideas on how we can get rid of these columns without crashing all the nodes?
Are there many such tables, and is creating a full database dump feasible?
So far I could only find one way that seems to be working – create a schema dump, manually remove GENERATED ALWAYS AS (`AttendDet_ID`) VIRTUAL part from the definition, purge the old datadir and re-initialize the database from the dump. I realize that it's not a great workaround, and will see if I can find a better one. Hopefully the bug will be fixed in the upcoming 10.2.10 release.
Sorry for the inconvenience.
The simplest test case is:
|
On 10.1 |
CREATE TABLE t (pk INT AUTO_INCREMENT PRIMARY KEY, v INT AS (pk) VIRTUAL) ENGINE=InnoDB; |
INSERT INTO t () VALUES (),(); |
|
On 10.2 |
ALTER TABLE t DROP COLUMN v; |
Crashes on debug and non-debug builds.
|
Debug 387bdf07ae0973 |
#3 <signal handler called>
|
#4 0x000055bd69cc129c in prepare_inplace_drop_virtual (ha_alter_info=0x7fceec09f660, altered_table=0x7fce84031c40, table=0x7fce8401bf40) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:3817
|
#5 0x000055bd69cc6d6e in ha_innobase::prepare_inplace_alter_table (this=0x7fce8401cb48, altered_table=0x7fce84031c40, ha_alter_info=0x7fceec09f660) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:6115
|
#6 0x000055bd699832f3 in handler::ha_prepare_inplace_alter_table (this=0x7fce8401cb48, altered_table=0x7fce84031c40, ha_alter_info=0x7fceec09f660) at /data/src/10.2/sql/handler.cc:4208
|
#7 0x000055bd697d892b in mysql_inplace_alter_table (thd=0x7fce84000b00, table_list=0x7fce840110f0, table=0x7fce8401bf40, altered_table=0x7fce84031c40, ha_alter_info=0x7fceec09f660, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7fceec09f6d0, alter_ctx=0x7fceec0a0290) at /data/src/10.2/sql/sql_table.cc:7298
|
#8 0x000055bd697dddfe in mysql_alter_table (thd=0x7fce84000b00, new_db=0x7fce84011700 "test", new_name=0x0, create_info=0x7fceec0a0ea0, table_list=0x7fce840110f0, alter_info=0x7fceec0a0df0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9323
|
#9 0x000055bd69856c26 in Sql_cmd_alter_table::execute (this=0x7fce84011730, thd=0x7fce84000b00) at /data/src/10.2/sql/sql_alter.cc:324
|
#10 0x000055bd6971386c in mysql_execute_command (thd=0x7fce84000b00) at /data/src/10.2/sql/sql_parse.cc:6203
|
#11 0x000055bd6971811c in mysql_parse (thd=0x7fce84000b00, rawbuf=0x7fce84011008 "ALTER TABLE t DROP COLUMN v", length=27, parser_state=0x7fceec0a2250, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7875
|
#12 0x000055bd69705dc0 in dispatch_command (command=COM_QUERY, thd=0x7fce84000b00, packet=0x7fce84008791 "ALTER TABLE t DROP COLUMN v", packet_length=27, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
|
#13 0x000055bd69704736 in do_command (thd=0x7fce84000b00) at /data/src/10.2/sql/sql_parse.cc:1360
|
#14 0x000055bd69851917 in do_handle_one_connection (connect=0x55bd6dbf75d0) at /data/src/10.2/sql/sql_connect.cc:1354
|
#15 0x000055bd698516a4 in handle_one_connection (arg=0x55bd6dbf75d0) at /data/src/10.2/sql/sql_connect.cc:1260
|
#16 0x00007fcef1680494 in start_thread (arg=0x7fceec0a3700) at pthread_create.c:333
|
#17 0x00007fceef7f893f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
A datadir with pre-created table t is attached as data1.tar.gz
.
With a more complicated table, like in the original report, debug build also crashes on SELECT (release build does not):
|
On 10.1 |
CREATE TABLE `AttendDet` ( |
`EmplCode` smallint(6) DEFAULT NULL, |
`Comments` longtext DEFAULT NULL, |
`EmplName` varchar(30) DEFAULT NULL, |
`AttendCode` smallint(6) DEFAULT NULL, |
`SearchDate` smallint(6) DEFAULT NULL, |
`CreatedBy` varchar(12) DEFAULT NULL, |
`ActClockInTime` char(5) DEFAULT NULL, |
`ActClockOutTime` char(5) DEFAULT NULL, |
`AdjClockInTime` char(5) DEFAULT NULL, |
`AdjClockOutTime` char(5) DEFAULT NULL, |
`ActClockInDate` char(8) DEFAULT NULL, |
`ActClockOutDate` char(8) DEFAULT NULL, |
`AdjClockInDate` char(8) DEFAULT NULL, |
`AdjClockOutDate` char(8) DEFAULT NULL, |
`TotActTime` double DEFAULT NULL, |
`TotAdjTime` double DEFAULT NULL, |
`PayRateCode` smallint(6) DEFAULT NULL, |
`PayrollRate` double DEFAULT NULL, |
`Shift` smallint(6) DEFAULT NULL, |
`OverTime` char(1) DEFAULT NULL, |
`Holiday` char(1) DEFAULT NULL, |
`GLAcct` varchar(12) DEFAULT NULL, |
`OTCalcFlag` char(1) DEFAULT NULL, |
`DeviceNo` smallint(6) DEFAULT NULL, |
`AttendDet_ID` int(11) NOT NULL AUTO_INCREMENT, |
`TicketDate` date DEFAULT NULL, |
`Counter` int(11) GENERATED ALWAYS AS (`AttendDet_ID`) VIRTUAL, |
`LastModDate` datetime DEFAULT NULL, |
`LastModUser` varchar(12) CHARACTER SET utf8 DEFAULT NULL, |
PRIMARY KEY (`AttendDet_ID`), |
KEY `IX_AttendDet_EmplCode_TicketDate` (`EmplCode`,`TicketDate`), |
KEY `IX_AttendDet_EmplCode` (`EmplCode`), |
KEY `IX_AttendDet_AttendCode` (`AttendCode`), |
KEY `IX_AttendDet_CreatedBy` (`CreatedBy`), |
KEY `IX_AttendDet_ActClockInTime` (`ActClockInTime`), |
KEY `IX_AttendDet_EmplCode_Holiday_SearchDate` (`EmplCode`,`Holiday`,`SearchDate`), |
KEY `IX_AttendDet_SearchDate` (`SearchDate`), |
KEY `IX_AttendDet_EmplCode_Holiday` (`EmplCode`,`Holiday`), |
KEY `IX_AttendDet_EmplCode_SearchDate` (`EmplCode`,`SearchDate`), |
KEY `IX_AttendDet_EmplCode_OTCalcFlag` (`EmplCode`,`OTCalcFlag`), |
KEY `IX_AttendDet_Shift` (`Shift`), |
KEY `IX_AttendDet_EmplCode_ActClockOutTime_AttendCode` (`EmplCode`,`ActClockOutTime`,`AttendCode`), |
KEY `IX_AttendDet_EmplCode_ActClockOutTime` (`EmplCode`,`ActClockOutTime`) |
) ENGINE=InnoDB AUTO_INCREMENT=527 DEFAULT CHARSET=utf8mb4 ROW_FORMAT=DYNAMIC; |
|
|
INSERT INTO `AttendDet` () VALUES (),(); |
|
On 10.2 debug |
MariaDB [test]> SELECT * FROM `AttendDet`; |
ERROR 2013 (HY000): Lost connection to MySQL server during query |
|
10.2 debug 387bdf07ae097 |
mysqld: /data/src/10.2/storage/innobase/include/dict0dict.ic:546: dict_v_col_t* dict_table_get_nth_v_col(const dict_table_t*, ulint): Assertion `pos < table->n_v_def' failed.
|
171007 17:21:00 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f6d8e110ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x00005589882394ab in dict_table_get_nth_v_col (table=0x7f6d2402d248, pos=0) at /data/src/10.2/storage/innobase/include/dict0dict.ic:546
|
#9 0x0000558988246e7b in build_template_field (prebuilt=0x7f6d2403e158, clust_index=0x7f6d2402e7c8, index=0x7f6d2402e7c8, table=0x7f6d2401aec0, field=0x7f6d24022850, i=26, v_no=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:7739
|
#10 0x0000558988248a20 in ha_innobase::build_template (this=0x7f6d240205a8, whole_row=false) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:8235
|
#11 0x000055898824d354 in ha_innobase::change_active_index (this=0x7f6d240205a8, keynr=0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10105
|
#12 0x000055898824da3f in ha_innobase::rnd_init (this=0x7f6d240205a8, scan=true) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:10313
|
#13 0x0000558987c4b08e in handler::ha_rnd_init (this=0x7f6d240205a8, scan=true) at /data/src/10.2/sql/handler.h:2832
|
#14 0x0000558987f3b4fb in handler::ha_rnd_init_with_error (this=0x7f6d240205a8, scan=true) at /data/src/10.2/sql/handler.cc:2784
|
#15 0x00005589880a46f9 in init_read_record (info=0x7f6d24015040, thd=0x7f6d24000b00, table=0x7f6d2401aec0, select=0x7f6d240158c8, filesort=0x0, use_record_cache=1, print_error=true, disable_rr_cache=false) at /data/src/10.2/sql/records.cc:299
|
#16 0x0000558987d36cc2 in join_init_read_record (tab=0x7f6d24014f78) at /data/src/10.2/sql/sql_select.cc:19482
|
#17 0x0000558987d34aec in sub_select (join=0x7f6d24011900, join_tab=0x7f6d24014f78, end_of_records=false) at /data/src/10.2/sql/sql_select.cc:18560
|
#18 0x0000558987d340e7 in do_select (join=0x7f6d24011900, procedure=0x0) at /data/src/10.2/sql/sql_select.cc:18107
|
#19 0x0000558987d0e923 in JOIN::exec_inner (this=0x7f6d24011900) at /data/src/10.2/sql/sql_select.cc:3483
|
#20 0x0000558987d0ddd2 in JOIN::exec (this=0x7f6d24011900) at /data/src/10.2/sql/sql_select.cc:3278
|
#21 0x0000558987d0ef9b in mysql_select (thd=0x7f6d24000b00, tables=0x7f6d24011200, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f6d240118e0, unit=0x7f6d240046a0, select_lex=0x7f6d24004dd8) at /data/src/10.2/sql/sql_select.cc:3678
|
#22 0x0000558987d038c6 in handle_select (thd=0x7f6d24000b00, lex=0x7f6d240045d8, result=0x7f6d240118e0, setup_tables_done_option=0) at /data/src/10.2/sql/sql_select.cc:373
|
#23 0x0000558987ccf75a in execute_sqlcom_select (thd=0x7f6d24000b00, all_tables=0x7f6d24011200) at /data/src/10.2/sql/sql_parse.cc:6434
|
#24 0x0000558987cc54a3 in mysql_execute_command (thd=0x7f6d24000b00) at /data/src/10.2/sql/sql_parse.cc:3461
|
#25 0x0000558987cd311c in mysql_parse (thd=0x7f6d24000b00, rawbuf=0x7f6d24011008 "SELECT * FROM `AttendDet`", length=25, parser_state=0x7f6d78501250, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:7875
|
#26 0x0000558987cc0dc0 in dispatch_command (command=COM_QUERY, thd=0x7f6d24000b00, packet=0x7f6d24008791 "", packet_length=25, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1812
|
#27 0x0000558987cbf736 in do_command (thd=0x7f6d24000b00) at /data/src/10.2/sql/sql_parse.cc:1360
|
#28 0x0000558987e0c917 in do_handle_one_connection (connect=0x55898ad235d0) at /data/src/10.2/sql/sql_connect.cc:1354
|
#29 0x0000558987e0c6a4 in handle_one_connection (arg=0x55898ad235d0) at /data/src/10.2/sql/sql_connect.cc:1260
|
#30 0x00007f6d90055494 in start_thread (arg=0x7f6d78502700) at pthread_create.c:333
|
#31 0x00007f6d8e1cd93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
A datadir with pre-created table AttendDet is attached as data2.tar.gz
I can repeat the crash on 10.2 with the attached data2.tar.gz. The crash occurs on this column:
`Counter` int(11) GENERATED ALWAYS AS (`AttendDet_ID`) VIRTUAL, |
In 10.2, InnoDB would store virtual columns in the dictionary table SYS_VIRTUAL. There is no such table in 10.1 or in the attached data dump. So, we will have table->n_v_def==0.
The question is: Why does ha_innobase::build_template() think that this column should be included in the query? There is no index on the column (because before MDEV-5800 in 10.2, indexed virtual columns were not supported in InnoDB).
We do have !whole_row, so the wrong decision must have been made by build_template_needs_field(). The input parameter looks wrong:
if (innobase_is_v_fld(table->field[i])) { |
contain = dict_index_contains_col_or_prefix(
|
index, num_v, true); |
The clustered index never really contains virtual columns, but the code incorrectly claims so:
/** Returns TRUE if the index contains a column or a prefix of that column.
|
@param[in] index index
|
@param[in] n column number
|
@param[in] is_virtual whether it is a virtual col
|
@return TRUE if contains the column or its prefix */
|
ibool
|
dict_index_contains_col_or_prefix(
|
const dict_index_t* index, |
ulint n,
|
bool is_virtual) |
{
|
const dict_field_t* field; |
const dict_col_t* col; |
ulint pos;
|
ulint n_fields;
|
|
|
ut_ad(index);
|
ut_ad(index->magic_n == DICT_INDEX_MAGIC_N);
|
|
|
if (dict_index_is_clust(index)) { |
|
|
return(TRUE); |
}
|
I fixed the InnoDB part with the patch below. But, there still is something wrong:
==11359==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x6190000914d2 at pc 0x0000006b83f1 bp 0x7fffdfe94490 sp 0x7fffdfe93c40
|
READ of size 16736 at 0x6190000914d2 thread T27
|
#0 0x6b83f0 in __asan_memcpy (/mariadb/10.2/build/sql/mysqld+0x6b83f0)
|
#1 0xc8a761 in String::append(char const*, unsigned long) /mariadb/10.2/sql/sql_string.cc:473:3
|
#2 0xd8416e in parse_vcol_defs(THD*, st_mem_root*, TABLE*, bool*) /mariadb/10.2/sql/table.cc:1062:14
|
#3 0xd8f67c in open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool) /mariadb/10.2/sql/table.cc:3176:9
|
#4 0x8738e2 in open_table(THD*, TABLE_LIST*, Open_table_context*) /mariadb/10.2/sql/sql_base.cc:1874:12
|
#5 0x87ed03 in open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) /mariadb/10.2/sql/sql_base.cc:3409:14
|
#6 0x87b728 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /mariadb/10.2/sql/sql_base.cc:3926:14
|
#7 0x8875e4 in open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /mariadb/10.2/sql/sql_base.h:235:10
|
#8 0x8871a8 in open_normal_and_derived_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) /mariadb/10.2/sql/sql_base.cc:4745:7
|
#9 0xc02965 in mysqld_list_fields(THD*, TABLE_LIST*, char const*) /mariadb/10.2/sql/sql_show.cc:1422:7
|
#10 0x9df01a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /mariadb/10.2/sql/sql_parse.cc:2006:5
|
#11 0x9e5bcc in do_command(THD*) /mariadb/10.2/sql/sql_parse.cc:1359:17
|
#12 0xe80b0a in do_handle_one_connection(CONNECT*) /mariadb/10.2/sql/sql_connect.cc:1354:11
|
#13 0xe80231 in handle_one_connection /mariadb/10.2/sql/sql_connect.cc:1260:3
|
#14 0x28cfec4 in pfs_spawn_thread /mariadb/10.2/storage/perfschema/pfs.cc:1862:3
|
#15 0x6dae52 in __asan::AsanThread::ThreadStart(unsigned long, __sanitizer::atomic_uintptr_t*) (/mariadb/10.2/build/sql/mysqld+0x6dae52)
|
#16 0x7ffff7bc3493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
|
#17 0x7ffff6405abe in clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8abe)
|
|
|
0x6190000914d2 is located 98 bytes to the right of 1008-byte region [0x619000091080,0x619000091470)
|
allocated by thread T27 here:
|
#0 0x6cd3a0 in __interceptor_malloc (/mariadb/10.2/build/sql/mysqld+0x6cd3a0)
|
#1 0x2a050c5 in my_malloc /mariadb/10.2/mysys/my_malloc.c:101:10
|
#2 0x29d67cf in alloc_root /mariadb/10.2/mysys/my_alloc.c:184:28
|
#3 0x29d717c in multi_alloc_root /mariadb/10.2/mysys/my_alloc.c:304:24
|
#4 0xd761f7 in TABLE_SHARE::init_from_binary_frm_image(THD*, bool, unsigned char const*, unsigned long) /mariadb/10.2/sql/table.cc:1620:8
|
#5 0xd6f890 in open_table_def(THD*, TABLE_SHARE*, unsigned int) /mariadb/10.2/sql/table.cc:669:10
|
#6 0x10610fb in tdc_acquire_share(THD*, TABLE_LIST*, unsigned int, TABLE**) /mariadb/10.2/sql/table_cache.cc:825:5
|
#7 0x872922 in open_table(THD*, TABLE_LIST*, Open_table_context*) /mariadb/10.2/sql/sql_base.cc:1742:10
|
#8 0x87ed03 in open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) /mariadb/10.2/sql/sql_base.cc:3409:14
|
#9 0x87b728 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /mariadb/10.2/sql/sql_base.cc:3926:14
|
#10 0x8875e4 in open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /mariadb/10.2/sql/sql_base.h:235:10
|
#11 0x8871a8 in open_normal_and_derived_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) /mariadb/10.2/sql/sql_base.cc:4745:7
|
#12 0xc02965 in mysqld_list_fields(THD*, TABLE_LIST*, char const*) /mariadb/10.2/sql/sql_show.cc:1422:7
|
#13 0x9df01a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /mariadb/10.2/sql/sql_parse.cc:2006:5
|
#14 0x9e5bcc in do_command(THD*) /mariadb/10.2/sql/sql_parse.cc:1359:17
|
#15 0xe80b0a in do_handle_one_connection(CONNECT*) /mariadb/10.2/sql/sql_connect.cc:1354:11
|
#16 0xe80231 in handle_one_connection /mariadb/10.2/sql/sql_connect.cc:1260:3
|
#17 0x28cfec4 in pfs_spawn_thread /mariadb/10.2/storage/perfschema/pfs.cc:1862:3
|
#18 0x6dae52 in __asan::AsanThread::ThreadStart(unsigned long, __sanitizer::atomic_uintptr_t*) (/mariadb/10.2/build/sql/mysqld+0x6dae52)
|
|
|
Thread T27 created by T0 here:
|
#0 0x630890 in pthread_create (/mariadb/10.2/build/sql/mysqld+0x630890)
|
#1 0x28d4e9b in spawn_thread_v1(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /mariadb/10.2/storage/perfschema/pfs.cc:1912:15
|
#2 0x713e2a in inline_mysql_thread_create(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) /mariadb/10.2/include/mysql/psi/mysql_thread.h:1239:11
|
#3 0x7230dd in create_thread_to_handle_connection(CONNECT*) /mariadb/10.2/sql/mysqld.cc:6445:15
|
#4 0x72517f in create_new_thread(CONNECT*) /mariadb/10.2/sql/mysqld.cc:6515:3
|
#5 0x72298a in handle_connections_sockets() /mariadb/10.2/sql/mysqld.cc:6790:5
|
#6 0x717246 in mysqld_main(int, char**) /mariadb/10.2/sql/mysqld.cc:6064:3
|
#7 0x70b661 in main /mariadb/10.2/sql/main.cc:25:10
|
#8 0x7ffff633d2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
|
|
|
SUMMARY: AddressSanitizer: heap-buffer-overflow (/mariadb/10.2/build/sql/mysqld+0x6b83f0) in __asan_memcpy
|
Shadow bytes around the buggy address:
|
0x0c328000a240: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a250: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a260: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a270: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a280: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 fa fa
|
=>0x0c328000a290: fa fa fa fa fa fa fa fa fa fa[fa]fa fa fa fa fa
|
0x0c328000a2a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c328000a2b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a2c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a2d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c328000a2e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
This happens during client startup:
#5 0x00000000006b8410 in __asan_memcpy ()
|
#6 0x0000000000c8a762 in String::append (this=0x7fffdfe946e0,
|
s=0x6190000914d2 "", size=16736) at /mariadb/10.2/sql/sql_string.cc:473
|
#7 0x0000000000d8416f in parse_vcol_defs (thd=0x62a0000ba208,
|
mem_root=0x61e000041f40, table=0x61e000041488,
|
error_reported=0x7fffdfe95180) at /mariadb/10.2/sql/table.cc:1062
|
#8 0x0000000000d8f67d in open_table_from_share (thd=0x62a0000ba208,
|
share=0x61a0000702a0, alias=0x60600015fdc0 "AttendDet", db_stat=33,
|
prgflag=8, ha_open_flags=16, outparam=0x61e000041488,
|
) at /mariadb/10.2/sql/table.cc:3176
|
#9 0x00000000008738e3 in open_table (thd=0x62a0000ba208,
|
table_list=0x7fffdfe99010, ot_ctx=0x7fffdfe975c0)
|
at /mariadb/10.2/sql/sql_base.cc:1874
|
#10 0x000000000087ed04 in open_and_process_table (thd=0x62a0000ba208,
|
lex=0x62a0000bdce0, tables=0x7fffdfe99010, counter=0x7fffdfe97e60,
|
flags=1024, prelocking_strategy=0x7fffdfe97e40,
|
has_prelocking_list=false, ot_ctx=0x7fffdfe975c0)
|
at /mariadb/10.2/sql/sql_base.cc:3409
|
#11 0x000000000087b729 in open_tables (thd=0x62a0000ba208, options=...,
|
start=0x7fffdfe97e20, counter=0x7fffdfe97e60, flags=1024,
|
prelocking_strategy=0x7fffdfe97e40) at /mariadb/10.2/sql/sql_base.cc:3926
|
#12 0x00000000008875e5 in open_tables (thd=0x62a0000ba208,
|
tables=0x7fffdfe97e20, counter=0x7fffdfe97e60, flags=1024,
|
prelocking_strategy=0x7fffdfe97e40) at /mariadb/10.2/sql/sql_base.h:235
|
#13 0x00000000008871a9 in open_normal_and_derived_tables (thd=0x62a0000ba208,
|
tables=0x7fffdfe99010, flags=1024, dt_phases=35)
|
at /mariadb/10.2/sql/sql_base.cc:4745
|
#14 0x0000000000c02966 in mysqld_list_fields (thd=0x62a0000ba208,
|
table_list=0x7fffdfe99010, wild=0x604000016ef0 "")
|
at /mariadb/10.2/sql/sql_show.cc:1422
|
#15 0x00000000009df01b in dispatch_command (command=COM_FIELD_LIST,
|
thd=0x62a0000ba208, packet=0x62900008c213 "", packet_length=10,
|
is_com_multi=false, is_next_command=false)
|
at /mariadb/10.2/sql/sql_parse.cc:2006
|
#16 0x00000000009e5bcd in do_command (thd=0x62a0000ba208)
|
at /mariadb/10.2/sql/sql_parse.cc:1359
|
#17 0x0000000000e80b0b in do_handle_one_connection (connect=0x6080000021a8)
|
at /mariadb/10.2/sql/sql_connect.cc:1354
|
#18 0x0000000000e80232 in handle_one_connection (arg=0x6080000021a8)
|
at /mariadb/10.2/sql/sql_connect.cc:1260
|
This is my InnoDB patch:
diff --git a/storage/innobase/dict/dict0dict.cc b/storage/innobase/dict/dict0dict.cc
|
index 54e0115070d..b95592d43d4 100644
|
--- a/storage/innobase/dict/dict0dict.cc
|
+++ b/storage/innobase/dict/dict0dict.cc
|
@@ -912,8 +912,7 @@ dict_index_contains_col_or_prefix(
|
ut_ad(index->magic_n == DICT_INDEX_MAGIC_N);
|
|
if (dict_index_is_clust(index)) {
|
-
|
- return(TRUE);
|
+ return(!is_virtual);
|
}
|
|
if (is_virtual) {
|
diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc
|
index 0e9708eb151..3374f46fb24 100644
|
--- a/storage/innobase/handler/ha_innodb.cc
|
+++ b/storage/innobase/handler/ha_innodb.cc
|
@@ -8204,13 +8204,16 @@ ha_innobase::build_template(
|
} else {
|
ibool contain;
|
|
- if (innobase_is_v_fld(table->field[i])) {
|
- contain = dict_index_contains_col_or_prefix(
|
- index, num_v, true);
|
- } else {
|
+ if (!innobase_is_v_fld(table->field[i])) {
|
contain = dict_index_contains_col_or_prefix(
|
index, i - num_v,
|
false);
|
+ } else if (dict_index_is_clust(index)) {
|
+ num_v++;
|
+ continue;
|
+ } else {
|
+ contain = dict_index_contains_col_or_prefix(
|
+ index, num_v, true);
|
}
|
|
field = build_template_needs_field( |
With the above patch, I only tested that SELECT and CHECK TABLE works.
I did not test various forms of ALTER TABLE…ALGORITHM=INPLACE yet.
I think that we should also test MDEV-11369 in 10.3 with the same dataset.
For some reason, I did not originally get the above-reported stack trace in ASAN. It appears to occur on the first access to the table. With mysql -A, it happens on the first SQL statement that refers to the table (say, CHECK TABLE AttendDet).
I pushed the InnoDB fix to 10.2.
With that fix (and when building the server without -DWITH_ASAN), the server no longer crashes on SELECT, but it does show another problem that I filed as
MDEV-14046 Allow ALGORITHM=INPLACE for 10.1 tables that contain virtual columns
I see that serg pushed a work-around for this into bb-10.2-serg, forcing ALGORITHM=COPY for the affected tables. That work-around is OK for now, but the commit comment should refer to MDEV-14046.
The heap buffer overflow that I reported is not repeatable today. It might depend on the nondeterministic behaviour of the memory allocator. Maybe the memory alignment plays a role?
I tested the current 10.2 built in the following configurations:
cmake -DWITH_ASAN=1 -DCMAKE_BUILD_TYPE=Debug
|
cmake -DWITH_ASAN=1 -DCMAKE_BUILD_TYPE=RelWithDebInfo
|
Could you please provide the output of SHOW CREATE TABLE `Counter`, attach your cnf file(s), and also if possible paste the stack trace from the node where the query was initially issued?
Thanks.