Mysql Crashed and recovered automatically

Bug #1680267 reported by Murugiah A
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server moved to https://jira.percona.com/projects/PS
New
Undecided
Unassigned

Bug Description

Here's the log file during the crash and recovery. There was a brief period of 9 minutes where this database was not accessible.

I've attached the conf file and log file while the crash recovery happened is provided below. Let me know in case you need more details.

20:24:50 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=1073741824
read_buffer_size=1048576
max_used_connections=372
max_threads=3026
thread_count=152
connection_count=152
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 7287724 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x31fbff0
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...
170405 13:33:15 mysqld_safe Number of processes running now: 0
170405 13:33:15 mysqld_safe mysqld restarted
2017-04-05 13:33:15 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-04-05 13:33:15 0 [Warning] 'ERROR_FOR_DIVISION_BY_ZERO' is deprecated and will be removed in a future release.
2017-04-05 13:33:15 0 [Warning] 'NO_ZERO_DATE' is deprecated and will be removed in a future release.
2017-04-05 13:33:15 0 [Warning] 'NO_ZERO_IN_DATE' is deprecated and will be removed in a future release.
2017-04-05 13:33:15 0 [Note] /usr/sbin/mysqld (mysqld 5.6.32-78.0-log) starting as process 4793 ...
2017-04-05 13:33:15 4793 [Warning] Buffered warning: Changed limits: max_open_files: 6000 (requested 15125)

2017-04-05 13:33:15 4793 [Note] Plugin 'FEDERATED' is disabled.
2017-04-05 13:33:15 4793 [Warning] option 'audit-json-file-bufsize': signed value 0 adjusted to 1
2017-04-05 13:33:15 4793 [Warning] option 'plugin-audit-json-file-bufsize': signed value 0 adjusted to 1
2017-04-05 13:33:15 7f84ea33b7e0 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-04-05 13:33:15 7f84ea33b7e0 InnoDB: Warning: Using innodb_locks_unsafe_for_binlog is DEPRECATED. This option may be removed in future releases. Please use READ COMMITTED transaction isolation level instead, see http://dev.mysql.com/doc/refman/5.6/en/set-transaction.html.
2017-04-05 13:33:15 4793 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-04-05 13:33:15 4793 [Note] InnoDB: The InnoDB memory heap is disabled
2017-04-05 13:33:15 4793 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-04-05 13:33:15 4793 [Note] InnoDB: Memory barrier is not used
2017-04-05 13:33:15 4793 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-04-05 13:33:15 4793 [Note] InnoDB: Using Linux native AIO
2017-04-05 13:33:15 4793 [Note] InnoDB: Using CPU crc32 instructions
2017-04-05 13:33:15 4793 [Note] InnoDB: Initializing buffer pool, size = 100.0G
2017-04-05 13:33:18 4793 [Note] InnoDB: Completed initialization of buffer pool
2017-04-05 13:33:18 4793 [Note] InnoDB: Highest supported file format is Barracuda.
2017-04-05 13:33:18 4793 [Note] InnoDB: The log sequence numbers 126035939180329 and 126035939180329 in ibdata files do not match the log sequence number 132712113998484 in the ib_logfiles!
2017-04-05 13:33:18 4793 [Note] InnoDB: Database was not shutdown normally!
2017-04-05 13:33:18 4793 [Note] InnoDB: Starting crash recovery.
2017-04-05 13:33:18 4793 [Note] InnoDB: Reading tablespace information from the .ibd files...
2017-04-05 13:33:19 4793 [Note] InnoDB: Restoring possible half-written data pages
2017-04-05 13:33:19 4793 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Last MySQL binlog file position 0 8805341, file name binlog.000291
2017-04-05 13:33:22 4793 [Note] InnoDB: 128 rollback segment(s) are active.
2017-04-05 13:33:22 4793 [Note] InnoDB: Waiting for purge to start
2017-04-05 13:33:22 4793 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.32-78.0 started; log sequence number 132712113998484
2017-04-05 13:33:22 4793 [Note] Audit Plugin: starting up. Version: 1.0.9 , Revision: 585 (64bit). AUDIT plugin interface version: 769 (0x301). MySQL Server version: 5.6.32-78.0-log.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: setup_offsets audit_offsets: 7704, 7760, 4392, 5032, 88, 2720, 96, 0, 32, 104, 152, 7880 validate_checksum: 0 offsets_by_version: 1
2017-04-05 13:33:22 4793 [Note] Audit Plugin: mysqld: /usr/sbin/mysqld (db841c1052b94a80765dd73881b84948)
2017-04-05 13:33:22 4793 [Note] Audit Plugin: setup_offsets Audit_formatter::thd_offsets values: 7704 7760 4392 5032 88 2720 96 0 32 104 152 7880
2017-04-05 13:33:22 4793 [Note] Audit Plugin: extended offsets validate res: MySQL thread id 123456, OS thread handle 0x0, query id 789 aud_tusr
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Validation passed. Using offsets from audit_offsets: 7704, 7760, 4392, 5032, 88, 2720, 96, 0, 32, 104, 152, 7880
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set whitelist_cmds num: 2, value: BEGIN,COMMIT
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set record_cmds num: 4, value: alter,truncate,drop,create
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set record_objs num: 0, value:
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set record_empty_objs: 1
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set password_masking_cmds num: 7, value: CREATE_USER,GRANT,SET_OPTION,SLAVE_START,CREATE_SERVER,ALTER_SERVER,CHANGE_MASTER
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Compile password_masking_regex res: [0]
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set password_masking_regex value: [identified(?:/\*.*?\*/|\s)*?by(?:/\*.*?\*/|\s)*?(?:password)?(?:/\*.*?\*/|\s)*?['|"](?<psw>.*?)(?<!\\)['|"]|password(?:/\*.*?\*/|\s)*?\((?:/\*.*?\*/|\s)*?['|"](?<psw>.*?)(?<!\\)['|"](?:/\*.*?\*/|\s)*?\)|password(?:/\*.*?\*/|\s)*?(?:for(?:/\*.*?\*/|\s)*?\S+?)?(?:/\*.*?\*/|\s)*?=(?:/\*.*?\*/|\s)*?['|"](?<psw>.*?)(?<!\\)['|"]|password(?:/\*.*?\*/|\s)*?['|"](?<psw>.*?)(?<!\\)['|"]]
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Set json_socket_name str: [] value: [/tmp/mysql.audit__var_lib_mysql_cachecluster3_4901]
2017-04-05 13:33:22 4793 [Note] Audit Plugin: bufsize for file [/var/lib/mysql/auditlog/mysql-audit.json]: 1. Value of json_file_bufsize: 1.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: success opening file: /var/lib/mysql/auditlog/mysql-audit.json.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: mem func addr: 0x7f84a3d86260 mem start addr: 0x7f84a3d87000 page size: 4096
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patching function: 0x6d9c80, trampolineFunction: 0x7f84a3d87000 trampolinePage: 0x7f84a3d87000
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patch for: mysql_execute_command (0x6d9c80) complete. Audit func: 0x7f84a3d89c80, Trampoline address: 0x7f84a3d87000 size: 16.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patching function: 0x69c680, trampolineFunction: 0x7f84a3d87020 trampolinePage: 0x7f84a3d87000
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patch for: send_result_to_client (0x69c680) complete. Audit func: 0x7f84a3d89560, Trampoline address: 0x7f84a3d87020 size: 15.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patching function: 0x6d5cc0, trampolineFunction: 0x7f84a3d87040 trampolinePage: 0x7f84a3d87000
2017-04-05 13:33:22 4793 [Note] Audit Plugin: hot patch for: open_tables (0x6951a0) complete. Audit func: 0x7f84a3d89270, Trampoline address: 0x7f84a3d87060 size: 15.
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Done initializing sql command names. status_vars_index: [152], com_status_vars: [0x11eccc0].
2017-04-05 13:33:22 4793 [Note] Audit Plugin: Init completed successfully.
2017-04-05 13:33:22 4793 [Note] Recovering after a crash using /var/log/mysql/cachecluster3/binlog/binlog
2017-04-05 13:33:22 4793 [Note] Starting crash recovery...
2017-04-05 13:33:22 4793 [Note] Crash recovery finished.
2017-04-05 13:33:22 4793 [Note] RSA private key file not found: /var/lib/mysql/cachecluster3//private_key.pem. Some authentication plugins will not work.
2017-04-05 13:33:22 4793 [Note] RSA public key file not found: /var/lib/mysql/cachecluster3//public_key.pem. Some authentication plugins will not work.
2017-04-05 13:33:22 4793 [Note] Server hostname (bind-address): '*'; port: 4901
2017-04-05 13:33:22 4793 [Note] IPv6 is available.
2017-04-05 13:33:22 4793 [Note] - '::' resolves to '::';
2017-04-05 13:33:22 4793 [Note] Server socket created on IP: '::'.
2017-04-05 13:33:22 4793 [Note] Event Scheduler: Loaded 0 events
2017-04-05 13:33:22 4793 [Note] /usr/sbin/mysqld: ready for connections.

Revision history for this message
Murugiah A (murugiah.a) wrote :
Revision history for this message
Murugiah A (murugiah.a) wrote :

OS is Linux - Kernel version 2.6 and mysql version is

mysql> select version();
+-----------------+
| version() |
+-----------------+
| 5.6.32-78.0-log |
+-----------------+
1 row in set (0.00 sec)

description: updated
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-3681

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.