MySQL Bugs: #90397: google-perftools under some conditions causes mysql

Bug #90397	google-perftools under some conditions causes mysql_ping to loop infinitely
Submitted:	12 Apr 2018 2:13	Modified:	8 May 2018 8:37
Reporter:	Nobuyuki Okamura	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: C API (client library)	Severity:	S3 (Non-critical)
Version:	5.7.21	OS:	CentOS (7.4)
Assigned to:		CPU Architecture:	x86 (Intel Core i7-6700K)

Description:
While profiling my program in my environment, I encountered a problem of mysql_ping hanging.
According to my simple test, it occurred when the following conditions were satisfied.

  * MYSQL_OPT_READ_TIMEOUT is set
  * google-perftools libprofiler is linked
  * CPUPROFILE environment variable is set
  * Build and run with docker container

My environment:
  Intel Core i7-6700K
  Windows 7 Professional
  Virtual Box 5.2.6 r120293(Qt5.6.2)
  Vagrant 2.0.1
  VirtualBox VM & Docker Container: CentOS 7.4 (x86_64)

Library:
  libmysqlclient.so.20.3.8

How to repeat:
(Windows)
> vagrant init bento/centos-7.4
> vagrant up

(after login to VM by root)
# yum -y install docker
# systemctl start docker
# docker run -d --name mysql -e MYSQL_ALLOW_EMPTY_PASSWORD=yes mysql:5.7
# docker run -it --name centos --link mysql:mysql -v /vagrant:/vagrant centos:7.4.1708 /bin/bash

(after login to docker container)
# yum -y localinstall https://dev.mysql.com/get/mysql57-community-release-el7-11.noarch.rpm
# yum -y install gcc-c++ gperftools-devel mysql-community-devel
# cd /vagrant
# gcc -L/usr/lib64/mysql -lmysqlclient -lprofiler -std=gnu++0x main.cpp
# CPUPROFILE=prof.out CPUPROFILE_FREQUENCY=10000 ./a.out

(output example)
...
08:04:33 mysql_ping 0 (404)
08:04:33 mysql_ping 0 (405)
08:04:33 mysql_ping 0 (406)
08:04:33 mysql_ping 0 (407)
08:04:33 mysql_ping 0 (408)
08:04:33 mysql_ping 0 (409)
08:04:33 mysql_ping 0 (410)
08:04:33 mysql_ping 0 (411)
08:04:33 mysql_ping 0 (412)
(stop)

test program

Attachment: main.cpp (text/plain), 1.00 KiB.

Hello Nobuyuki,

Thank you for the bug report and testcase.
Could you please provide full Stacktrace (- please make it as private if you prefer) to confirm this issue at our end?

Thanks,
Chiranjeevi.

Hello  Chiranjeevi,

Thank you for responding.
Typical full stacktrace is here.

(gdb) bt
#0  yaSSL::SSL::GetError (this=this@entry=0x1dc5830) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/extra/yassl/src/yassl_int.cpp:1521
#1  0x00007f91d4866264 in yaSSL::receiveData (ssl=..., data=..., peek=peek@entry=false) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/extra/yassl/src/handshake.cpp:1051
#2  0x00007f91d484c40d in yaSSL::yaSSL_read (ssl=ssl@entry=0x1dc5830, buffer=buffer@entry=0x1dc3130, sz=sz@entry=4) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/extra/yassl/src/ssl.cpp:363
#3  0x00007f91d482b4f6 in vio_ssl_read (vio=0x1dbeee0, buf=0x1dc3130 "\001", size=<optimized out>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/vio/viossl.c:186
#4  0x00007f91d48084c3 in net_read_raw_loop (net=net@entry=0x1dbc660, count=4) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:672
#5  0x00007f91d4808767 in net_read_packet_header (net=0x1dbc660) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:762
#6  net_read_packet (net=0x1dbc660, complen=0x7ffd6aa8b4d0) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:822
#7  0x00007f91d48094fc in my_net_read (net=net@entry=0x1dbc660) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:899
#8  0x00007f91d47fd66b in cli_safe_read_with_ok (mysql=mysql@entry=0x1dbc660, parse_ok=parse_ok@entry=1 '\001', is_data_packet=is_data_packet@entry=0x0) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql-common/client.c:1055
#9  0x00007f91d48046df in cli_advanced_command (mysql=0x1dbc660, command=COM_PING, header=0x0, header_length=<optimized out>, arg=0x0, arg_length=0, skip_check=0 '\000', stmt=0x0) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql-common/client.c:1336
#10 0x00007f91d47f7186 in mysql_ping (mysql=<optimized out>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/libmysql/libmysql.c:935
#11 0x00000000004009bd in main ()

(gdb) bt
#0  vio_errno (vio=<optimized out>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/vio/viosocket.c:52
#1  0x00007f9a71187699 in vio_should_retry (vio=<optimized out>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/vio/viosocket.c:391
#2  0x00007f9a711654d6 in net_should_retry (net=0x20b9660, retry_count=<synthetic pointer>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:252
#3  net_read_raw_loop (net=net@entry=0x20b9660, count=4) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:678
#4  0x00007f9a71165767 in net_read_packet_header (net=0x20b9660) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:762
#5  net_read_packet (net=0x20b9660, complen=0x7fff209b2870) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:822
#6  0x00007f9a711664fc in my_net_read (net=net@entry=0x20b9660) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql/net_serv.cc:899
#7  0x00007f9a7115a66b in cli_safe_read_with_ok (mysql=mysql@entry=0x20b9660, parse_ok=parse_ok@entry=1 '\001', is_data_packet=is_data_packet@entry=0x0) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql-common/client.c:1055
#8  0x00007f9a711616df in cli_advanced_command (mysql=0x20b9660, command=COM_PING, header=0x0, header_length=<optimized out>, arg=0x0, arg_length=0, skip_check=0 '\000', stmt=0x0) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/sql-common/client.c:1336
#9  0x00007f9a71154186 in mysql_ping (mysql=<optimized out>) at /export/home2/pb2/build/sb_1-27500212-1520171517.98/rpm/BUILD/mysql-5.7.22/mysql-5.7.22/libmysql/libmysql.c:935
#10 0x00000000004009bd in main ()

I found this ticket when I was searching, but I do not know if that is relevant or not.
https://bugs.mysql.com/bug.php?id=88428

Hello Nobuyuki,

Thank you for the feedback.
Verified based on internal discussion with dev's.
To overcome hang issue end user can set this MYSQL_OPT_RETRY_COUNT as part of mysql_options.

Thanks,
Chiranjeevi.