Details
-
Bug
-
Status: Closed (View Workflow)
-
Minor
-
Resolution: Fixed
-
10.1.13
-
None
-
>$ uname -a
Linux <hostname removed in bug report> 2.6.32-431.23.3.el6.x86_64 #1 SMP Thu Jul 31 17:20:51 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
Description
I have a script running through and deleting rows a fairly large table ( ~150 GB ) on a day - by - day.. there's around 90-150k+ rows per day (to be clear, its a delete .. between StartDay and EndDay kind of query)
My particular problem is that I'm also trying to restore a different table in the same DB, and the restore keeps failing. Could be related.
I noticed the infamous:
ERROR 2013 (HY000) at line 18594: Lost connection to MySQL server during query
|
In both cases.
In that script, occasionally, and now I'm doing a load of a large table (same DB, different table) I dumped (using mysqldump, default options), truncated, and would now like to restore, and I get the same error. max_allowed_packet is set to 128 MB, and also, I just dumped this table, and settings have not changed since the data was inserted - so weird that mysqldump could generate things that you cannot re-insert. So, I went to the logs:
Looking through the logs I noticed this stack trace appearing periodically (note in this, and other logs, I replaced some stuff with <> because I didn't want it public):
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: Block in space_id 0 in file /var/lib/mysql/ibdata1 encrypted.
|
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: However key management plugin or used key_id 359 is not found or used encryption algorithm or method does not match.
|
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: Marking tablespace as missing. You may drop this table or install correct key management plugin and key file.
|
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: Block in space_id 0 in file /var/lib/mysql/ibdata1 encrypted.
|
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: However key management plugin or used key_id 359 is not found or used encryption algorithm or method does not match.
|
2017-01-28 0:40:20 139757855127296 [ERROR] InnoDB: Marking tablespace as missing. You may drop this table or install correct key management plugin and key file.
|
2017-01-28 00:40:20 7f1be94f3700 InnoDB: Assertion failure in thread 139757855127296 in file buf0buf.cc line 4803
|
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.
|
170128 0:40:20 [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.13-MariaDB
|
key_buffer_size=1048576
|
read_buffer_size=1048576
|
max_used_connections=159
|
max_threads=1002
|
thread_count=137
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3099672 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x0x7f1bdd23f008
|
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 = 0x7f1be94f2d40 thread_stack 0x40000
|
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7f208977ee0b]
|
/usr/sbin/mysqld(handle_fatal_signal+0x475)[0x7f20892df055]
|
/lib64/libpthread.so.0(+0x39f3c0f710)[0x7f20888e5710]
|
/lib64/libc.so.6(gsignal+0x35)[0x7f2086d0d625]
|
/lib64/libc.so.6(abort+0x175)[0x7f2086d0ee05]
|
/usr/sbin/mysqld(+0x87d188)[0x7f2089592188]
|
/usr/sbin/mysqld(+0x894c68)[0x7f20895a9c68]
|
/usr/sbin/mysqld(+0x89577f)[0x7f20895aa77f]
|
/usr/sbin/mysqld(+0x874a6f)[0x7f2089589a6f]
|
/usr/sbin/mysqld(+0x8f5e50)[0x7f208960ae50]
|
/usr/sbin/mysqld(+0x841953)[0x7f2089556953]
|
/usr/sbin/mysqld(+0x845c99)[0x7f208955ac99]
|
/usr/sbin/mysqld(+0x854075)[0x7f2089569075]
|
/usr/sbin/mysqld(+0x74fbf7)[0x7f2089464bf7]
|
/usr/sbin/mysqld(+0x753545)[0x7f2089468545]
|
/usr/sbin/mysqld(+0x850bd8)[0x7f2089565bd8]
|
/usr/sbin/mysqld(+0x7ecacd)[0x7f2089501acd]
|
/usr/sbin/mysqld(+0x7f6438)[0x7f208950b438]
|
/usr/sbin/mysqld(+0x7faa02)[0x7f208950fa02]
|
/usr/sbin/mysqld(+0x7da48c)[0x7f20894ef48c]
|
/usr/sbin/mysqld(+0x7c654c)[0x7f20894db54c]
|
/usr/sbin/mysqld(+0x7c8ae0)[0x7f20894ddae0]
|
/usr/sbin/mysqld(+0x7f5979)[0x7f208950a979]
|
/usr/sbin/mysqld(+0x7fa1b1)[0x7f208950f1b1]
|
/usr/sbin/mysqld(+0x7fa973)[0x7f208950f973]
|
/usr/sbin/mysqld(+0x7d98e3)[0x7f20894ee8e3]
|
/usr/sbin/mysqld(+0x728747)[0x7f208943d747]
|
/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f20892e8ecf]
|
/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f20893f2eaf]
|
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f20891735f1]
|
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f208917590d]
|
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f208917856b]
|
/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f2089178b1b]
|
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f20892344af]
|
/usr/sbin/mysqld(handle_one_connection+0x47)[0x7f2089234607]
|
/lib64/libpthread.so.0(+0x39f3c079d1)[0x7f20888dd9d1]
|
/lib64/libc.so.6(clone+0x6d)[0x7f2086dc38fd]
|
|
|
Trying to get some variables.
|
Some pointers may be invalid and cause the dump to abort.
|
Query (0x7f1c06876020): is an invalid pointer
|
Connection ID (thread ID): 30164
|
Status: NOT_KILLED
|
|
|
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
|
|
|
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.
|
170128 00:40:20 mysqld_safe Number of processes running now: 0
|
170128 00:40:20 mysqld_safe mysqld restarted
|
2017-01-28 0:40:20 139979614677024 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
|
2017-01-28 0:40:20 139979614677024 [Warning] options --log-slow-admin-statements, --log-queries-not-using-indexes and --log-slow-slave-statements have no effect if --log_slow_queries is not set
|
2017-01-28 0:40:20 139979614677024 [Note] /usr/sbin/mysqld (mysqld 10.1.13-MariaDB) starting as process 28049 ...
|
2017-01-28 0:40:20 139979614677024 [Note] Using unique option prefix 'myisam_recover' is error-prone and can break in the future. Please use the full name 'myisam-recover-options' instead.
|
2017-01-28 00:40:20 7f4f8b356820 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: The InnoDB memory heap is disabled
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Memory barrier is not used
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Using Linux native AIO
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Using SSE crc32 instructions
|
2017-01-28 0:40:20 139979614677024 [Note] InnoDB: Initializing buffer pool, size = 16.0G
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Completed initialization of buffer pool
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2400612224831
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Database was not shutdown normally!
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Starting crash recovery.
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Reading tablespace information from the .ibd files...
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: Restoring possible half-written data pages
|
2017-01-28 0:40:21 139979614677024 [Note] InnoDB: from the doublewrite buffer...
|
InnoDB: Doing recovery: scanned up to log sequence number 2400617467392
|
InnoDB: Doing recovery: scanned up to log sequence number 2400622710272
|
[
|
.... removed a long sequence of these from the bug report, for conciseness
|
]
|
InnoDB: Doing recovery: scanned up to log sequence number 2400633196032
|
InnoDB: Doing recovery: scanned up to log sequence number 2400643681792
|
InnoDB: Doing recovery: scanned up to log sequence number 2400654167552
|
nnoDB: Doing recovery: scanned up to log sequence number 2402258488832
|
InnoDB: Doing recovery: scanned up to log sequence number 2402263731712
|
InnoDB: Doing recovery: scanned up to log sequence number 2402264584622
|
InnoDB: 6 transaction(s) which must be rolled back or cleaned up
|
InnoDB: in total 986008 row operations to undo
|
InnoDB: Trx id counter is 933044992
|
2017-01-28 0:40:39 139979614677024 [Note] InnoDB: Starting an apply batch of log records to the database...
|
InnoDB: Progress in percent: 0 1 2 3 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 81485718, file name /var/lib/mysql/mysql-bin.001936
|
InnoDB: Starting in background the rollback of uncommitted transactions
|
2017-01-28 0:40:59 139979614677024 [Note] InnoDB: 128 rollback segment(s) are active.
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933044670, 3 rows to undo
|
2017-01-28 0:40:59 139979614677024 [Note] InnoDB: Waiting for purge to start
|
2017-01-28 0:40:59 139960078300928 [Note] InnoDB: Rollback of trx with id 933044670 completed
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933044663, 1 rows to undo
|
2017-01-28 0:40:59 139960078300928 [Note] InnoDB: Rollback of trx with id 933044663 completed
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933044662, 1 rows to undo
|
2017-01-28 0:40:59 139960078300928 [Note] InnoDB: Rollback of trx with id 933044662 completed
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933044661, 1 rows to undo
|
2017-01-28 0:40:59 139960078300928 [Note] InnoDB: Rollback of trx with id 933044661 completed
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933044660, 1 rows to undo
|
2017-01-28 0:40:59 139960078300928 [Note] InnoDB: Rollback of trx with id 933044660 completed
|
2017-01-28 00:40:59 7f4afebff700 InnoDB: Rolling back trx with id 933034392, 986001 rows to undo
|
|
|
InnoDB: Progress in percents: 12017-01-28 0:40:59 139979614677024 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.28-76.1 started; log sequence number 2402264584622
|
2 3 4 5 6 7 8 9 10 112017-01-28 0:42:23 139959778379520 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
2017-01-28 0:42:23 139979614677024 [Note] Plugin 'FEEDBACK' is disabled.
|
2017-01-28 0:42:23 139979614677024 [Note] Recovering after a crash using /var/lib/mysql/mysql-bin
|
2017-01-28 0:42:24 139979614677024 [Note] Starting crash recovery...
|
2017-01-28 0:42:24 139979614677024 [Note] Crash recovery finished.
|
2017-01-28 0:42:24 139979614677024 [Note] Server socket created on IP: '::'.
|
2017-01-28 0:42:24 139979614677024 [Note] Reading of all Master_info entries succeded
|
2017-01-28 0:42:24 139979614677024 [Note] Added new Master_info '' to hash table
|
2017-01-28 0:42:24 139979614677024 [Note] /usr/sbin/mysqld: ready for connections.
|
Version: '10.1.13-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
|
12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 352017-01-28 0:43:20 139959712200448 [Note] Start binlog_dump to slave_server(994593286), pos(mysql-bin.001936, 81485718)
|
2017-01-28 0:43:20 139959712466688 [Note] Start binlog_dump to slave_server(511624938), pos(mysql-bin.001936, 81485718)
|
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 832017-01-28 0:44:32 139979614136064 [Warning] Aborted connection 13 to db: '<>' user: '<>' host: '<>org' (Unknown error)
|
84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 1002017-01-28 0:44:55 139960078300928 [Note] InnoDB: Rollback of trx with id 933034392 completed
|
2017-01-28 00:44:55 7f4afebff700 InnoDB: Rollback of non-prepared transactions completed
|
2017-01-28 0:46:23 139959679309568 [Warning] IP address '10.7.50.19' could not be resolved: Name or service not known
|
2017-01-28 0:48:21 139959702611712 [Warning] Aborted connection 579 to db: '<removed for bug report>' user: '<removed for bug report>' host: '<removed for bug report>.org' (Unknown error)
|
To give you an idea of how it's repeating, I grepped:
$ grep -Hinr "/usr/sbin/mysqld(_Z" mysqld-error.log
|
mysqld-error.log:91354:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7fef6b633ecf]
|
mysqld-error.log:91355:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7fef6b73deaf]
|
mysqld-error.log:91356:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7fef6b4be5f1]
|
mysqld-error.log:91357:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7fef6b4c090d]
|
mysqld-error.log:91358:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7fef6b4c356b]
|
mysqld-error.log:91359:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7fef6b4c3b1b]
|
mysqld-error.log:91360:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7fef6b57f4af]
|
mysqld-error.log:95885:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7fc2c8a85ecf]
|
mysqld-error.log:95886:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7fc2c8b8feaf]
|
mysqld-error.log:95887:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7fc2c89105f1]
|
mysqld-error.log:95888:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7fc2c891290d]
|
mysqld-error.log:95889:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7fc2c891556b]
|
mysqld-error.log:95890:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7fc2c8915b1b]
|
mysqld-error.log:97544:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f9f422b1ecf]
|
mysqld-error.log:97545:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f9f423bbeaf]
|
mysqld-error.log:97546:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f9f4213c5f1]
|
mysqld-error.log:97547:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f9f4213e90d]
|
mysqld-error.log:97548:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f9f4214156b]
|
mysqld-error.log:97549:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f9f42141b1b]
|
mysqld-error.log:97550:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f9f421fd4af]
|
mysqld-error.log:98399:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f1dc3798ecf]
|
mysqld-error.log:98400:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f1dc38a2eaf]
|
mysqld-error.log:98401:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f1dc36235f1]
|
mysqld-error.log:98402:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f1dc362590d]
|
mysqld-error.log:98403:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f1dc362856b]
|
mysqld-error.log:98404:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f1dc3628b1b]
|
mysqld-error.log:98405:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f1dc36e44af]
|
mysqld-error.log:99373:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f3ce0493ecf]
|
mysqld-error.log:99374:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f3ce059deaf]
|
mysqld-error.log:99375:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f3ce031e5f1]
|
mysqld-error.log:99376:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f3ce032090d]
|
mysqld-error.log:99377:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f3ce032356b]
|
mysqld-error.log:99378:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f3ce0323b1b]
|
mysqld-error.log:99379:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f3ce03df4af]
|
mysqld-error.log:99906:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f34e4ffdecf]
|
mysqld-error.log:99907:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f34e5107eaf]
|
mysqld-error.log:99908:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f34e4e885f1]
|
mysqld-error.log:99909:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f34e4e8a90d]
|
mysqld-error.log:99910:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f34e4e8d56b]
|
mysqld-error.log:99911:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f34e4e8db1b]
|
mysqld-error.log:99912:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f34e4f494af]
|
mysqld-error.log:100713:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f0004453ecf]
|
mysqld-error.log:100714:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f000455deaf]
|
mysqld-error.log:100715:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f00042de5f1]
|
mysqld-error.log:100716:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f00042e090d]
|
mysqld-error.log:100717:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f00042e356b]
|
mysqld-error.log:101089:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f5287e28ecf]
|
mysqld-error.log:101090:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f5287f32eaf]
|
mysqld-error.log:101091:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f5287cb35f1]
|
mysqld-error.log:101092:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f5287cb590d]
|
mysqld-error.log:101093:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f5287cb856b]
|
mysqld-error.log:101094:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f5287cb8b1b]
|
mysqld-error.log:101095:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f5287d744af]
|
mysqld-error.log:101560:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f5f3cb0decf]
|
mysqld-error.log:101561:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f5f3cc17eaf]
|
mysqld-error.log:101562:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f5f3c9985f1]
|
mysqld-error.log:101563:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f5f3c99a90d]
|
mysqld-error.log:101564:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f5f3c99d56b]
|
mysqld-error.log:101565:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f5f3c99db1b]
|
mysqld-error.log:101566:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f5f3ca594af]
|
mysqld-error.log:101928:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7fc4865a2ecf]
|
mysqld-error.log:101929:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7fc4866aceaf]
|
mysqld-error.log:101930:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7fc48642d5f1]
|
mysqld-error.log:101931:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7fc48642f90d]
|
mysqld-error.log:101932:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7fc48643256b]
|
mysqld-error.log:101933:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7fc486432b1b]
|
mysqld-error.log:101934:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7fc4864ee4af]
|
mysqld-error.log:102395:/usr/sbin/mysqld(_ZN7handler13ha_delete_rowEPKh+0x23f)[0x7f20892e8ecf]
|
mysqld-error.log:102396:/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyyP13select_result+0x110f)[0x7f20893f2eaf]
|
mysqld-error.log:102397:/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x7061)[0x7f20891735f1]
|
mysqld-error.log:102398:/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x28d)[0x7f208917590d]
|
mysqld-error.log:102399:/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x243b)[0x7f208917856b]
|
mysqld-error.log:102400:/usr/sbin/mysqld(_Z10do_commandP3THD+0x16b)[0x7f2089178b1b]
|
mysqld-error.log:102401:/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x7f20892344af]
|
Memory usage seems OK whenever I check it:
$ free -m
|
total used free shared buffers cached
|
Mem: 64320 63968 352 0 140 43698
|
-/+ buffers/cache: 20129 44191
|
Swap: 4095 213 3882
|
No idea if all of my lost connections are related to the issue - but it does appear at least some of my lost connections are related to it.
Note that in the script doing the deletes, I have it looping and sleeping and retrying on failure:
2017-01-28 01:59:07.325604 Issue with query: 2003: Can't connect to MySQL server on '<>' (111) sleeping and trying again
|
Deleting 623366 from 2016-10-27 18:52:42.588751 to 2016-10-28 18:52:42.588751
|
|
|
2017-01-28 01:59:12.331931 Issue with query: 2003: Can't connect to MySQL server on '<>' (111) sleeping and trying again
|
Deleting 623366 from 2016-10-27 18:52:42.588751 to 2016-10-28 18:52:42.588751
|
|
|
2017-01-28 01:59:17.338245 Issue with query: 2003: Can't connect to MySQL server on '<>' (111) sleeping and trying again
|
In the try block, I open, get cursor, query, commit, close, so hopefully I'm not burning through connections or anything - it's a fairly straightforward python script. .... and I can make progress in the script, via retries, and just starting the script again.
However, since the dump keeps failing, I can't restore the data.
Attachments
Issue Links
- duplicates
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
(3 relates to)
Activity
Unless someone did something to the configuration that I don't know about, then, no, encryption is not enabled.
Attaching cnf shortly (some redaction may be necessary).
To confirm if this is a duplicate of MDEV-11759, we would need a copy of the page in ibdata1 that is wrongly reported as corrupted. The log messages do not clearly indicate the page number.
Maybe we could exploit MDEV-11939 to diagnose this. If we are lucky, the 10.1 innochecksum would flag the same page as corrupted. So, please run
innochecksum ibdata1 ibdata2
|
If it reports a page as corrupted, then we would want a copy of that page, with a command like this:
dd bs=16384 count=1 skip=PAGENUMBER if=ibdata1 of=pagePAGENUMBER.bin
|
innochecksum pagePAGENUMBER.bin
|
Replace PAGENUMBER with the incorrect page number. And as shown above, run innochecksum on the copy of the page to ensure that it is reported as corrupted.
If you think that the pages contain confidential data, we’d mostly be interested in the first 38 bytes:
od -Ax -t x1 -N 38 pagePAGENUMBER.bin
|
Using the command that I posted in MDEV-11939, I can make innochecksum accept these pages. This definitely is a duplicate of MDEV-11759.
The files should not contain any confidential data. ibdata1_page0.bin is page 0 of the system tablespace. It contains some metadata, such as the size of the tablespace in pages. In addition to that, like all pages whose page number is an integer multiple of innodb_page_size, it contains an allocation bitmap that tells which of the following innodb_page_size-1 pages are marked as allocated. The file ibdata2_page0.bin could contain any page number. In this case, the page number is 8192, and the page happens to be a mostly empty page of type FIL_PAGE_IBUF_FREE_LIST.
I have hit this too, but it seems to be encryption related. Here is the stack trace enhanced with addr2line.
gawk -F '[])([]' '{print $0 ; } /\(\+/ {system("/usr/bin/addr2line -pCfie " $1 " " substr($2,4))}' mysqld-stack.txt
|
/usr/sbin/mysqld(my_print_stacktrace+0x3a)[0x5564556e8c4a]
|
/usr/sbin/mysqld(handle_fatal_signal+0x30d)[0x55645513837d]
|
/lib64/libpthread.so.0(+0x11a30)[0x7f8063d2ba30]
|
funlockfile at ??:?
|
/lib64/libc.so.6(gsignal+0x3b)[0x7f806315632b]
|
/lib64/libc.so.6(abort+0x181)[0x7f80631579a1]
|
/usr/sbin/mysqld(+0xa9d949)[0x5564555f9949]
|
buf_page_io_complete(buf_page_t*) at :?
|
/usr/sbin/mysqld(+0xab5b05)[0x556455611b05]
|
buf_read_page_low(dberr_t*, bool, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long, trx_t*, buf_page_t**) at :?
|
/usr/sbin/mysqld(+0xab6cd7)[0x556455612cd7]
|
buf_read_page(unsigned long, unsigned long, unsigned long, trx_t*, buf_page_t**) at :?
|
/usr/sbin/mysqld(+0xa97c66)[0x5564555f3c66]
|
buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*, dberr_t*) at :?
|
/usr/sbin/mysqld(+0xb03935)[0x55645565f935]
|
fil_crypt_thread at :?
|
/lib64/libpthread.so.0(+0x765c)[0x7f8063d2165c]
|
__pthread_get_minstack at ??:?
|
/lib64/libc.so.6(clone+0x6d)[0x7f80632154fd]
|
And the logs / innodb data. Not that I am using encryption, but the database has never gone into production all that's been run on it is sql-bench and I'm more than happy to use new encryption keys and provide the innodb database files if requested as the is no privacy concerns at play.
Here's the last 400 or so lines from mysqld.err
Pastebin of mysqld.err
And here we go:
2017-03-25 22:47:14 7f7fd97fa700 InnoDB: Assertion failure in thread 140187086595840 in file buf0buf.cc line 4829
The other thing to note is this relates to the innodb_page_size.
When I had 32k it hit the error at 4096 - now I have 64k it hit the error at 2048.
2017-03-25 22:47:12 140187086595840 [ERROR] InnoDB: Database page corruption on disk or a failed
2017-03-25 22:47:12 140187086595840 [ERROR] InnoDB: Space 0 file /var/lib/mysql/ibdata1 read of page 2048.
Also this may be related to crc32 (the other user uses that - I'm now using innodb type checksums). If I was to change binlog checksums to crc32 down she goes within a minute. I can't even create databases with crc32.
I had some problems with cryptoapi on a VPS. using the cryptodev it was failing with hashes with openssl. That was after I did the supposed work around to limit the crytodev hash size to 64, so I recompiled openssl to only use aes from /dev/crypto not the hashes.
I'm using kernel 3.9 from sabayon-sources on gentoo/sabayon - latest version. Properly configured with only what you need for a VPS. The host has strange flags in CPU info - not the full Westerme set. So I guess I can provide my my.cnf and you can set up a qemu instance with only the same flags to replicate.
I might try 10.2 to see if mysql.com's innodb storage engine fairs any better. I have debug, non-stripped binary and system tap and I'm willing to help in any way I can to debug this.
My startup script adds the encryption unlocking secret to a very short lived file in tmpfs when mysqld starts, apart from that all the config I'm using is in there. I tried using O_DSYNC and fsync() for flushing method. It was failing on btrfs so I moved to ext4 data=journal. Ext4 data=journal warns not to use O_DIRECT - I don't know if that also applies to O_DSYNC, maybe you could confirm / deny.
processor : 3
|
vendor_id : GenuineIntel
|
cpu family : 6
|
model : 44
|
model name : Intel(R) Xeon(R) CPU X5650 @ 2.67GHz
|
stepping : 2
|
microcode : 0x1
|
cpu MHz : 2666.760
|
cache size : 4096 KB
|
physical id : 3
|
siblings : 1
|
core id : 0
|
cpu cores : 1
|
apicid : 3
|
initial apicid : 3
|
fpu : yes
|
fpu_exception : yes
|
cpuid level : 11
|
wp : yes
|
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss syscall nx pdpe1gb lm constant_tsc arch_perfmon nopl eagerfpu pni pclmulqdq ssse3 cx16 pcid sse4_1 sse4_2 x2apic popcnt aes hypervisor lahf_lm
|
bugs :
|
bogomips : 5335.75
|
clflush size : 64
|
cache_alignment : 64
|
address sizes : 40 bits physical, 48 bits virtual
|
power management:
|
|
The encryption in MariaDB 10.1 suffered from several design problems, most of which I believe were fixed in MariaDB 10.1.23. Can you repeat these problems with that version?
First of all, are you using encryption? Could you perhaps attach your my.cnf file?
There are some other bugs showing that MariaDB encryption sometimes mistakes encrypted tablespaces for clear-text or vice versa.
In this case, it seems that XtraDB is noticing corruption of the system tablespace (tablespace 0):
if (bpage->space > TRX_SYS_SPACE) {if (corrupted) {buf_mark_space_corrupt(bpage);}} else {ut_error;}Following the code flow, it appears that corrupted=FALSE.
I cannot see other than some cosmetic changes to this function buf_page_io_complete() between 10.1.13 and the latest release 10.1.21. But, maybe there have been other fixes to the encryption code.