Bug #74393 program crashes while calling mysql_ping()
Submitted: 15 Oct 2014 7:44 Modified: 4 Jul 2015 12:14
Reporter: xin huang Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: C API (client library) Severity:S3 (Non-critical)
Version:5.5.28 OS:Linux
Assigned to: Assigned Account CPU Architecture:Any

[15 Oct 2014 7:44] xin huang 
Description:
Our program connects to mysql server with C API. We found that the memory used by mysqld was growing slowly up to about 8G during performance test. Then the program crashed and the memory was not released. 
If we restart the program and run the performance test, it will re-crash after about 30-40 seconds. And the last query generated 2013 error.

------------------------------------------------------------
the core file:
Core was generated by `/usr/lib64/erlang/erts-5.8.1/bin/beam.smp -K true -A 32 -K true -- -root /usr/l'.
Program terminated with signal 11, Segmentation fault.
#0  0x00002b4c13558e64 in my_real_read (net=0x2b4c043e1cb0, 
    complen=0x2b4caa57fef0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc:833
833     /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc: No such file or directory.
        in /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc

(gdb) bt
#0  0x00002b4c13558e64 in my_real_read (net=0x2b4c043e1cb0, 
    complen=0x2b4caa57fef0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc:833
#1  0x00002b4c135590d0 in my_net_read (net=0x0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc:1028
#2  0x00002b4c1355a3b6 in cli_safe_read (mysql=0x0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql-common/client.c:735
#3  0x00002b4c1355e0d9 in cli_advanced_command (mysql=0x2b4c043e1cb0, 
    command=<value optimized out>, header=0x0, header_length=0, arg=0x0, 
    arg_length=0, skip_check=0 '\000', stmt=0x0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql-common/client.c:863
#4  0x00002b4c135519e5 in mysql_ping (mysql=0x0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/libmysql/libmysql.c:969
#5  0x00002b4c1354c63b in rytong::MysqlConnection::get_connection (
    this=0x2b4c043e1c90)
    at /root/ewp/drivers/db/c_src/mysql/MysqlConnection.h:53
#6  0x00002b4c1354e907 in rytong::MysqlDBOperation::real_query_sql (
    this=0x2b4ce4092530, sql=0x2b4c135dfa3f "ROLLBACK", res=0x912fa68, 
    db_conn=@0x2b4caa580070) at c_src/mysql/MysqlDBOperation.cpp:558
#7  0x00002b4c1354e9d8 in rytong::MysqlDBOperation::trans_rollback (
    this=0x2b4ce4092530, res=0x912fa68) at c_src/mysql/MysqlDBOperation.cpp:166
#8  0x00002b4c135454d1 in rytong::DatabaseDrv::execute_cmd (
    db_oper=0x2b4ce4092530, cmd=DRV_TRANSACTION_ROLLBACK, res=0x912fa68)
    at c_src/base/DatabaseDrv.cpp:178
#9  0x00002b4c135457e8 in rytong::DatabaseDrv::io_async (arg=0x912fa58)
    at c_src/base/DatabaseDrv.cpp:98
#10 0x00002b4c135416b7 in rytong::ThreadPool::async_main (arg=0x2b4c0401ed50)
    at c_src/base/ThreadPool.cpp:136
#11 0x0000003832e0683d in start_thread () from /lib64/libpthread.so.0
#12 0x00000038322d4fcd in clone () from /lib64/libc.so.6

------------------------------------------------------------

At first, we thought the MYSQL pointer was set to NULL by mistake according to the stack trace generated by gdb. But the pointer turned out to be not NULL when it was printed by gdb:

(gdb) up
#5  0x00002b4c1354c63b in rytong::MysqlConnection::get_connection (
    this=0x2b4c043e1c90)
    at /root/ewp/drivers/db/c_src/mysql/MysqlConnection.h:53
53              int state = mysql_ping(conn_);
(gdb) print conn_
$1 = (MYSQL *) 0x2b4c043e1cb0
(gdb) print *conn_
$2 = {net = {vio = 0x0, buff = 0x0, buff_end = 0x2b4c043e8420 "\020b", 
    write_pos = 0x2b4c043e6420 "<", read_pos = 0x2b4c043e6420 "<", fd = 164, 
    remain_in_buf = 0, length = 0, buf_length = 0, where_b = 0, 
    max_packet = 8192, max_packet_size = 1073741824, pkt_nr = 1, 
    compress_pkt_nr = 0, write_timeout = 31536000, read_timeout = 31536000, 
    retry_count = 1, fcntl = 0, return_status = 0x0, 
    reading_or_writing = 0 '\000', save_char = 0 '\000', unused1 = 0 '\000', 
    unused2 = 0 '\000', compress = 0 '\000', unused3 = 0 '\000', unused = 0x0, 
    last_errno = 2013, error = 0 '\000', unused4 = 0 '\000', 
    unused5 = 0 '\000', 
    last_error = "Lost connection to MySQL server during query", '\000' <repeats 467 times>, sqlstate = "HY000", extension = 0x0}, connector_fd = 0x0, 
  host = 0x2b4c043e21f0 "192.168.20.93", user = 0x2b4c043e8430 "root", 
  passwd = 0x2b4c043e8450 "Ryt_123", unix_socket = 0x0, 
  server_version = 0x2b4c043e2208 "5.5.28-log", 
  host_info = 0x2b4c043e21d0 "192.168.20.93 via TCP/IP", info = 0x0, 
  db = 0x2b4c043e8470 "vas_manage", charset = 0x2b4c13a204e0, fields = 0x0, 
  field_alloc = {free = 0x0, used = 0x0, pre_alloc = 0x0, min_malloc = 32, 
    block_size = 8160, block_num = 4, first_block_usage = 0, 
    error_handler = 0}, affected_rows = 18446744073709551615, insert_id = 0, 
  extra_info = 0, thread_id = 5318, packet_length = 1, port = 3306, 
  client_flag = 959117, server_capabilities = 18446744071563114495, 
  protocol_version = 10, field_count = 0, server_status = 2, 
  server_language = 8, warning_count = 0, options = {connect_timeout = 0, 
    read_timeout = 0, write_timeout = 0, port = 0, protocol = 0, 
    client_flag = 128, host = 0x0, user = 0x0, password = 0x0, 
    unix_socket = 0x0, db = 0x0, init_commands = 0x0, my_cnf_file = 0x0, 
    my_cnf_group = 0x0, charset_dir = 0x0, 
    charset_name = 0x2b4c043e21b0 "utf8", ssl_key = 0x0, ssl_cert = 0x0, 
    ssl_ca = 0x0, ssl_capath = 0x0, ssl_cipher = 0x0, 
    shared_memory_base_name = 0x0, max_allowed_packet = 0, use_ssl = 0 '\000', 
    compress = 0 '\000', named_pipe = 0 '\000', unused1 = 0 '\000', 
    unused2 = 0 '\000', unused3 = 0 '\000', unused4 = 0 '\000', 
    methods_to_use = MYSQL_OPT_GUESS_CONNECTION, client_ip = 0x0, 
    secure_auth = 0 '\000', report_data_truncation = 1 '\001', 
    local_infile_init = 0, local_infile_read = 0, local_infile_end = 0, 
    local_infile_error = 0, local_infile_userdata = 0x0, extension = 0x0}, 
  status = MYSQL_STATUS_READY, free_me = 1 '\001', reconnect = 1 '\001', 
  scramble = "+&{\\<SnQ)xB~x]I5lDK.", unused1 = 0 '\000', unused2 = 0x0, 
  unused3 = 0x0, unused4 = 0x0, unused5 = 0x0, stmts = 0x0, 
  methods = 0x2b4c13a0d3c0, thd = 0x0, unbuffered_fetch_owner = 0x0, 
  info_buffer = 0x0, extension = 0x0}

------------------------------------------------------------

the source code of real_query_sql:
bool MysqlDBOperation::real_query_sql(const char* sql, ei_x_buff* res, MYSQL* & db_conn) {
    if (NULL == conn_) {
        EiEncoder::encode_error_msg(CONN_NULL_ERROR, res);
        return false;
    }
    db_conn = (MYSQL*) (conn_->get_connection());
    if (0 != mysql_real_query(db_conn, sql, strlen(sql))) {
        EiEncoder::encode_error_msg(mysql_error(db_conn), res);
        return false;
    }
    return true;
}

the source code of get_connection:
    void* get_connection() {
        // auto reconnect
        int state = mysql_ping(conn_);
        // error CR_COMMANDS_OUT_OF_SYNC
        // Commands were executed in an improper order.
        if (state == 1) {
            SysLogger::error("error CR_COMMANDS_OUT_OF_SYNC");
        }
        return (void*) conn_;
    }

How to repeat:
I don't know

Suggested fix:
I don't know
[15 Oct 2014 14:56] MySQL Verification Team 
Please provide a complete test case not just the fragment of it. Thanks.
[16 Oct 2014 2:36] xin huang 
I'm sorry for that. We run the test with scripts of LoadRunner to access the HTTP API of the program. Several business channels were tested. Each of thems contained several sql statements. Any of those statements, not a specific one, could generate the crash.

I print the pointer of NET used by mysql_real_read. In my opinion, it is the reason of crash that the vio pointer of NET structure becomes NULL.

#0  0x00002b6cc6cafe64 in my_real_read (net=0x1a318900, complen=0x2b6d1cc6eeb0)
    at /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc:833
833     in /export/home/pb2/build/sb_0-6742818-1346230389.05/rpm/BUILD/mysql-5.5.28/mysql-5.5.28/sql/net_serv.cc
(gdb) print net
$1 = (NET *) 0x1a318900
(gdb) print *net
$2 = {vio = 0x0, buff = 0x0, buff_end = 0x1a31f020 "\020b", 
  write_pos = 0x1a31d020 "2", read_pos = 0x1a31d020 "2", fd = 263, 
  remain_in_buf = 0, length = 0, buf_length = 0, where_b = 0, 
  max_packet = 8192, max_packet_size = 1073741824, pkt_nr = 1, 
  compress_pkt_nr = 0, write_timeout = 31536000, read_timeout = 31536000, 
  retry_count = 1, fcntl = 0, return_status = 0x0, 
  reading_or_writing = 0 '\000', save_char = 0 '\000', unused1 = 0 '\000', 
  unused2 = 0 '\000', compress = 0 '\000', unused3 = 0 '\000', unused = 0x0, 
  last_errno = 2013, error = 0 '\000', unused4 = 0 '\000', unused5 = 0 '\000', 
  last_error = "Lost connection to MySQL server during query", '\000' <repeats 467 times>, sqlstate = "HY000", extension = 0x0}

I hope it could help you!
[4 Jun 2015 12:14] Chiranjeevi Battula 
Hello xin huang,

Thank you for your feedback.
I tried to reproduce the issue at my end using MySQL 5.6 and MySQL Connector/C 6.1, but couldn't trace out any issue in  calling mysql_ping().
Could you please try with latest versions of MySQL and feel free to open the bug if it doesn't work with newer versions with complete repeatable steps.

Thanks,
Chiranjeevi.
[5 Jul 2015 1:00] Bugs System 
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".