Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1.8
-
linode virtual server Linode 48GB 16 Cores 1152 GB SSD
Centos 6.5
-
10.1.10
Description
Mariadb 10.1.8 server crashed and now it is restarting in the loop
Server is used just as backup server with no read traffic and it crashed during replication of commands from master running Mariadb 10.0.22
Part of the error log:
2015-11-13 05:39:37 7f4e03ffe700 InnoDB: Assertion failure in thread 139973051279104 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
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.
|
151113 5:39:37 [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.8-MariaDB-log
|
key_buffer_size=134217728
|
read_buffer_size=131072
|
max_used_connections=0
|
max_threads=5002
|
thread_count=0
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11117553 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
|
2015-11-13 05:39:37 7f4e047ff700 InnoDB: Assertion failure in thread 139973059671808 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
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.
|
151113 05:39:38 mysqld_safe Number of processes running now: 0
|
151113 05:39:38 mysqld_safe mysqld restarted
|
2015-11-13 5:39:38 139789607671840 [Note] /usr/sbin/mysqld (mysqld 10.1.8-MariaDB-log) starting as process 11180 ...
|
2015-11-13 05:39:38 7f234de89820 InnoDB: Warning: Setting innodb_use_sys_malloc to FALSE is DEPRECATED. This option may be removed in future releases, together with the InnoDB's internal memory allocator.
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Memory barrier is not used
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Using Linux native AIO
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Using CPU crc32 instructions
|
2015-11-13 5:39:38 139789607671840 [Note] InnoDB: Initializing buffer pool, size = 25.0G
|
2015-11-13 5:39:40 139789607671840 [Note] InnoDB: Completed initialization of buffer pool
|
2015-11-13 5:39:41 139789607671840 [Note] InnoDB: Highest supported file format is Barracuda.
|
2015-11-13 5:39:41 139789607671840 [Note] InnoDB: Log scan progressed past the checkpoint lsn 4932606017459
|
2015-11-13 5:39:41 139789607671840 [Note] InnoDB: Database was not shutdown normally!
|
2015-11-13 5:39:41 139789607671840 [Note] InnoDB: Starting crash recovery.
|
2015-11-13 5:39:41 139789607671840 [Note] InnoDB: Reading tablespace information from the .ibd files...
|
2015-11-13 5:39:57 139789607671840 [Note] InnoDB: Processed 100683 .ibd/.isl files
|
2015-11-13 5:40:13 139789607671840 [Note] InnoDB: Processed 198737 .ibd/.isl files
|
2015-11-13 5:40:29 139789607671840 [Note] InnoDB: Processed 297902 .ibd/.isl files
|
2015-11-13 5:40:45 139789607671840 [Note] InnoDB: Processed 391842 .ibd/.isl files
|
2015-11-13 5:41:01 139789607671840 [Note] InnoDB: Processed 487883 .ibd/.isl files
|
2015-11-13 5:41:17 139789607671840 [Note] InnoDB: Processed 579656 .ibd/.isl files
|
2015-11-13 5:41:33 139789607671840 [Note] InnoDB: Processed 670725 .ibd/.isl files
|
2015-11-13 5:41:42 139789607671840 [Note] InnoDB: Restoring possible half-written data pages
|
2015-11-13 5:41:42 139789607671840 [Note] InnoDB: from the doublewrite buffer...
|
InnoDB: Doing recovery: scanned up to log sequence number 4932606076098
|
2015-11-13 5:41:43 139789607671840 [Note] InnoDB: Starting an apply batch of log records to the database...
|
InnoDB: Progress in percent: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
|
InnoDB: Apply batch completed
|
InnoDB: Last MySQL binlog file position 0 242205496, file name ./mysql-bin.001779
|
2015-11-13 5:42:07 139789607671840 [Note] InnoDB: 128 rollback segment(s) are active.
|
2015-11-13 5:42:07 139789607671840 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 4932606076098
|
2015-11-13 5:42:07 139756801316608 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2015-11-13 5:42:07 139789607671840 [Note] Plugin 'FEEDBACK' is disabled.
|
2015-11-13 5:42:07 139789607671840 [Note] Recovering after a crash using mysql-bin
|
2015-11-13 5:42:07 139789607671840 [Note] Starting crash recovery...
|
2015-11-13 5:42:07 139789607671840 [Note] Crash recovery finished.
|
2015-11-13 5:42:07 139789607671840 [Note] Server socket created on IP: '::'.
|
2015-11-13 5:42:07 139789607671840 [Note] Event Scheduler: Loaded 0 events
|
2015-11-13 5:42:07 139789607671840 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=3_dbbackup_la_linode-uk-relay-bin' to avoid this problem.
|
2015-11-13 5:42:07 139789607671840 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.1.8-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
|
2015-11-13 5:42:07 139789218531072 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.001790' at position 257187369, relay log './3_dbbackup_la_linode-uk-relay-bin.000928' position: 257187657
|
2015-11-13 5:42:07 139789606020864 [Note] Slave I/O thread: connected to master 'replicator@192.168.169.192:3306',replication started in log 'mysql-bin.001790' at position 862639170
|
2015-11-13 5:42:07 139789218830080 [Note] InnoDB: Online DDL : Start
|
2015-11-13 5:42:07 139789218830080 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
|
2015-11-13 05:42:09 7f1b9f3fe700 InnoDB: Assertion failure in thread 139756612609792 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
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.
|
151113 5:42:09 [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.8-MariaDB-log
|
key_buffer_size=134217728
|
read_buffer_size=131072
|
max_used_connections=0
|
max_threads=5002
|
thread_count=0
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11117553 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
|
2015-11-13 05:42:09 7f1b9fbff700 InnoDB: Assertion failure in thread 139756621002496 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
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.
|
151113 05:42:10 mysqld_safe Number of processes running now: 0
|
151113 05:42:10 mysqld_safe mysqld restarted
|
2015-11-13 5:42:10 140555941337120 [Note] /usr/sbin/mysqld (mysqld 10.1.8-MariaDB-log) starting as process 11482 ...
|
2015-11-13 05:42:10 7fd5baf45820 InnoDB: Warning: Setting innodb_use_sys_malloc to FALSE is DEPRECATED. This option may be removed in future releases, together with the InnoDB's internal memory allocator.
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Memory barrier is not used
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Using Linux native AIO
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Using CPU crc32 instructions
|
2015-11-13 5:42:10 140555941337120 [Note] InnoDB: Initializing buffer pool, size = 25.0G
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Completed initialization of buffer pool
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Highest supported file format is Barracuda.
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Log scan progressed past the checkpoint lsn 4932606076108
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Database was not shutdown normally!
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Starting crash recovery.
|
2015-11-13 5:42:13 140555941337120 [Note] InnoDB: Reading tablespace information from the .ibd files...
|
2015-11-13 5:42:29 140555941337120 [Note] InnoDB: Processed 97537 .ibd/.isl files
|
2015-11-13 5:42:45 140555941337120 [Note] InnoDB: Processed 195624 .ibd/.isl files
|
2015-11-13 5:43:01 140555941337120 [Note] InnoDB: Processed 293425 .ibd/.isl files
|
2015-11-13 5:43:17 140555941337120 [Note] InnoDB: Processed 386672 .ibd/.isl files
|
2015-11-13 5:43:33 140555941337120 [Note] InnoDB: Processed 480040 .ibd/.isl files
|
2015-11-13 5:43:49 140555941337120 [Note] InnoDB: Processed 574244 .ibd/.isl files
|
2015-11-13 5:44:05 140555941337120 [Note] InnoDB: Processed 661463 .ibd/.isl files
|
2015-11-13 5:44:16 140555941337120 [Note] InnoDB: Restoring possible half-written data pages
|
2015-11-13 5:44:16 140555941337120 [Note] InnoDB: from the doublewrite buffer...
|
InnoDB: Doing recovery: scanned up to log sequence number 4932606134463
|
2015-11-13 5:44:17 140555941337120 [Note] InnoDB: Starting an apply batch of log records to the database...
|
InnoDB: Progress in percent: 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
|
InnoDB: Apply batch completed
|
InnoDB: Last MySQL binlog file position 0 242205496, file name ./mysql-bin.001779
|
2015-11-13 5:44:40 140555941337120 [Note] InnoDB: 128 rollback segment(s) are active.
|
2015-11-13 5:44:40 140555941337120 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 4932606134463
|
2015-11-13 5:44:40 140523113240320 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2015-11-13 5:44:40 140555941337120 [Note] Plugin 'FEEDBACK' is disabled.
|
2015-11-13 5:44:40 140555941337120 [Note] Recovering after a crash using mysql-bin
|
2015-11-13 5:44:40 140555941337120 [Note] Starting crash recovery...
|
2015-11-13 5:44:40 140555941337120 [Note] Crash recovery finished.
|
2015-11-13 5:44:40 140555941337120 [Note] Server socket created on IP: '::'.
|
2015-11-13 5:44:40 140555941337120 [Note] Event Scheduler: Loaded 0 events
|
2015-11-13 5:44:40 140555941337120 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=3_dbbackup_la_linode-uk-relay-bin' to avoid this problem.
|
2015-11-13 5:44:40 140555941337120 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.1.8-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
|
2015-11-13 5:44:40 140555552024320 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.001790' at position 257187369, relay log './3_dbbackup_la_linode-uk-relay-bin.000928' position: 257187657
|
2015-11-13 5:44:40 140555939686144 [Note] Slave I/O thread: connected to master 'replicator@192.168.169.192:3306',replication started in log 'mysql-bin.001790' at position 873411395
|
2015-11-13 5:44:40 140555846170368 [Note] InnoDB: Online DDL : Start
|
2015-11-13 5:44:40 140555846170368 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
|
2015-11-13 05:44:42 7fce0a7fe700 InnoDB: Assertion failure in thread 140522916144896 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
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.
|
.... and the same logs again and again
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
When I started server in readonly mode, replication doesn't start and the server is running fine.
Also mysqlcheck confirmed, that all data are correct without corruption.
So the problem is isolated to ALTER TABLE, which adds fulltext index on huge table
We have found solution to fix the problem:
innodb_sort_buffer_size was increased from default value 1MB to 4G
It should print at least the message, that the ALTER TABLE failed because of low buffer size or it should handle the creating of index on smaller buffers in less efficient way
I had same problem while having default innodb settings activated. It happened when I played with gtd_slave_pos table converting from myisam to innodb (and back), so it suddenly crashed and then mariadb (10) began endless restarts. I simply disabled innodb. Afterwards I couldn't simulate the problem again.
Could you please paste the output of SHOW CREATE TABLE and SHOW INDEX IN ... for the table, and also attach your cnf files?
Trying to reproduce it on an arbitrary table of a similar size didn't succeed.
Table looks like this after ALTER TABLE was executed
CREATE TABLE `qu_la_contacts` ( |
`contactid` char(8) NOT NULL, |
`parent_contactid` char(8) DEFAULT NULL, |
`company` char(1) NOT NULL DEFAULT 'N', |
`job_position` varchar(255) DEFAULT NULL, |
`emails` text,
|
`firstname` varchar(100) DEFAULT NULL, |
`lastname` varchar(100) DEFAULT NULL, |
`system_name` varchar(100) DEFAULT NULL, |
`description` varchar(255) DEFAULT NULL, |
`rtype` char(1) NOT NULL, |
`status` char(1) NOT NULL DEFAULT 'A' COMMENT 'A=Active, X=Deleted', |
`datecreated` datetime DEFAULT NULL, |
`avatar_url` text,
|
`city` varchar(255) DEFAULT NULL, |
`countrycode` varchar(2) DEFAULT NULL, |
`note` text,
|
`time_offset` int(11) DEFAULT NULL, |
`language` varchar(10) DEFAULT NULL, |
`gender` char(1) NOT NULL DEFAULT 'M', |
`levelid` char(8) DEFAULT NULL, |
`ldap_id` varchar(255) DEFAULT NULL, |
`groups` varchar(255) DEFAULT NULL, |
`ip` varchar(39) DEFAULT NULL, |
`useragent` text,
|
`screen` varchar(12) DEFAULT NULL, |
`latitude` float DEFAULT NULL, |
`longitude` float DEFAULT NULL, |
`last_action_type` char(1) DEFAULT NULL, |
`last_action_date` datetime DEFAULT NULL, |
`last_action_meta` varchar(80) DEFAULT NULL, |
PRIMARY KEY (`contactid`), |
KEY `fk_qu_la_contacts_qu_la_levels1_idx` (`levelid`), |
KEY `fk_parent_contactid` (`parent_contactid`), |
KEY `qu_la_contacts_datecreated` (`datecreated`), |
FULLTEXT KEY `ft_qu_la_contacts_groups` (`groups`) |
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=8 |
MariaDB [u72359_aa97]> show index in qu_la_contacts;
|
+----------------+------------+-------------------------------------+--------------+------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
|
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
|
+----------------+------------+-------------------------------------+--------------+------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
|
| qu_la_contacts | 0 | PRIMARY | 1 | contactid | A | 665638 | NULL | NULL | | BTREE | | |
|
| qu_la_contacts | 1 | fk_qu_la_contacts_qu_la_levels1_idx | 1 | levelid | A | 20 | NULL | NULL | YES | BTREE | | |
|
| qu_la_contacts | 1 | fk_parent_contactid | 1 | parent_contactid | A | 2 | NULL | NULL | YES | BTREE | | |
|
| qu_la_contacts | 1 | qu_la_contacts_datecreated | 1 | datecreated | A | 665638 | NULL | NULL | YES | BTREE | | |
|
| qu_la_contacts | 1 | ft_qu_la_contacts_groups | 1 | groups | NULL | 665638 | NULL | NULL | YES | FULLTEXT | | |
|
+----------------+------------+-------------------------------------+--------------+------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
|
5 rows in set (0.00 sec)
|
[mysqld]
|
server-id=103
|
datadir=/opt/mysql/
|
socket=/var/lib/mysql/mysql.sock
|
tmpdir=/tmp/
|
|
|
innodb_sort_buffer_size=4G
|
log_bin=mysql-bin
|
expire_logs_days=6
|
|
|
wait_timeout=60
|
long_query_time=1
|
slow_query_log=1
|
slow_query_log_file=/opt/log/slow.log
|
|
|
userstat = 1
|
user=root
|
symbolic-links=0
|
binlog_format=STATEMENT
|
default_storage_engine=InnoDB
|
slave_skip_errors=1062,1396,1690
|
innodb_autoinc_lock_mode=2
|
innodb_buffer_pool_size=25G
|
innodb_buffer_pool_instances=20
|
innodb_log_file_size=4G
|
innodb_log_buffer_size=196M
|
innodb_flush_log_at_trx_commit=0
|
innodb_thread_concurrency=24
|
innodb_file_per_table
|
innodb_write_io_threads=24
|
innodb_read_io_threads=24
|
innodb_sched_priority_cleaner=39
|
innodb_adaptive_flushing=1
|
innodb_purge_threads=5
|
innodb_adaptive_hash_index_partitions=64
|
innodb_flush_neighbors=0
|
innodb_flush_method=O_DIRECT
|
innodb_io_capacity=5000
|
innodb_io_capacity_max=8000
|
innodb_lru_scan_depth=1024
|
innodb_use_sys_malloc=0
|
innodb_file_format=Barracuda
|
innodb_file_format_max=Barracuda
|
slave_parallel_threads=10
|
log_slave_updates=on
|
performance_schema=off
|
|
|
skip-name-resolve
|
|
|
max_allowed_packet = 512M
|
|
|
query_cache_type=1
|
query_cache_size = 0
|
query_cache_limit = 1M
|
query_cache_min_res_unit=1K
|
max_connections = 5000
|
|
|
table_open_cache=64K
|
innodb_open_files=64K
|
open_files_limit=1020000
|
collation-server = utf8_general_ci
|
character-set-server = utf8
|
|
|
[mysqld_safe]
|
log-error=/opt/log/error.log
|
pid-file=/var/run/mysqld/mysqld.pid
|
malloc-lib=/usr/lib64/libjemalloc.so.1
|
maybe the key to the problem is, that it was replicated from other server
Thank you, I could reproduce it now.
2015-11-18 01:27:56 7f7c18ffe700 InnoDB: Assertion failure in thread 140170972096256 in file row0merge.cc line 892
|
InnoDB: Failing assertion: b < &block[srv_sort_buf_size]
|
InnoDB: We intentionally generate a memory trap.
|
|
Stack trace from 10.1 commit 836275bb203a47104eb7f28aa409924b91abc801 |
#4 0x00007f7d4b4593e0 in *__GI_abort () at abort.c:92
|
#5 0x00007f7d4e230098 in row_merge_buf_write (buf=0x7f7d1fca3028, of=<optimized out>, block=0x7f7d1e406000 "") at 10.1/storage/xtradb/row/row0merge.cc:892
|
#6 0x00007f7d4e21fb13 in fts_parallel_tokenization (arg=0x7f7d1fc1ef68) at 10.1/storage/xtradb/row/row0ftsort.cc:775
|
#7 0x00007f7d4d673b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
|
#8 0x00007f7d4b4ff95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
|
10.0 also fails, but differently, see MDEV-9148 (10.1 fails both on debug and release builds, while 10.0 only fails on release).
To reproduce, download and unpack ftp://ftp.askmonty.org/public/MDEV-9129_data.gz
create table t1 (groups varchar(255) DEFAULT NULL) ENGINE=InnoDB; |
load data local infile 't1.data' into table t1; |
ALTER TABLE t1 ADD FULLTEXT ft_qu_la_contacts_groups (groups); |
Default server settings are enough.
I'm also hit by this bug creating a fulltext index for a 2G InnoDB table.
I'm curious that increasing the innodb_sort_buffer_size from default value 1MB to 4G worked for @unitminer because:
- 64M is the max value for innodb_sort_buffer_size and any value above will be reset to 64M
- srv_sort_buf_size is actually the sort_buffer_size
I tried increasing the sort_buffer_size to 4G , but creating the fulltext index still crashes the server.
commit 1ac6640210bb337ecdfa9f8b818cc3c6156dbdcc
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Tue Dec 15 20:37:33 2015 +0200
MDEV-9129: Server is restarting in the loop after crash
Analysis: We have reserved ROW_MERGE_RESERVE_SIZE ( = 4) for
encryption key_version. When calculating is there more
space on sort buffer, this value needs to be substracted
from current available space.
Bug was not fixed. We have updated to Mariadb 10.1.18 to make sure we are running latest stable version and bug is still crashing server
(Maybe it was fixed for any other row format, but for row_format=COMPRESSED the problem is still there and server crash)
Is it exactly the same assertion, can you provide the error log?
Looks very similar:
2016-11-02 12:17:45 7f09b5ffe700 InnoDB: Assertion failure in thread 139679684880128 in file row0merge.cc line 890 |
InnoDB: Failing assertion: b == &block[0] + buf->total_size + ROW_MERGE_RESERVE_SIZE |
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.
|
161102 12:17:45 [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.1.18-MariaDB |
key_buffer_size=134217728 |
read_buffer_size=131072 |
max_used_connections=7 |
max_threads=902 |
thread_count=4 |
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2112329 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 0x48400 |
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x55b2f23d60ab] |
/usr/sbin/mysqld(handle_fatal_signal+0x475)[0x55b2f1f329f5] |
/lib64/libpthread.so.0(+0xf7e0)[0x7f0ef41c57e0] |
/lib64/libc.so.6(gsignal+0x35)[0x7f0ef281f5e5] |
/lib64/libc.so.6(abort+0x175)[0x7f0ef2820dc5] |
/usr/sbin/mysqld(+0x7d217b)[0x55b2f213717b] |
/usr/sbin/mysqld(+0x7bc990)[0x55b2f2121990] |
/lib64/libpthread.so.0(+0x7aa1)[0x7f0ef41bdaa1] |
/lib64/libc.so.6(clone+0x6d)[0x7f0ef28d5aad] |
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.
|
161102 12:17:46 mysqld_safe Number of processes running now: 0 |
161102 12:17:46 mysqld_safe mysqld restarted |
2016-11-02 12:17:47 140154303006752 [Note] /usr/sbin/mysqld (mysqld 10.1.18-MariaDB) starting as process 11425 ... |
2016-11-02 12:17:47 140154303006752 [Warning] Although a path was specified for the --log-slow-queries option, log tables are used. To enable logging to files use the --log-output=file option. |
2016-11-02 12:17:47 140154303006752 [Warning] option 'innodb-sort-buffer-size': unsigned value 4294967296 adjusted to 67108864 |
2016-11-02 12:17:47 140154303006752 [Warning] option 'innodb-ft-cache-size': unsigned value 83886080 adjusted to 80000000 |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Using mutexes to ref count buffer pool pages |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: The InnoDB memory heap is disabled |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Compressed tables use zlib 1.2.3 |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Using Linux native AIO |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Using SSE crc32 instructions |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Initializing buffer pool, size = 14.0G |
2016-11-02 12:17:47 140154303006752 [Note] InnoDB: Completed initialization of buffer pool |
2016-11-02 12:17:48 140154303006752 [Note] InnoDB: Highest supported file format is Barracuda. |
2016-11-02 12:17:48 140154303006752 [Note] InnoDB: Log scan progressed past the checkpoint lsn 15937771677812 |
2016-11-02 12:17:48 140154303006752 [Note] InnoDB: Database was not shutdown normally! |
2016-11-02 12:17:48 140154303006752 [Note] InnoDB: Starting crash recovery. |
2016-11-02 12:17:48 140154303006752 [Note] InnoDB: Reading tablespace information from the .ibd files... |
2016-11-02 12:18:04 140154303006752 [Note] InnoDB: Processed 92422 .ibd/.isl files |
2016-11-02 12:18:15 140154303006752 [Note] InnoDB: Restoring possible half-written data pages |
2016-11-02 12:18:15 140154303006752 [Note] InnoDB: from the doublewrite buffer... |
InnoDB: Doing recovery: scanned up to log sequence number 15937776920576 |
InnoDB: Doing recovery: scanned up to log sequence number 15937782163456 |
InnoDB: Doing recovery: scanned up to log sequence number 15937787406336 |
InnoDB: Doing recovery: scanned up to log sequence number 15937792649216 |
|
Only difference between original crash report and current crash could be, that in the meantime we are using compressed table row format.
This is not a same assertion is different as it tries to assert that whole buffer was added to sort buffer. I could not repeat the assertion using original table and data above. Can you share the structure of the table and loaded data for current problem ?
Table structure:
CREATE TABLE `qu_g_mails` (
|
`mailid` int(10) unsigned NOT NULL AUTO_INCREMENT, |
`hdr_message_id` varchar(255) DEFAULT NULL, |
`unique_message_id` varchar(255) NOT NULL, |
`subject` text,
|
`headers` text,
|
`body_text` longtext,
|
`body_html` longtext,
|
`created` datetime NOT NULL,
|
`delivered` datetime DEFAULT NULL,
|
`from_mail` text,
|
`to_recipients` text,
|
`cc_recipients` text,
|
`bcc_recipients` text,
|
`accountuserid` char(8) DEFAULT NULL, |
`reply_to` text,
|
PRIMARY KEY (`mailid`),
|
KEY `IDX_qu_g_mails_1` (`accountuserid`)
|
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED;
|
|
Mysql crash when adding index on 3 columns: subject, body_text, body_html
ALTER TABLE qu_g_mails ADD FULLTEXT ft_qu_g_mails1 (subject, body_text, body_html);
|
Database table is filled with about 150MB of emails, I'm not able to provide these data
Here are server settings:
[mysqld]
|
server-id=3 |
datadir=/opt/mysql/
|
socket=/var/lib/mysql/mysql.sock
|
tmpdir=/tmp/
|
|
|
log_bin=mysql-bin
|
expire_logs_days=4 |
|
|
wait_timeout=60 |
|
|
long_query_time=1 |
slow_query_log=1 |
slow_query_log_file=/opt/log/slow.log
|
log_output=TABLE
|
|
|
userstat = 1 |
|
|
user=root
|
symbolic-links=0 |
binlog_format=STATEMENT
|
|
|
default_storage_engine=InnoDB
|
|
|
slave_skip_errors=1062,1396,1690 |
|
|
innodb_autoinc_lock_mode=2 |
|
|
innodb_buffer_pool_size=14G
|
innodb_buffer_pool_instances=10 |
innodb_log_file_size=1G
|
innodb_log_buffer_size=196M
|
innodb_flush_log_at_trx_commit=1 |
innodb_thread_concurrency=24 |
innodb_file_per_table
|
innodb_write_io_threads=24 |
innodb_read_io_threads=24 |
innodb_sched_priority_cleaner=39 |
innodb_adaptive_flushing=1 |
innodb_purge_threads=5 |
innodb_adaptive_hash_index_partitions=64 |
innodb_flush_neighbors=0 |
innodb_flush_method=O_DIRECT
|
innodb_io_capacity=5000 |
innodb_io_capacity_max=8000 |
innodb_lru_scan_depth=1024 |
innodb_sort_buffer_size=32M
|
innodb_ft_cache_size=80M
|
innodb_ft_total_cache_size=1G
|
|
|
|
|
|
|
slave_parallel_threads=10 |
log_slave_updates=on
|
|
|
performance_schema=off
|
|
|
skip-name-resolve
|
|
|
max_allowed_packet = 512M
|
|
|
query_cache_type=1 |
query_cache_size = 0 |
query_cache_limit = 1M
|
query_cache_min_res_unit=1K
|
max_connections = 900 |
|
|
table_open_cache=64K
|
innodb_open_files=64K
|
open_files_limit=1020000 |
collation-server = utf8_general_ci
|
character-set-server = utf8
|
|
|
log-error=/opt/log/error.log
|
|
|
[mysqld_safe]
|
log-error=/opt/log/error.log
|
pid-file=/var/run/mysqld/mysqld.pid
|
malloc-lib=/usr/lib64/libjemalloc.so.1 |
|
after closer investigation I have found, that the crash was caused by the replication of SQL:
Query: 'ALTER TABLE qu_la_contacts ADD FULLTEXT ft_qu_la_contacts_groups (groups)'
table has more than 1GB and more than few millions rows.