Crash : Invalid Pointer in Audit Log Plugin

Bug #1625266 reported by CJ
8
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

We have seen three servers over the last week consistently crash a few times a day. These are the first servers we have put in production using Percona 5.7. We have the latest 5.7.14-7 installed on OEL6.

On each server when we disabled the audit log plugin, the regular crashing stopped completely.

In both cases, we observed a table rename query in the state "Waiting for table metadata lock" while a large INSERT SELECT query ran in another thread. It seems like when the select completed,
the server crashed. In most cases it came back up quickly after a short innodb log rollback.

# uname -r
3.8.13-118.4.2.el6uek.x86_64

Error Log:

18:44:39 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=2147483648
read_buffer_size=131072
max_used_connections=20
max_threads=201
thread_count=4
connection_count=4
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2176773 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f0b7c0126e0
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 = 7f0c61db1d40 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xec6b8c]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x79dba1]
/lib64/libpthread.so.0[0x345320f7e0]
/usr/lib64/mysql/plugin/audit_log.so(+0x6213)[0x7f0c70422213]
/usr/lib64/mysql/plugin/audit_log.so(+0x67b5)[0x7f0c704227b5]
/usr/lib64/mysql/plugin/audit_log.so(+0x695f)[0x7f0c7042295f]
/usr/sbin/mysqld[0x79dd93]
/usr/sbin/mysqld(_Z18mysql_audit_notifyP3THD30mysql_event_general_subclass_tiPKcm+0x1f4)[0x79e314]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x3ae)[0xcac2ee]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1b7)[0xcae207]
/usr/sbin/mysqld(handle_connection+0x2a0)[0xd6fd00]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0xede504]
/lib64/libpthread.so.0[0x3453207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3452ee8aad]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f0b7f73f4a0): is an invalid pointer
Connection ID (thread ID): 2494
Status: NOT_KILLED

Audit Log Config:

# AUDIT LOG #
plugin-load = "audit_log=audit_log.so"
audit_log_file = /logs/mysql/audit.log
audit_log_format = "NEW"
audit_log_rotate_on_size = 1G
audit_log_rotations = 5

Tags: audit
tags: added: audit
Revision history for this message
Sergei Glushchenko (sergei.glushchenko) wrote :

Hi,

Stack trace is not resolved, so it is difficult to say where exactly in the plugin crash happened. Can you post the query which you suspect caused the crash?

Revision history for this message
CJ (rcj1) wrote :

It's hard to say which specific query caused the crash. It appears that the queries we observed running on the server did not make it to the log.

From our memory there were two queries:

1. INSERT SELECT from a table a -- in a 'sending data' state
2. RENAME TABLE a to a_2, a_old to a, a_2 to a_old - waiting for the first query to finish

It appeared that as soon as the first query finished, the 2nd query did not run. When the system came back online the tables had not appeared to rotate through

Revision history for this message
CJ (rcj1) wrote :

Over the weekend we updated our 5.6.31 servers to 5.6.32. Subsequently we started seeing this same crash behavior.

Were there any changes to the audit log that went into both codebases?

Revision history for this message
Sergei Glushchenko (sergei.glushchenko) wrote :

Do you happen to use SET STATEMENT ... FOR ... syntax? There is a confirmed crashing bug 1626519 when SET STATEMENT used with audit log turned on.

Revision history for this message
CJ (rcj1) wrote :

No SET statements in our query.

If there are some additional parameters I can include to provide more verbose output to help troubleshoot, I'm happy to re-enable the audit log and send crash logs when it crashes.

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-3562

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.