proxysql 2.3.2 crash frequently

[Fanduzi]

Error: signal 11:
proxysql(_Z13crash_handleri+0x2a)[0x594b7a]
/lib64/libc.so.6(+0x36340)[0x7f3f93e5f340]
proxysql(unpack_field+0x6c)[0xa340ac]
proxysql(mthd_my_read_metadata_ex+0xac)[0xa353bc]
proxysql(mthd_my_read_query_result+0x14a)[0xa356ca]
proxysql[0xa4829b]
proxysql(my_context_spawn+0x41)[0xa4cf91]
 ---- proxysql(_Z13crash_handleri+0x2a) [0x594b7a] : crash_handler(int)
2022-08-18 15:25:08 main.cpp:1245:ProxySQL_daemonize_phase3(): [ERROR] ProxySQL crashed. Restarting!
2022-08-18 15:25:08 [INFO] ProxySQL version 2.3.2-10-g8cd66cf

warning: Could not load shared library symbols for C_CHECK_.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `proxysql --idle-threads --no-version-check -c /data/proxysql_6032/proxysql.cnf'.
Program terminated with signal 11, Segmentation fault.
#0  0x0000000000a340ac in unpack_field (mysql=mysql@entry=0x7f3f8b473a00, alloc=alloc@entry=0x7f3f8b473d00, default_value=default_value@entry=0 '\000', row=row@entry=0x7f3f8b5aef20, field=field@entry=0x7f3f857d0050)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:911
911     /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c: No such file or directory.
Missing separate debuginfos, use: debuginfo-install proxysql-2.3.2-1.x86_64
(gdb) where
#0  0x0000000000a340ac in unpack_field (mysql=mysql@entry=0x7f3f8b473a00, alloc=alloc@entry=0x7f3f8b473d00, default_value=default_value@entry=0 '\000', row=row@entry=0x7f3f8b5aef20, field=field@entry=0x7f3f857d0050)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:911
#1  0x0000000000a353bc in mthd_my_read_metadata_ex (mysql=mysql@entry=0x7f3f8b473a00, mem_root=mem_root@entry=0x7f3f8b473d00, field_count=field_count@entry=3, m_field_count=7)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:1199
#2  0x0000000000a354e4 in mthd_my_read_metadata (mysql=mysql@entry=0x7f3f8b473a00, field_count=field_count@entry=3, m_field_count=<optimized out>)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:1233
#3  0x0000000000a356ca in mthd_my_read_query_result (mysql=0x7f3f8b473a00) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:2559
#4  0x0000000000a4829b in mysql_query_start_internal (d=<optimized out>) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_async.c:798
#5  0x0000000000a4cf91 in my_context_spawn (c=0x7f3f8e763ff0, f=0x0, d=0x0) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/ma_context.c:201

proxysql.log
core.16851.zip

[JavierJF]

Hi @Fanduzi,

I have been analyzing this issue, and there are several things that points to a potential memory corruption on ProxySQL side, let me share with you this findings and propose a curse of action for trying to isolate it.

Server health

There are multiple times that ProxySQL appears to have received a invalid replication lag response as log indicates, this is usually indicative of an unhealthy server. This situation continues to take place and can be seeing multiple times in the log:

2022-08-18 12:49:25 MySQL_Monitor.cpp:1282:monitor_read_only_thread(): [ERROR] mysql_fetch_fields returns NULL, or mysql_num_fields is incorrect. Server 172.16.23.152:3306 . See bug #1994
2022-08-18 12:50:05 MySQL_Monitor.cpp:2298:monitor_replication_lag_thread(): [ERROR] mysql_fetch_fields returns NULL, or mysql_num_fields is incorrect. Server 172.16.23.152:3306 . See bug #1994
2022-08-18 12:50:15 MySQL_Monitor.cpp:2298:monitor_replication_lag_thread(): [ERROR] mysql_fetch_fields returns NULL, or mysql_num_fields is incorrect. Server 172.16.23.152:3306 . See bug #1994
Error: signal 11:
proxysql(_Z13crash_handleri+0x2a)[0x594b7a]
/lib64/libc.so.6(+0x36340)[0x7f3f93e5f340]
proxysql(unpack_field+0x6c)[0xa340ac]
proxysql(mthd_my_read_metadata_ex+0xac)[0xa353bc]
proxysql(mthd_my_read_query_result+0x14a)[0xa356ca]
proxysql[0xa4829b]
proxysql(my_context_spawn+0x41)[0xa4cf91]
 ---- proxysql(_Z13crash_handleri+0x2a) [0x594b7a] : crash_handler(int)
2022-08-18 14:42:27 main.cpp:1245:ProxySQL_daemonize_phase3(): [ERROR] ProxySQL crashed. Restarting!

But, since as later we will see there are indicatives of a potential memory corruption, I can't be sure if this invalid responses from the server are actually invalid responses or early consequences of the corruption. To have a better picture of your setup, I would like to ask you a couple of questions:

• Were these servers healthy and serving traffic at the moment of the crashes?
• Which MySQL versions are they? Do all share the same version?
• Were any or all the servers updated prior to the crashes?
• All the crashes from the log appear to take place on the day of the report 2022-08-18, yet the log spanws for multiple months before the crashes. Was anything changed either in ProxySQL config or in the backend servers on that date?

With these questions I just want to obtain more information that could help us to isolate the issue without the need of further doing on your side.

Coredump analysis

I'm going to try to perform a coredump analysis for you, for making my point of this being a potential memory corruption, and so justifying the next actions. Reason for the crash looks clear in first frame:

(gdb) frame 0
#0  0x0000000000a340ac in unpack_field (mysql=mysql@entry=0x7f3f8b473a00, alloc=alloc@entry=0x7f3f8b473d00, default_value=default_value@entry=0 '\000', row=row@entry=0x7f3f8b5aef20, field=field@entry=0x7f3f857d0050)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:911
911	    if (row->data[i][0] == 0) {
(gdb) p row->data
$1 = (MYSQL_ROW) 0x7f3f857d01d0
(gdb) p row->data[0]
$2 = 0x0

Data to be read from the MYSQL_ROW is empty, this of course, shouldn't be the case. Let's get more context about the MySQL connection:

(gdb) p *mysql
$5 = {net = {pvio = 0x7f3f8e732640, buff = 0x7f3f8cfea000 "\376", buff_end = 0x7f3f8cfec000 "\377\377\377\377", write_pos = 0x7f3f8cfea000 "\376", read_pos = 0x7f3f8cfea000 "\376", fd = 43, remain_in_buf = 0, server_version = 0x7f3f8e670780 "5.7.29-32-log",  client_flag = 10003077, server_capabilities = 3238002687, protocol_version = 10, field_count = 0, server_status = 2, server_language = 33, warning_count = 0, ...}

We know now that target server was host = 0x7f3f8e670760 "172.16.23.152" and that was a MySQL 5.7.29-32-log. Server capabilities indicates that user has CLIENT_DEPRECATE_EOF disabled. Let's focus on the actual packet being received when the crash took place, since backtrace points to mthd_my_read_metadata_ex this means metadata has already been received and we can inspect the expected fields for the received resultset:

(gdb) x/32xb mysql->net->buff
0x7f3f8cfea000:	0xfe	0x00	0x00	0x02	0x00	0x00	0x00	0x09
0x7f3f8cfea008:	0x72	0x65	0x61	0x64	0x5f	0x6f	0x6e	0x6c
0x7f3f8cfea010:	0x79	0x00	0x0c	0x3f	0x00	0x01	0x00	0x00
0x7f3f8cfea018:	0x00	0x08	0x80	0x00	0x00	0x00	0x00	0x00

Contents of the buffer are already odd, since the starting position of it points to what it looks like an EOF packet:

0x7f3f8cfea000:	0xfe	0x00	0x00	0x02	0x00

This is followed by three more 0x00 which should in reality be four, and then there is the size of the string for the field name, which should have been removed, followed by the field name itself. The field name is:

(gdb) p (char*)0x7f3f8cfea008
$10 = 0x7f3f8cfea008 "read_only"

So, now we know that this resultset is a response from MySQL to a read_only check issued by Monitor. We should check if the received packet matches our malformed buffer:

(gdb) x/64xb mysql->net->pvio->cache
0x7f3f8b558000:	0x01	0x00	0x00	0x01	0x01	0x1f	0x00	0x00
0x7f3f8b558008:	0x02	0x03	0x64	0x65	0x66	0x00	0x00	0x00
0x7f3f8b558010:	0x09	0x72	0x65	0x61	0x64	0x5f	0x6f	0x6e
0x7f3f8b558018:	0x6c	0x79	0x00	0x0c	0x3f	0x00	0x01	0x00
0x7f3f8b558020:	0x00	0x00	0x08	0x80	0x00	0x00	0x00	0x00
0x7f3f8b558028:	0x05	0x00	0x00	0x03	0xfe	0x00	0x00	0x02
0x7f3f8b558030:	0x00	0x02	0x00	0x00	0x04	0x01	0x31	0x05
0x7f3f8b558038:	0x00	0x00	0x05	0xfe	0x00	0x00	0x02	0x08

The received packet doesn't present any short of corruption in the relevant sections, in fact:

0x7f3f8b558000:        0x01        0x00        0x00        0x01        0x01        0x1f        0x00        0x00
//                                header              | seq       | col_count  | col def header
0x7f3f8b558008:        0x02        0x03        0x64        0x65        0x66        0x00        0x00        0x00
//                      seq  | str_size    |           str 'def'               |   db      |   table    |  org_table
0x7f3f8b558010:        0x09        0x72        0x65        0x61        0x64        0x5f        0x6f        0x6e
//                  str_size |     str   'read_only' 
0x7f3f8b558018:        0x6c        0x79        0x00        0x0c        0x3f        0x00        0x01        0x00
//                                         | org_name  |       charset         |     etc....

The troubling section should be col def header followed by the seq and column name itself, but, they look
completely normal. For comparison, here is the output from a "healthy" resultset received against a MySQL server, for the query issued by monitor SELECT @@global.read_only read_only:

(gdb) x/64xb mysql->net->pvio->cache
0x7ffff6eaa980:	0x01	0x00	0x00	0x01	0x01	0x1f	0x00	0x00
0x7ffff6eaa988:	0x02	0x03	0x64	0x65	0x66	0x00	0x00	0x00
0x7ffff6eaa990:	0x09	0x72	0x65	0x61	0x64	0x5f	0x6f	0x6e
0x7ffff6eaa998:	0x6c	0x79	0x00	0x0c	0x3f	0x00	0x01	0x00
0x7ffff6eaa9a0:	0x00	0x00	0x08	0x80	0x00	0x00	0x00	0x00
0x7ffff6eaa9a8:	0x05	0x00	0x00	0x03	0xfe	0x00	0x00	0x02
0x7ffff6eaa9b0:	0x00	0x02	0x00	0x00	0x04	0x01	0x31	0x05
0x7ffff6eaa9b8:	0x00	0x00	0x05	0xfe	0x00	0x00	0x02	0x00

The only difference between the two are in the final byte, which in the case of the crash was '0x08' meaning server status SERVER_QUERY_WAS_SLOW. This matches the previously observed status of servers being overloaded in ProxySQL log.

For completion, this is a side by side comparison of mysql->net->buff for this scenario and a healthy one in the same stage of processing, this is at deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:1199, during:

->        if (unpack_field(mysql, mem_root, 0, &m_rows, m_fields++))
            return NULL;

Network buffers comparison:

Healthy:

(gdb) x/32xb mysql->net->buff
0x7ffff6e83000:	0x03	0x64	0x65	0x66	0x00	0x00	0x00	0x00
0x7ffff6e83008:	0x72	0x65	0x61	0x64	0x5f	0x6f	0x6e	0x6c
0x7ffff6e83010:	0x79	0x00	0x00	0x3f	0x00	0x01	0x00	0x00
0x7ffff6e83018:	0x00	0x08	0x80	0x00	0x00	0x00	0x00	0x00

Unhealthy:

(gdb) x/32xb mysql->net->buff
0x7f3f8cfea000:	0xfe	0x00	0x00	0x02	0x00	0x00	0x00	0x09
0x7f3f8cfea008:	0x72	0x65	0x61	0x64	0x5f	0x6f	0x6e	0x6c
0x7f3f8cfea010:	0x79	0x00	0x0c	0x3f	0x00	0x01	0x00	0x00
0x7f3f8cfea018:	0x00	0x08	0x80	0x00	0x00	0x00	0x00	0x00

Actions

The fact that the buffer contains a invalid packet and that everything points that ProxySQL itself wrote that packet makes me think that we are seeing a memory corruption. Sadly, trying to find a memory corruption like this from a coredump is sometimes an impossible task. Because of this, if you are still able to replicate these crashes or if you are still affected by them, I wanted to ask you if you will be willing to try a special ASAN build (with ASAN address sanitizer enabled) for trying to find the source of this corruption.

Please let me know if you want to try this build and I will provide it to you. Thank you!

[Fanduzi]

1. Were these servers healthy and serving traffic at the moment of the crashes?
   they were healthy and serving traffic
2. Which MySQL versions are they? Do all share the same version?
   all 5.7.29
3. Were any or all the servers updated prior to the crashes?
   Did not understand this sentence. Are you referring to the update as a version upgrade or what?
4. All the crashes from the log appear to take place on the day of the report 2022-08-18, yet the log spanws for multiple months before the crashes. Was anything changed either in ProxySQL config or in the backend servers on that date?
   No changes

It should be added that this is a one-master-two-slave cluster. The master and one slave are in region1-az1, and the other slave is in region1-az2

This cluster uses a set of servers, three servers for mysql deployment and two servers for proxysql deployment. This set of servers deploys multiple clusters, i.e. multi-instance deployment. 8.18 When the proxysql instance of this cluster crashes, the other instances of the same server are normal and do not crash

Since the crash on 8.18, I don't think it has crashed again, but another cluster has crashed a few times before (but this one is on a different set of servers). I can't reproduce it at the moment. If it crashes again, I can provide some monitoring data. If I can reproduce this crash scenario consistently, I can use the ASAN build version you mentioned.

Thank you very much, if I can reproduce, or if I have more information, I will come back to reply

[JavierJF]

Hi @Fanduzi, sorry for the late reply, I just wanted to answer a couple of your questions,

3. Were any or all the servers updated prior to the crashes?
   Did not understand this sentence. Are you referring to the update as a version upgrade or what?

Sorry for not being clear. Yes, I was referring to a version upgrade. But since you mentioned that no changed took place in either ProxySQL or the backend, it's not relevant. Thanks.

Since the crash on 8.18, I don't think it has crashed again, but another cluster has crashed a few times before (but this one is on a different set of servers). I can't reproduce it at the moment. If it crashes again, I can provide some monitoring data. If I can reproduce this crash scenario consistently, I can use the ASAN build version you mentioned.

Thank you very much, if I can reproduce, or if I have more information, I will come back to reply

Yw! Please let us know if it happens again, and of course if you can reproduce it, and I would be happy to provide the ASAN build.

Thank you!

[nvahalik]

I am having this same issue.

Brand new installation of proxysql on a new Debian 11 server. I have used both the packaged versions and built-from-source proxysql binaries. They all exhibit the issue. Here is my dump:

[Current thread is 1 (Thread 0x7fbb08c78700 (LWP 169631))]
(gdb) bt
#0  0x000056334f0cc98b in unpack_field (mysql=mysql@entry=0x7fbb09db5000, alloc=alloc@entry=0x7fbb07caebb0, default_value=default_value@entry=0 '\000', row=row@entry=0x7fbb07caeb50, field=field@entry=0x7fbb045e6658)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:911
#1  0x000056334f0cdb9c in mthd_my_read_metadata_ex (mysql=0x7fbb09db5000, mem_root=mem_root@entry=0x7fbb07caebb0, field_count=27489, m_field_count=m_field_count@entry=7) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_lib.c:1199
#2  0x000056334f0d241f in mthd_stmt_get_param_metadata (stmt=0x7fbb07aabc00) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/include/ma_priv.h:33
#3  0x000056334f0d43d5 in mysql_stmt_prepare (stmt=0x7fbb07aabc00, query=0x7fbb09107d25 "select * from `custom_macros` where `transphormer_id` = ? order by `created_at` desc", length=84)
    at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_stmt.c:1738
#4  0x000056334f0e0af3 in mysql_stmt_prepare_start_internal (d=<optimized out>) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/mariadb_async.c:1337
#5  0x000056334f0e3c61 in my_context_spawn (c=0x7fbb09d575b0, f=0x0, d=0x0) at /opt/proxysql/deps/mariadb-client-library/mariadb_client/libmariadb/ma_context.c:201
#6  0x0000000000000000 in ?? ()

My server is 5.7.29-log.

[jplewes]

I have the same problem when running 2.5.1 in Kubernetes. My backend is 8.0.33-25.1

Error: signal 11:
/usr/bin/proxysql(_Z13crash_handleri+0x2a)[0x5ce71a]
/lib64/libc.so.6(+0x4eb50)[0x7f8f9b222b50]
/usr/bin/proxysql(unpack_field+0x6c)[0xb530ec]
/usr/bin/proxysql(mthd_my_read_metadata_ex+0xac)[0xb5422c]
/usr/bin/proxysql(mthd_my_read_query_result+0x13a)[0xb5450a]
/usr/bin/proxysql[0xb66e5f]
/usr/bin/proxysql(my_context_spawn+0x41)[0xb6a381]
---- /usr/bin/proxysql(_Z13crash_handleri+0x2a) [0x5ce71a] : crash_handler(int)

[utdrmac]

Reporting same issue with PXC 5.7.34 and ProxySQL 2.4.8. This happened last night during an ALTER table.

Error: signal 11:
/usr/bin/proxysql(_Z13crash_handleri+0x40)[0x55da6beed760]
/lib/x86_64-linux-gnu/libc.so.6(+0x42520)[0x7f70a7f9e520]
/usr/bin/proxysql(unpack_field+0x6b)[0x55da6c541dab]
/usr/bin/proxysql(mthd_my_read_metadata_ex+0xbc)[0x55da6c542ffc]
/usr/bin/proxysql(mthd_my_read_query_result+0x154)[0x55da6c543344]
/usr/bin/proxysql(+0x984093)[0x55da6c556093]
/usr/bin/proxysql(my_context_spawn+0x45)[0x55da6c559aa5]

[JavierJF]

Hello everyone,

if you could please share the following information with us, we could further investigate these issues:

If this is a crashing bug, please also include:
- [ ] The package used to install ProxySQL
- [ ] The compressed proxysql binary
- [ ] The compressed core dump (Note: if you're worried it may contain sensitive data, please contact us for information on sharing it securely: https://proxysql.com/contact-us/)

(The previous information is part of the issue template)

I would like to point out a couple of things:

• When submitting a issue, please make sure to at least provide the information present in the issue template. It's many times the minimal information that we require to start an investigation.
• Even if the crashes you are experiencing have a similar backtrace, that doesn't mean that you are encountering the same issue. On those supplied backtraces, two different execution paths can be identified. I'm not saying that they are not related, they might be, but at this time we don't have sufficient information to correlate them. It's important that you submit the information related to your particular crashes, so we can establish correlation between them after a proper investigation is performed.

Thank you, Javier.

[danayala-sewell]

Requested binaries for @utdrmac. Comment above.

proxysql.tar.gz

Thanks!

[JavierJF]

Hi @danayala-sewell ,

thanks for the provided info, but is this a custom build? The hash (sha1sum) of the binary you provided isn't between the ones of our packages provided for v2.4.8. If that is not the case, could you point the original package from which this ProxySQL was installed?

Thanks, Javier.

[danayala-sewell]

Hi @JavierJF,

Yes, it is the Percona ProxySQL 2.4.8.

[JavierJF]

Hi @danayala-sewell,

Percona has builds for different OS builds, for troubleshooting, the exact build it's required to be known. That includes the target platform of the build. Also, please take into account that while we can try to troubleshoot this build, the fact it's not an official one can complicate the process.

Thanks, Javier.