Skip to content

Error "Too many arguments (first extra is 'file')" when log file has null pointers #410

Closed
@hadret

Description

@hadret

Hello 👋🏻

Recently we encountered a rather unpleasant edge case when one of nodes received non-graceful reboot. It tried to re-join the cluster, but was looping in the error log with the following message:

[...]
2023-02-03T11:58:39.629737Z 0 [ERROR] [MY-010147] [Server] Too many arguments (first extra is 'file').
2023-02-03T11:58:39.630568Z 0 [ERROR] [MY-010119] [Server] Aborting
terminate called after throwing an instance of 'wsrep::runtime_error'
  what():  State wait was interrupted
11:58:41 UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
Thread pointer: 0x7fc730004900
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 = 7fc74d949b58 thread_stack 0x100000
/usr/sbin/mysqld(my_print_stacktrace(unsigned char const*, unsigned long)+0x41) [0x5616ca5a3cd1]
/usr/sbin/mysqld(handle_fatal_signal+0x313) [0x5616c93f2e43]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x143c0) [0x7fc85cf2a3c0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb) [0x7fc85c60203b]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x12b) [0x7fc85c5e1859]
/lib/x86_64-linux-gnu/libstdc++.so.6(+0x9e911) [0x7fc85c9b9911]
/lib/x86_64-linux-gnu/libstdc++.so.6(+0xaa38c) [0x7fc85c9c538c]
/lib/x86_64-linux-gnu/libstdc++.so.6(+0xaa3f7) [0x7fc85c9c53f7]
/lib/x86_64-linux-gnu/libstdc++.so.6(+0xaa6a9) [0x7fc85c9c56a9]
/usr/sbin/mysqld(+0xf0501e) [0x5616c913f01e]
/usr/sbin/mysqld(wsrep::server_state::sst_received(wsrep::client_service&, int)+0xf55) [0x5616cad18645]
/usr/sbin/mysqld(+0x11e2ab6) [0x5616c941cab6]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8609) [0x7fc85cf1e609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7fc85c6de163]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0): Connection ID (thread ID): 3
Status: NOT_KILLED

The manual page at [http://dev.mysql.com/doc/mysql/en/crashing.html](http://dev.mysql.com/doc/mysql/en/crashing.html) contains
information that should help you find out what is causing the crash.
[...]

Long story short, it's because GNU grep tries to be clever sometimes with discovering file type and it was treating /var/log/mysql/error.log as a binary — simply because there were null pointers in that file (^@). When it does that, the last line it's printing is "Binary file /var/log/mysql/error.log matches", which is then passed to mysql --wsrep_start_position= on start.

I wrote a little bit more about that subject here: https://chabik.com/galera-cluster-and-mysql-signal-6-loop/

I have tiny fix for this and from what I can tell it affects all versions 5.7+ (for us it was 8.0.27). I couldn't find publicly available repository/branch for 8.0+ so I'll create PR against 5.7 branch in this repository.

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions