Bug #91278 preparing MySQL statement failed: Lost connection to MySQL server during query
Submitted: 15 Jun 2018 10:21 Modified: 15 Jun 2018 12:36
Reporter: mike ettrich Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: C API (client library) Severity:S3 (Non-critical)
Version:mysql-5.7.22 OS:SUSE (SUSE Linux Enterprise Server 12 (x86_64) Patchlevel 3)
Assigned to: CPU Architecture:x86

[15 Jun 2018 10:21] mike ettrich
Description:
Using the mysql client from strongswan 5.5.3 in a heavy load scenario a signal SIGABRT occurs. In a low and medium load scenario this  abort doesn't take place. 
The mysql server ist installed on the same host as the charon (caller) process over the lo(127.0.0.1) interface.

gdb back trace:
gdb ../install_20180508/libexec/ipsec/charon -c core.charon.1529050245.10326
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/PEGK/vpnzgd/strongswan/install/libexec/ipsec/charon --use-syslog --debug-cfg 2'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f66262fb8c7 in raise () from /lib64/libc.so.6
[Current thread is 1 (Thread 0x7f661df47700 (LWP 10327))]
Missing separate debuginfos, use: zypper install glibc-debuginfo-2.22-62.6.2.x86_64 krb5-debuginfo-1.12.5-40.16.1.x86_64 libatomic1-debuginfo-7.3.1+r258812-5.2.x86_64 libcom_err2-debuginfo-1.42.11-15.1.x86_64 libcurl4-debuginfo-7.37.0-37.14.1.x86_64 libgcc_s1-debuginfo-7.2.1+r253435-2.4.x86_64 libgmp10-debuginfo-5.1.3-2.121.x86_64 libidn11-debuginfo-1.28-4.1.x86_64 libkeyutils1-debuginfo-1.5.9-3.29.x86_64 libldap-2_4-2-debuginfo-2.4.41-18.37.5.x86_64 libopenssl1_0_0-debuginfo-1.0.2j-60.20.2.x86_64 libpcre1-debuginfo-8.39-8.3.1.x86_64 libsasl2-3-debuginfo-2.1.26-8.7.1.x86_64 libselinux1-debuginfo-2.5-8.79.x86_64 libssh2-1-debuginfo-1.4.3-19.1.x86_64 libstdc++6-debuginfo-7.2.1+r253435-2.4.x86_64 libz1-debuginfo-1.2.8-11.1.x86_64
(gdb) bt
#0  0x00007f66262fb8c7 in raise () from /lib64/libc.so.6
#1  0x00007f66262fcc9a in abort () from /lib64/libc.so.6
#2  0x00000000004020ba in segv_handler (signal=11) at charon.c:181
#3  <signal handler called>
#4  0x00007f661fb9d0f0 in net_should_retry (net=0x7f65e40149c0, retry_count=<synthetic pointer>) at /PEGK/src/mysql/mysql-5.7.22/sql/net_serv.cc:252
#5  net_read_raw_loop (net=net@entry=0x7f65e40149c0, count=4) at /PEGK/src/mysql/mysql-5.7.22/sql/net_serv.cc:678
#6  0x00007f661fb9d378 in net_read_packet_header (net=0x7f65e40149c0) at /PEGK/src/mysql/mysql-5.7.22/sql/net_serv.cc:762
#7  net_read_packet (net=0x7f65e40149c0, complen=0x7f661df46760) at /PEGK/src/mysql/mysql-5.7.22/sql/net_serv.cc:822
#8  0x00007f661fb9e04c in my_net_read (net=net@entry=0x7f65e40149c0) at /PEGK/src/mysql/mysql-5.7.22/sql/net_serv.cc:899
#9  0x00007f661fb9281b in cli_safe_read_with_ok (mysql=mysql@entry=0x7f65e40149c0, parse_ok=parse_ok@entry=0 '\000', is_data_packet=is_data_packet@entry=0x0)
    at /PEGK/src/mysql/mysql-5.7.22/sql-common/client.c:1055
#10 0x00007f661fb92b1f in cli_safe_read (mysql=mysql@entry=0x7f65e40149c0, is_data_packet=is_data_packet@entry=0x0) at /PEGK/src/mysql/mysql-5.7.22/sql-common/client.c:1188
#11 0x00007f661fb93a69 in cli_read_query_result (mysql=0x7f65e40149c0) at /PEGK/src/mysql/mysql-5.7.22/sql-common/client.c:5162
#12 0x00007f661fb95926 in mysql_real_query (mysql=0x7f65e40149c0, query=<optimized out>, length=<optimized out>) at /PEGK/src/mysql/mysql-5.7.22/sql-common/client.c:5258
#13 0x00007f661fb8bab7 in mysql_query (mysql=<optimized out>, query=<optimized out>) at /PEGK/src/mysql/mysql-5.7.22/libmysql/libmysql.c:667
#14 0x00007f662017e78b in finalize_transaction (this=0x1697fc0, rollback=<optimized out>) at mysql_database.c:787
#15 0x00007f661eb9bd6e in get_identity (ike_sa=<optimized out>, this=0x163dde0) at attr_sql_provider.c:69
#16 0x00007f661eb9c903 in acquire_address (this=0x163dde0, pools=0x7f65f80084d0, ike_sa=<optimized out>, requested=0x7f65f8026520) at attr_sql_provider.c:316
#17 0x00007f6626d92ef3 in acquire_address (this=0x1634320, pools=0x7f65f80084d0, ike_sa=0x7f65f8000970, requested=0x7f65f8026520) at attributes/attribute_manager.c:74
#18 0x00007f6626dd2bc5 in build_r (this=0x7f65f80024f0, message=0x7f65f8025a60) at sa/ikev2/tasks/ike_config.c:357
#19 0x00007f6626dc6693 in build_response (request=0x7f65f800b1d0, this=0x7f65f80026c0) at sa/ikev2/task_manager_v2.c:864
#20 process_request (message=<optimized out>, this=0x7f65f80026c0) at sa/ikev2/task_manager_v2.c:1225
#21 process_message (this=0x7f65f80026c0, msg=<optimized out>) at sa/ikev2/task_manager_v2.c:1554
#22 0x00007f6626db97ff in process_message (this=0x7f65f8000970, message=0x7f65f800b1d0) at sa/ike_sa.c:1577
#23 0x00007f6626dc5a0c in handle_fragment (defrag=defrag@entry=0x7f65f8002798, msg=msg@entry=0x7f660c009db0, this=0x7f65f80026c0) at sa/ikev2/task_manager_v2.c:1278
#24 0x00007f6626dc62f8 in process_message (this=0x7f65f80026c0, msg=0x7f660c009db0) at sa/ikev2/task_manager_v2.c:1544
#25 0x00007f6626db97ff in process_message (this=0x7f65f8000970, message=0x7f660c009db0) at sa/ike_sa.c:1577
#26 0x00007f6626db0f9f in execute (this=0x7f660c009770) at processing/jobs/process_message_job.c:74
#27 0x00007f6627048142 in process_job (worker=0x16a6290, this=0x162fdd0) at processing/processor.c:235
#28 process_jobs (worker=0x16a6290) at processing/processor.c:321
#29 0x00007f66270585c5 in thread_main (this=0x16a62c0) at threading/thread.c:331
#30 0x00007f6626874724 in start_thread () from /lib64/libpthread.so.0
#31 0x00007f66263b0c9d in clone () from /lib64/libc.so.6

my.cnf
####################################################################
# Mysql default configuration
###################################################################

[client]
port            = 3306
socket          = /DBA/nest/mysql/DBYPEGKR1ZGDT2/etc/mysql.sock

[mysqld]
port            = 3306
bind_address    = 127.0.0.1
basedir         = /DBA/mysql/SQL/5.7.latest/
datadir         = /PEGK/DBYPEGKR1ZGDT2/datadir
pid_file        = /DBA/nest/mysql/DBYPEGKR1ZGDT2/etc/mysql.pid
socket          = /DBA/nest/mysql/DBYPEGKR1ZGDT2/etc/mysql.sock
tmpdir          = /WORK/DUMP/DBYPEGKR1ZGDT2/mysqltmp/
slow_query_log_file = /DBA/nest/mysql/DBYPEGKR1ZGDT2/logs/slow_query_log
slow_query_log  = 1

character_set_server = utf8
collation_server     = utf8_general_ci

skip_external_locking
key_buffer_size=128M
max_allowed_packet=16M
query_cache_size=64M
thread_cache_size=150
max_connections=300

max_binlog_size=50M
binlog_format=MIXED
server_id       = 1

# innodb
innodb_file_per_table = 1
innodb_buffer_pool_size=128M
innodb_log_file_size=64M

explicit_defaults_for_timestamp

[mysqldump]
quick
max_allowed_packet=16M
quote_names
single_transaction
master_data = 2

[mysql]
no_auto_rehash

[myisamchk]
key_buffer=20M
sort_buffer=20M
read_buffer=2M

[mysqlhotcopy]
interactive_timeout

How to repeat:
Running strongswan with activated sql-attr plugin with IP-Pool in the mysql-Database with more then 10 connection requests per second.
[15 Jun 2018 12:36] Sinisa Milivojevic
Hi,

This is a forum devoted to the bugs related to MySQL software. The stacktrace that you display is not from any of our products.

Hence, if you can repeat this with our software only, like mysql CLI, please notify us. 

However, before you do that, remove totally query cache from the server configuration, since this looks like a simple timeout due to the huge query cache that you have set.