MySQL Bugs: #96384: MySQL Crash with Assertion failure in file trx0trx.ic

Bug #96384	MySQL Crash with Assertion failure in file trx0trx.ic
Submitted:	31 Jul 2019 10:39	Modified:	23 Sep 2019 16:13
Reporter:	Stephan Järmann	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server	Severity:	S2 (Serious)
Version:	5.7.26	OS:	Ubuntu (16.04.6)
Assigned to:		CPU Architecture:	Any

Description:
We are seeing crashes with this issue since version 5.7.22 (See comment from former colleague Beat Vontobel here: https://bugs.mysql.com/bug.php?id=88757). We updated to 5.7.26 last week and it still occurs. Do you have any idea how to further investigate this? Any input is greatly appreciated.

2019-07-29 09:45:13 0x7f3af6083700  InnoDB: Assertion failure in thread 139891212564224 in file trx0trx.ic line 213
InnoDB: Failing assertion: !trx->has_search_latch
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:45:13 UTC - 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.
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.

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

Thread pointer: 0x7f3b1c886f20
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 = 7f3af6082e70 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xe9510b]
/usr/sbin/mysqld(handle_fatal_signal+0x489)[0x78ad29]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f3e492aa390]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38)[0x7f3e48663428]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f3e4866502a]
/usr/sbin/mysqld[0x7605dc]
/usr/sbin/mysqld(_Z21innobase_rename_tableP3THDP5trx_tPKcS4_+0x0)[0xede120]
/usr/sbin/mysqld(_ZN11ha_innobase8end_stmtEv+0xf7)[0xeceb67]
/usr/sbin/mysqld(_Z18close_thread_tableP3THDPP5TABLE+0x2b1)[0xbf2591]
/usr/sbin/mysqld(_Z19close_thread_tablesP3THD+0x31b)[0xbf2c7b]
/usr/sbin/mysqld(_ZN18Prepared_statement7prepareEPKcm+0x724)[0xc7fc64]
/usr/sbin/mysqld(_Z19mysqld_stmt_prepareP3THDPKcj+0xf0)[0xc80dc0]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x190c)[0xc5672c]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1c7)[0xc57307]
/usr/sbin/mysqld(handle_connection+0x290)[0xd19880]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x11b4be4]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f3e492a06ba]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f3e4873541d]

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

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.
2019-07-29T09:45:15.448002Z 0 [Warning] The syntax '--log_warnings/-W' is deprecated and will be removed in a future release. Please use '--log_error_verbosity' instead.
2019-07-29T09:45:15.448121Z 0 [Warning] options --log-slow-admin-statements, --log-queries-not-using-indexes and --log-slow-slave-statements have no effect if --slow-query-log is not set
2019-07-29T09:45:15.448128Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-07-29T09:45:15.448133Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
2019-07-29T09:45:15.466673Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.26-0ubuntu0.16.04.1) starting as process 15254 ...

How to repeat:
Unfortunately not reproducible.

Hello Mr. Jarmann,

Thank you for your bug report.

However, we can not conclude much from what you have sent us. Not only that stacktrace is not enough, but also, in that part of code, many inline functions are called.

There are two things that you can do for us.

First, when you run RENAME TABLE, or ALTER statement that renames table, please try to use ALGORITHM=COPY and see if the problem is recurring ........

Second, if the problem is recurring, can you try using our debug binary (which should be a part of the package) and then let us know when you obtain a core file. You should enable your OS to dump core on assert. Instructions on that issue are in our Reference Manual.

Thanks in advance.

Thanks a lot for your reply.

Unfortunately we cannot change our queries to ALGORITHM=COPY. Our DB-Specialist says that it would cause delays and possible interruptions in our production environment and connected services.

Using a debug-binary is also quite difficult, if not possible at all, because it's a production environment that is  heavily used by many systems.

Can we do anything else to produce some meaningful information for you?

Kind regards

Stephan

Hi Mr. Jarmann,

There are three things that you could do for us.

First two are the ones that I already asked for.

Third one would be much better then any of the the other two. Please, provide us with a fully repeatable test case that will always lead to the crash that you describe.

Thanks in advance.

No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".

This assertion has been seen again on 5.7.31.   However,  Bug 30594501 is fixed in 5.7.32, so it might be possible solution.  We'll have to see, as it is very hard to repeat.  Please try 5.7.32 or 5.7.33.

Thank you, Shane .....