As was found out in "Kamailio stops processing requests over UDP" thread, db_mysql_submit_query() in some circumstances hangs when it executes mysql_ping here:
if (my_ping_interval) { t = time(0); if ((t - CON_TIMESTAMP(_h)) > my_ping_interval) { for (i=0; i < (db_mysql_auto_reconnect ? 3 : 1); i++) { if (mysql_ping(CON_CONNECTION(_h))) { LM_INFO("driver error on ping: %s\n", mysql_error(CON_CONNECTION(_h))); counter_inc(mysql_cnts_h.driver_err); } else { break; } } } ... }
Comment in front of db_mysql_submit_query() function tells:
* Send a SQL query to the database server. This methods tries to reconnect * to the server if the connection is gone and the auto_reconnect parameter is * enabled. It also issues a mysql_ping before the query to connect again after * a long waiting period because for some older mysql versions the auto reconnect * don't work sufficient. If auto_reconnect is enabled and the server supports it, * then the mysql_ping is probably not necessary, but its safer to do it in this * cases too. *
The text was most likely written many years ago and auto reconnect now works OK in mysql versions in use today.
I would like to test if the hangup could be prevented without the above code. Would it be possible to make the code optional via a compilation flag or by some other means?
-- Juha
I would suggest to add a new module parameter to control it, it is better than a compile time flag.
Being code that tries to resolve a bug/issue, it can still be pushed to master branch even it is testing phase, and if proves to be useless can be reverted later.
Cheers, Daniel
On 06.09.19 08:46, Juha Heinanen wrote:
As was found out in "Kamailio stops processing requests over UDP" thread, db_mysql_submit_query() in some circumstances hangs when it executes mysql_ping here:
if (my_ping_interval) { t = time(0); if ((t - CON_TIMESTAMP(_h)) > my_ping_interval) { for (i=0; i < (db_mysql_auto_reconnect ? 3 : 1); i++) { if (mysql_ping(CON_CONNECTION(_h))) { LM_INFO("driver error on ping: %s\n", mysql_error(CON_CONNECTION(_h))); counter_inc(mysql_cnts_h.driver_err); } else { break; } } } ... }
Comment in front of db_mysql_submit_query() function tells:
- Send a SQL query to the database server. This methods tries to reconnect
- to the server if the connection is gone and the auto_reconnect parameter is
- enabled. It also issues a mysql_ping before the query to connect again after
- a long waiting period because for some older mysql versions the auto reconnect
- don't work sufficient. If auto_reconnect is enabled and the server supports it,
- then the mysql_ping is probably not necessary, but its safer to do it in this
- cases too.
The text was most likely written many years ago and auto reconnect now works OK in mysql versions in use today.
I would like to test if the hangup could be prevented without the above code. Would it be possible to make the code optional via a compilation flag or by some other means?
-- Juha
Kamailio (SER) - Development Mailing List sr-dev@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev
Daniel-Constantin Mierla writes:
I would suggest to add a new module parameter to control it, it is better than a compile time flag.
Being code that tries to resolve a bug/issue, it can still be pushed to master branch even it is testing phase, and if proves to be useless can be reverted later.
I'll comment the ping code away locally and do tests without it. If hanging doesn't happen without it, I'll add the module param.
-- Juha
Juha Heinanen writes:
I'll comment the ping code away locally and do tests without it. If hanging doesn't happen without it, I'll add the module param.
Unfortunately udp receiver hangs also without mysql_ping. Now hang happens in insert (below).
Will try next without cluster if regular insert would work.
-- Juha
---start 4576 ----------------------------------------------------- [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". 0x00007fa641ed98a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 84 ../sysdeps/unix/syscall-template.S: No such file or directory. #0 0x00007fa641ed98a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007fa63fe5fec1 in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #2 0x00007fa63fe5ff48 in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #3 0x00007fa63fe60052 in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #4 0x00007fa63fe60115 in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #5 0x00007fa63fe3be51 in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #6 0x00007fa63fe3ccec in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #7 0x00007fa63fe2e87f in ?? () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #8 0x00007fa63fe2ffae in mysql_free_result () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #9 0x00007fa63fe31936 in mysql_real_query () from /usr/lib/x86_64-linux-gnu/libmariadbclient.so.18 No symbol table info available. #10 0x00007fa64040c05c in db_mysql_submit_query (_h=0x7fa641258a90, _s=0x7fa64086b2d0 <sql_str>) at km_dbase.c:112 i = 0 code = 32678 __func__ = "db_mysql_submit_query" #11 0x00007fa64065ab88 in db_do_submit_query (_h=0x7fa641258a90, _query=0x7fa64086b2d0 <sql_str>, submit_query=0x7fa64040bcf1 <db_mysql_submit_query>) at db_query.c:58 ret = 32678 tvb = {tv_sec = 94212721508036, tv_usec = 140352034278032} tve = {tv_sec = 108261778181, tv_usec = 1382979469336} tz = {tz_minuteswest = 24, tz_dsttime = 65147} tdiff = 908405824 __func__ = "db_do_submit_query" #12 0x00007fa64065d1ca in db_do_insert_cmd (_h=0x7fa641258a90, _k=0x7fa636252960 <db_keys>, _v=0x7fa636252c40 <db_vals>, _n=24, val2str=0x7fa6404255a6 <db_mysql_val2str>, submit_query=0x7fa64040bcf1 <db_mysql_submit_query>, mode=0) at db_query.c:242 off = 711 ret = 322 __func__ = "db_do_insert_cmd" #13 0x00007fa64065d831 in db_do_insert (_h=0x7fa641258a90, _k=0x7fa636252960 <db_keys>, _v=0x7fa636252c40 <db_vals>, _n=24, val2str=0x7fa6404255a6 <db_mysql_val2str>, submit_query=0x7fa64040bcf1 <db_mysql_submit_query>) at db_query.c:257 No locals. #14 0x00007fa640410a6a in db_mysql_insert (_h=0x7fa641258a90, _k=0x7fa636252960 <db_keys>, _v=0x7fa636252c40 <db_vals>, _n=24) at km_dbase.c:494 No locals. #15 0x00007fa63768055c in db_cluster_insert (_h=0x7fa64145cd90, _k=0x7fa636252960 <db_keys>, _v=0x7fa636252c40 <db_vals>, _n=24) at dbcl_api.c:379 ret = -1 i = 5 k = 32678 sec = 56341002 rc = 0 rok = 0 j = 0 dbh = 0x7fa641258a90 cls = 0x7fa641274c20 __func__ = "db_cluster_insert" #16 0x00007fa63601d66c in acc_db_request (rq=0x7fa6292a26f0) at acc.c:476 m = 24 n = 690628336 i = 24 o = 17 t = 0x7fa6292a35a8 dtime = -2.8399536906951675e-300 __func__ = "acc_db_request" #17 0x00007fa636030230 in acc_onreply (t=0x7fa6292a9c50, req=0x7fa6292ad410, reply=0xffffffffffffffff, code=408) at acc_logic.c:604 ...
Juha Heinanen writes:
Unfortunately udp receiver hangs also without mysql_ping. Now hang happens in insert (below).
Will try next without cluster if regular insert would work.
So far no hang when acc is not using cluster db_url.
Cluster has two connections with mode "5s5s".
If I have understood correctly, underlying db_mysql module is not aware of the cluster. If so, how could use of cluster cause hang in libmariadb?
-- Juha
On 11.09.19 21:20, Juha Heinanen wrote:
Juha Heinanen writes:
Unfortunately udp receiver hangs also without mysql_ping. Now hang happens in insert (below).
Will try next without cluster if regular insert would work.
So far no hang when acc is not using cluster db_url.
Cluster has two connections with mode "5s5s".
If I have understood correctly, underlying db_mysql module is not aware of the cluster. If so, how could use of cluster cause hang in libmariadb?
Are the two connections going to the same mysql server? Or different ones?
Are you able to see from the logs if writing to the first connection failed and it tried to the second one?
db_cluster does some basic operations here, in the way that tries to use the first connection and if the underlying module returns error, it tries via the second one. It doesn't do anything specific for the connector module and the connector module should not be aware of the db_cluster.
Cheers, Daniel
Daniel-Constantin Mierla writes:
Are the two connections going to the same mysql server? Or different ones?
Different ones.
Are you able to see from the logs if writing to the first connection failed and it tried to the second one?
No, everything seems normal. Here is the last working acc insert before the freeze:
Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:446]: should_acc_reply(): acc is on Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:482]: db_cluster_use_table(): use table (accounting) - cluster [sip_proxy_usage_cluster] Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:491]: db_cluster_use_table(): set read table (accounting) - cluster [sip_proxy_usage_cluster] (5/0) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:501]: db_cluster_use_table(): set write table (accounting) - cluster [sip_proxy_usage_cluster] (5/0) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:491]: db_cluster_use_table(): set read table (accounting) - cluster [sip_proxy_usage_cluster] (4/0) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:501]: db_cluster_use_table(): set write table (accounting) - cluster [sip_proxy_usage_cluster] (4/0) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:378]: db_cluster_insert(): executing db cluster insert command Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: db_cluster [dbcl_api.c:379]: db_cluster_insert(): serial operation - cluster [sip_proxy_usage_cluster] (5/0) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_extra.h:63]: free_strar_mem(): Freeing memory, type is 2, message_index 7, index i 0 Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): RETR/FR timers reset Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/receive.c:442]: receive_msg(): reply-route executed in: 1395 usec Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up Sep 2 12:00:20 rox2 /usr/bin/sip-proxy[341]: DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/1063) [[INVITE ...]]
After that there is a couple of these:
Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:413]: should_acc_reply(): probing acc state - code: 183 flags: 0x200209c0 Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:442]: should_acc_reply(): early media acc is off
And finally the last should_acc_reply() before the freeze that does not result to any kind db_cluster entry in syslog:
Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:413]: should_acc_reply(): probing acc state - code: 480 flags: 0x240005c4 Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:430]: should_acc_reply(): failed acc is on Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_lookup.c:1111]: t_check_msg(): msg (0x7f2383bea9e0) id=12872/341 global id=12872/341 T end=0x7f236b1cc3f0 Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_reply.c:2243]: reply_received(): transaction found - T:0x7f236b1cc3f0 branch:0
Next process 341 entry in syslog is 13+ minutes later after the freeze:
Sep 2 12:13:55 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_reply.c:2256]: reply_received(): org. status uas=408, uac[0]=408 local=0 is_invite=1)
-- Juha
Juha Heinanen writes:
And finally the last should_acc_reply() before the freeze that does not result to any kind db_cluster entry in syslog:
Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:413]: should_acc_reply(): probing acc state - code: 480 flags: 0x240005c4 Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: acc [acc_logic.c:430]: should_acc_reply(): failed acc is on Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_lookup.c:1111]: t_check_msg(): msg (0x7f2383bea9e0) id=12872/341 global id=12872/341 T end=0x7f236b1cc3f0 Sep 2 12:00:21 rox2 /usr/bin/sip-proxy[341]: DEBUG: tm [t_reply.c:2243]: reply_received(): transaction found - T:0x7f236b1cc3f0 branch:0
I guess because process 341 is waiting for a lock (below). Before this acc attempt I have not found any failing ones. They have all ended up in cleaning of memory, cleanup_uac_timers(), and reply-route executed.
-- Juha
---start 341 ----------------------------------------------------- [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38 38 ../sysdeps/unix/sysv/linux/x86_64/syscall.S: No such file or directory. #0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38 No locals. #1 0x00007f2380e7f05d in futex_get (lock=0x7f236b1cc5c0) at ../../core/parser/../mem/../futexlock.h:108 v = 2 i = 1024 #2 0x00007f2380e80f10 in _lock (s=0x7f236b1cc5c0) at lock.h:80 No locals. #3 0x00007f2380ea04e8 in tm_reply_mutex_lock (t=0x7f236b1cc3f0) at t_reply.c:2928 mypid = 341 #4 0x00007f2380e9ab51 in reply_received (p_msg=0x7f2383bea9e0) at t_reply.c:2248 msg_status = 2011789584 last_uac_status = 271554156 ack = 0x1ffb <error: Cannot access memory at address 0x1ffb> ack_len = 2011789776 branch = 0 reply_status = 32765 onreply_route = 271554156 cancel_data = {cancel_bitmap = 2213206539, reason = {cause = 24, u = {text = {s = 0x7ffd77e97a90 "\227\224D\017AV", len = 271554144}, e2e_cancel = 0x7ffd77e97a90, packed_hdrs = {s = 0x7ffd77e97a90 "\227\224D\017AV", len = 271554144}}}} uac = 0x31343341101bac10 ...
I build libmariadbclient18 with symbols (below) and got a new backtrace of the hanging process.
I guess the only choice is to try with the newer lib that comes with Debian Buster or give up use of db_cluster module with MySQL.
-- Juha
---start 24717 ----------------------------------------------------- [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". 0x00007f517466d8a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 84 ../sysdeps/unix/syscall-template.S: No such file or directory. #0 0x00007f517466d8a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007f51725f3ef1 in poll (__timeout=2000, __nfds=1, __fds=0x7ffed132f808) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46 No locals. #2 vio_io_wait (vio=vio@entry=0x560529eb39d8, event=event@entry=VIO_IO_EVENT_READ, timeout=2000) at ./vio/viosocket.c:992 ret = <optimized out> revents = <optimized out> pfd = {fd = 18, events = 3, revents = 0} state = {m_flags = 3509778656, m_socket = 0x7ffed132f820, m_thread = 0x0, m_number_of_bytes = 21474836512, m_timer_start = 140732408199414, m_timer = 0x7ffed132f8fc, m_operation = 3509778680, m_src_file = 0x7ffed132f8fc "\376\177", m_src_line = 16, m_wait = 0x7f517398d010} #3 0x00007f51725f3f78 in vio_socket_io_wait (vio=vio@entry=0x560529eb39d8, event=event@entry=VIO_IO_EVENT_READ) at ./vio/viosocket.c:108 timeout = <optimized out> ret = -516 #4 0x00007f51725f4082 in vio_read (vio=vio@entry=0x560529eb39d8, buf=0x560529eb3bd8 "\001", size=size@entry=16384) at ./vio/viosocket.c:184 error = <optimized out> ret = <optimized out> flags = 64 #5 0x00007f51725f4145 in vio_read_buff (vio=0x560529eb39d8, buf=0x560529eb7be8 "\001", size=4) at ./vio/viosocket.c:232 rc = <optimized out> #6 0x00007f51725cfe91 in my_real_read (net=0x7f5173d674e0, complen=complen@entry=0x7ffed132f9f8, header=0 '\000') at ./sql/net_serv.cc:877 pos = 0x560529eb7be8 "\001" length = <optimized out> i = <optimized out> retry_count = <optimized out> len = <optimized out> expect_error_packet = <optimized out> alarmed = 0 '\000' remain = 4 #7 0x00007f51725d0d1c in my_net_read_packet (net=net@entry=0x7f5173d674e0, read_from_server=read_from_server@entry=0 '\000') at ./sql/net_serv.cc:1140 len = <optimized out> complen = 0 #8 0x00007f51725c28af in cli_safe_read (mysql=mysql@entry=0x7f5173d674e0) at ./sql-common/client.c:587 net = 0x7f5173d674e0 len = <optimized out> #9 0x00007f51725c8323 in cli_advanced_command (mysql=0x7f5173d674e0, command=<optimized out>, header=0x0, header_length=0, arg=0x0, arg_length=0, skip_check=0 '\000', stmt=0x0) at ./sql-common/client.c:729 net = 0x7f5173d674e0 result = 0 '\000' stmt_skip = <optimized out> #10 0x00007f51725be2a1 in mysql_ping (mysql=<optimized out>) at ./libmysql/libmysql.c:982 res = <optimized out> #11 0x00007f5172bb14e6 in db_mysql_submit_query (_h=0x7f51739ecff0, _s=0x7f5172fff2d0 <sql_str>) at km_dbase.c:83 t = 1568791290 i = 0 code = 22021 __func__ = "db_mysql_submit_query" #12 0x00007f5172deeb88 in db_do_submit_query (_h=0x7f51739ecff0, _query=0x7f5172fff2d0 <sql_str>, submit_query=0x7f5172bb1149 <db_mysql_submit_query>) at db_query.c:58 ret = 32593 tvb = {tv_sec = 94580176772804, tv_usec = 139987808866288} tve = {tv_sec = 109108585221, tv_usec = 1365799600152} tz = {tz_minuteswest = 24, tz_dsttime = 65147} tdiff = 1755212864 __func__ = "db_do_submit_query" #13 0x00007f5172df11ca in db_do_insert_cmd (_h=0x7f51739ecff0, _k=0x7f51689e6960 <db_keys>, _v=0x7f51689e6c40 <db_vals>, _n=24, val2str=0x7f5172baf7b8 <db_mysql_val2str>, submit_query=0x7f5172bb1149 <db_mysql_submit_query>, mode=0) at db_query.c:242 off = 707 ret = 318 __func__ = "db_do_insert_cmd" ...
I haven't looked at the code of mysql library, but the parameters suggest there should be a timeout for poll(), with the value 2000ms (2sec), which obviously does not happen.
If there is no attempt to use the 2nd connection, then the interference of db_cluster should be minimal, it just passes parameters to the real db connector module. And in general, db cluster doesn't do anything special with the db connector module, it should be like sqlops dealing with two connections, when execution a query on one connection fails, will try via the second.
Not exactly, but somehow a similar blocking of mysql operation happens in an issue reported to the tracker (there leads to mem leak as the timer gets blocked and transactions not removed anymore):
* https://github.com/kamailio/kamailio/issues/1895
I have little reasons to suspect now the db_cluster code, if you can test with a newer lib would be good to see the results.
Cheers, Daniel
On 18.09.19 10:46, Juha Heinanen wrote:
I build libmariadbclient18 with symbols (below) and got a new backtrace of the hanging process.
I guess the only choice is to try with the newer lib that comes with Debian Buster or give up use of db_cluster module with MySQL.
-- Juha
---start 24717 ----------------------------------------------------- [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". 0x00007f517466d8a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 84 ../sysdeps/unix/syscall-template.S: No such file or directory. #0 0x00007f517466d8a0 in __poll_nocancel () at ../sysdeps/unix/syscall-template.S:84 No locals. #1 0x00007f51725f3ef1 in poll (__timeout=2000, __nfds=1, __fds=0x7ffed132f808) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46 No locals. #2 vio_io_wait (vio=vio@entry=0x560529eb39d8, event=event@entry=VIO_IO_EVENT_READ, timeout=2000) at ./vio/viosocket.c:992 ret = <optimized out> revents = <optimized out> pfd = {fd = 18, events = 3, revents = 0} state = {m_flags = 3509778656, m_socket = 0x7ffed132f820, m_thread = 0x0, m_number_of_bytes = 21474836512, m_timer_start = 140732408199414, m_timer = 0x7ffed132f8fc, m_operation = 3509778680, m_src_file = 0x7ffed132f8fc "\376\177", m_src_line = 16, m_wait = 0x7f517398d010} #3 0x00007f51725f3f78 in vio_socket_io_wait (vio=vio@entry=0x560529eb39d8, event=event@entry=VIO_IO_EVENT_READ) at ./vio/viosocket.c:108 timeout = <optimized out> ret = -516 #4 0x00007f51725f4082 in vio_read (vio=vio@entry=0x560529eb39d8, buf=0x560529eb3bd8 "\001", size=size@entry=16384) at ./vio/viosocket.c:184 error = <optimized out> ret = <optimized out> flags = 64 #5 0x00007f51725f4145 in vio_read_buff (vio=0x560529eb39d8, buf=0x560529eb7be8 "\001", size=4) at ./vio/viosocket.c:232 rc = <optimized out> #6 0x00007f51725cfe91 in my_real_read (net=0x7f5173d674e0, complen=complen@entry=0x7ffed132f9f8, header=0 '\000') at ./sql/net_serv.cc:877 pos = 0x560529eb7be8 "\001" length = <optimized out> i = <optimized out> retry_count = <optimized out> len = <optimized out> expect_error_packet = <optimized out> alarmed = 0 '\000' remain = 4 #7 0x00007f51725d0d1c in my_net_read_packet (net=net@entry=0x7f5173d674e0, read_from_server=read_from_server@entry=0 '\000') at ./sql/net_serv.cc:1140 len = <optimized out> complen = 0 #8 0x00007f51725c28af in cli_safe_read (mysql=mysql@entry=0x7f5173d674e0) at ./sql-common/client.c:587 net = 0x7f5173d674e0 len = <optimized out> #9 0x00007f51725c8323 in cli_advanced_command (mysql=0x7f5173d674e0, command=<optimized out>, header=0x0, header_length=0, arg=0x0, arg_length=0, skip_check=0 '\000', stmt=0x0) at ./sql-common/client.c:729 net = 0x7f5173d674e0 result = 0 '\000' stmt_skip = <optimized out> #10 0x00007f51725be2a1 in mysql_ping (mysql=<optimized out>) at ./libmysql/libmysql.c:982 res = <optimized out> #11 0x00007f5172bb14e6 in db_mysql_submit_query (_h=0x7f51739ecff0, _s=0x7f5172fff2d0 <sql_str>) at km_dbase.c:83 t = 1568791290 i = 0 code = 22021 __func__ = "db_mysql_submit_query" #12 0x00007f5172deeb88 in db_do_submit_query (_h=0x7f51739ecff0, _query=0x7f5172fff2d0 <sql_str>, submit_query=0x7f5172bb1149 <db_mysql_submit_query>) at db_query.c:58 ret = 32593 tvb = {tv_sec = 94580176772804, tv_usec = 139987808866288} tve = {tv_sec = 109108585221, tv_usec = 1365799600152} tz = {tz_minuteswest = 24, tz_dsttime = 65147} tdiff = 1755212864 __func__ = "db_do_submit_query" #13 0x00007f5172df11ca in db_do_insert_cmd (_h=0x7f51739ecff0, _k=0x7f51689e6960 <db_keys>, _v=0x7f51689e6c40 <db_vals>, _n=24, val2str=0x7f5172baf7b8 <db_mysql_val2str>, submit_query=0x7f5172bb1149 <db_mysql_submit_query>, mode=0) at db_query.c:242 off = 707 ret = 318 __func__ = "db_do_insert_cmd" ...