MySQL Bugs: #100983: the connection is disconnected, but the server CPU consumption is up to 700+%

Bug #100983	the connection is disconnected, but the server CPU consumption is up to 700+%
Submitted:	29 Sep 2020 6:27	Modified:	15 Oct 2020 13:44
Reporter:	Jhonson Leo	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	Connector / J	Severity:	S2 (Serious)
Version:	5.6.32	OS:	Red Hat ( 4.4.7-18)
Assigned to:	MySQL Verification Team	CPU Architecture:	Any

Description:
After the application shutdown, the database connection is disconnected, but the server CPU consumption is up to 700+%

How to repeat:
<dependency>
    <groupId>mysql</groupId>
    <artifactId>mysql-connector-java</artifactId>
    <version>5.1.37</version>
</dependency>

About 200 connections are cached（Our project）
In addition,Some services are also connecting to the database

SHOW STATUS LIKE 'Max_used_connections'; 
> 590
SHOW PROCESSLIST;
> About 471 records
When our project shutdown, the CPU of database on the server will rise.
And after restarting the database, it will return to normal
-------------------------------------------------------------------
top - 06:27:21 up 13 days, 16:32,  1 user,  load average: 341.79, 336.18, 323.27
Tasks: 495 total,   2 running, 493 sleeping,   0 stopped,   0 zombie
Cpu(s): 99.9%us,  0.1%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  65839572k total, 64941068k used,   898504k free,   416408k buffers
Swap:  8388604k total,   157572k used,  8231032k free, 55294736k cached
                                                                                                                          PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
27172 mysql5    20   0 3754m 1.6g 8960 S 796.3  2.5   1855:13 mysqld

Hi Mr. Leo,

Thank you for your bug report.

In order to narrow down the problem, can you send us a processlist after all your users have disconnected from MySQL server. Provided that CPU consumption is 700 %. Also, let us know ho many cores does that machine have ......

Mr. Leo,

One more info is required. Since our Connector / J uses thread pool, can you let us know number of connections that are still open within Connector / J.

Hi,

> 
> <dependency>

What are you using as orm/pool here? Hibernate?

> When our project shutdown, the CPU of database on the server will rise.

You are saying that after you disconnect from the database you have high CPU load on the database server?

> 27172 mysql5    20   0 3754m 1.6

MySQL is here loading your IO. What does SHOW PROCESSLIST at this point shows (when your app is disconnected)? Please upload config file too.

kind regards
Bogdan

Hi,
  Thanks for your response.I'm so sorry that I didn't reply in time due to my vacation.

----------------------------------------------
[~]$ cat /proc/cpuinfo | grep name | cut -f2 -d: | uniq -c
      8  Intel(R) Core(TM) i7-7700K CPU @ 4.20GHz
[~]$ cat /proc/cpuinfo| grep "cpu cores"| uniq
cpu cores       : 4

----------------------------------------------
When the application starts, 700 connections open within Connector / J.

----------------------------------------------
<dependency>
Not Hibernate, only array like stack save connections.

Class.forName(dbDriver);
pool = new ConnStack(queryCapacity);
Connection conn = null;
for (int i = 0; i < queryCapacity; i++) {
   if (user == null || password == null)
       conn = DriverManager.getConnection(dbUrl);
   else
       conn = DriverManager.getConnection(dbUrl, user, password);
   pool.push(conn);
} // end for
------------------------------------

Hi, 

> When our project shutdown, the CPU of database on the server will rise.
You are saying that after you disconnect from the database you have high CPU load on the database server?

yes,the server have high CPU load on the database server after disconnecting from the database

----------------------------------------------
# The configuration information of my.cnf is as follows：
# For advice on how to change settings please see
# http://dev.mysql.com/doc/refman/5.6/en/server-configuration-defaults.html
[client]
default-character-set=utf8
port=3306
socket=/new/mysql5/mysql_5.6.32/data/mysql5.sock
[mysql]
default-character-set=utf8
[mysqld]

# Remove leading # and set to the amount of RAM for the most important data
# cache in MySQL. Start at 70% of total RAM for dedicated server, else 10%.
# innodb_buffer_pool_size = 128M

# Remove leading # to turn on a very important data integrity option: logging
# changes to the binary log between backups.
# log_bin

# These are commonly set, remove the # and set as required.

basedir=/new/mysql5/mysql_5.6.32
datadir=/new/mysql5/mysql_5.6.32/data
pid-file=/new/mysql5/mysql_5.6.32/data/mysql5.pid
socket=/new/mysql5/mysql_5.6.32/data/mysql5.sock
port=3306
server_id=1

# Remove leading # to set options mainly useful for reporting servers.
# The server defaults are faster for transactions and fast SELECTs.
# Adjust sizes as needed, experiment to find the optimal values.
# join_buffer_size = 128M
# sort_buffer_size = 2M
# read_rnd_buffer_size = 2M 

character-set-server=utf8
log-bin=/new/mysql5/mysql_5.6.32/data/mysql3306

sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES

binlog_format=ROW
expire_logs_days=35
max_connections=3000
open-files-limit=65535
lower_case_table_names=1
skip-name-resolve

innodb_print_all_deadlocks=1
transaction-isolation=READ-COMMITTED

innodb_log_file_size=512M
innodb_buffer_pool_size=2048M
max_allowed_packet=64M

slow_query_log=ON
slow_query_log_file=/new/mysql5/mysql_5.6.32/data/mysql-slow.log
long_query_time=10

# innodb_force_recovery=2

event_scheduler=1
log_bin_trust_function_creators=1
innodb_flush_log_at_trx_commit=2
#wait_timeout=300

SHOW PROCESSLIT;
See the attachment for the contents

See the attachment for the contents

Attachment: show processlist.xlsx (application/vnd.openxmlformats-officedocument.spreadsheetml.sheet, text), 26.78 KiB.

Hi,

Looks like your app is not releasing connections.

What happens if you disconnect from the mysql (so no active connections).

From what I see this is a bug in your "only array like stack save connections". You need to use a proper connection pool that will 
 - properly handle every new "take connection"
 - properly handle every "release connection"
 - properly handle shutdown of the app by "closing all connections"

all best
Bogdan

Hi Bogdan,

  Thanks for your response.
   
  According to our analysis, our team doesn't think it is caused by the wrong connection release of app.

  First, the app is shutdown,a process in the operating system has died. This seems to have nothing to do with whether to release the connection. Second, The program fragment I give is just to illustrate the connection establishment and storage. Our project architecture has been running online for many years. In theory, it should not be the fault of the architecture layer. In addition, According to the query results of "show processlist", our connection has been released. 

  I don't know if my explanation is clear.And I hope it helps.

all best
Leo

Hi,

> In addition, According to the query results of "show processlist", our connection has been released. 

But you stated:
> SHOW PROCESSLIST;
> > About 471 records

so after you shutdown your application there is still 471 connections hanging meaning your "pool" did not disconnect from the server.

all best
Bogdan

Hi,
 
 The rest of the connections are used by other apps, not by app I stopped. 
 
 Even if I shut down other apps, it will not reduce the CPU consumption of MySQL server.

all best
Leo

Hi,

I cannot reproduce that. I can make 1000 concurrent connections using connector/j, execute queries, disconnect and cpu usage on the server will be around zero. You are doing something that's loading the cpu, maybe there is a bug but making connections from connector/j is not. What you are doing trough those connections might trigger it. 

all best