Bug #105104 MySQL dosen't response to connection abortion while executing query in javacliet
Submitted: 2 Oct 2021 2:51 Modified: 4 Oct 2021 10:41
Reporter: Brian Yue (OCA) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:8.0.25 OS:Any (rhel-7.4)
Assigned to: MySQL Verification Team CPU Architecture:Any (x86-64)
Tags: abort connection, java, no response

[2 Oct 2021 2:51] Brian Yue
Description:
Hello, dear verification team,

  I tried to execute a statement which will cost quite long time through java client with `useCursorFetch=true&useServerPrepStmts=true`. In the statement I execute a `select * from yxx.t1` sql command, and `yxx.t1` is a really big table (16,000,000 records). After the java program starts running, I kill it with `pkill`, and after that I have checked that the tcp connection is alreay vanished, but the `select` command is still running (checked with `show processlist;`) for quite long time. So I guess the sql command doesn't response to connection abortion.

How to repeat:
# 1. Firstly we create a really big table
create database yxx;
use yxx;

create table t1 (id int primary key, age int);

insert into t1 values (1,1);
insert into t1 values (2,2);
insert into t1 select id+2, age from t1;
insert into t1 select id+4, age from t1;
insert into t1 select id+8, age from t1;
insert into t1 select id+16, age from t1;
insert into t1 select id+32, age from t1;
insert into t1 select id+64, age from t1;
insert into t1 select id+128, age from t1;
insert into t1 select id+256, age from t1;
insert into t1 select id+512, age from t1;
insert into t1 select id+1024, age from t1;
insert into t1 select id+1024*2, age from t1;
insert into t1 select id+1024*4, age from t1;
insert into t1 select id+1024*8, age from t1;
insert into t1 select id+1024*16, age from t1;
insert into t1 select id+1024*32, age from t1;
insert into t1 select id+1024*64, age from t1;
insert into t1 select id+1024*128, age from t1;
insert into t1 select id+1024*256, age from t1;
insert into t1 select id+1024*512, age from t1;
insert into t1 select id+1024*1024, age from t1;
insert into t1 select id+1024*1024*2, age from t1;
insert into t1 select id+1024*1024*4, age from t1;
insert into t1 select id+1024*1024*8, age from t1;
insert into t1 select id+1024*1024*16, age from t1;
insert into t1 select id+1024*1024*32, age from t1;

# 2. Create a java file `Test.java` with the following code (Of course, ip and port info should be modified)

```
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.Statement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.util.ArrayList;
import java.util.Date;
import java.text.SimpleDateFormat;

public class Test {

    private static Connection get_conn() throws Exception {
        String driverClassName="com.mysql.jdbc.Driver";
        String url="jdbc:mysql://10.229.31.41:6310/yxx?useCursorFetch=true&useServerPrepStmts=true";
        String username="root";
        String password="db10$ZTE";

        Class.forName(driverClassName);
        Connection con=DriverManager.getConnection(url,username,password);

        return con;
    }

    private static void query_big(Connection con) throws Exception {
        String sql2= "select * from yxx.t1";

        Statement stmt =con.createStatement();
        stmt.setFetchSize(1000);
        ResultSet rs1 = stmt.executeQuery(sql2);

        while (rs1.next()) {
        }

        rs1.close();
        stmt.close();
    }

    private static void run_test() throws Exception {
        Connection con = get_conn();
        query_big(con);
        con.close();
    }

    public static void main(String[] args) throws Exception {
        run_test();
    }
}

```

# and mysql-connector-java-8.0.19.jar file should be prepared

# 3. compile and run the java program

# run the following command in Linux shell
javac Test.java && java -cp ./:mysql-connector-java-8.0.19.jar Test

# now we can find the tcp connection with netstat
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
tcp6       0      0 10.229.31.7:11974       10.229.31.41:6310       ESTABLISHED 47616/java
[root@localhost ~]#

# 4. now we can check that the Command is running through `show processlist` in MySQL

mysql> show processlist;
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time | State                  | Info                 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 3160 | Waiting on empty queue | NULL                 |
| 10 | root            | localhost         | NULL | Query   |    0 | init                   | show processlist     |
| 19 | root            | 10.229.31.7:10556 | yxx  | Execute |    1 | executing              | select * from yxx.t1 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
3 rows in set (0.01 sec)

# 5. kill the java program with kill

[yxx_sysbench_1@localhost ~]$ ps x | grep java
41485 pts/1    Sl+    0:00 java -cp ./:mysql-connector-java-8.0.19.jar Test
42640 pts/5    S+     0:00 grep --color=auto java
[yxx_sysbench_1@localhost ~]$
[yxx_sysbench_1@localhost ~]$ kill -9 41485
[yxx_sysbench_1@localhost ~]$

# 6. Check the tcp connection repeatedly until it is vanished
[root@localhost ~]#
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
tcp6       0      0 10.229.31.7:11974       10.229.31.41:6310       FIN_WAIT2   -
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
tcp6       0      0 10.229.31.7:11974       10.229.31.41:6310       FIN_WAIT2   -
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
tcp6       0      0 10.229.31.7:11974       10.229.31.41:6310       FIN_WAIT2   -
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
tcp6       0      0 10.229.31.7:11974       10.229.31.41:6310       FIN_WAIT2   -
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
您在 /var/spool/mail/root 中有邮件
[root@localhost ~]# netstat -anp | grep "10.229.31.41"
[root@localhost ~]#

# 7. Check `show processlist` again in MySQL
mysql> show processlist;
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time | State                  | Info                 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 3355 | Waiting on empty queue | NULL                 |
| 10 | root            | localhost         | NULL | Query   |    0 | init                   | show processlist     |
| 19 | root            | 10.229.31.7:10556 | yxx  | Execute |  196 | executing              | select * from yxx.t1 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
3 rows in set (0.00 sec)

# we can see that, the command is still running

mysql> show processlist;
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time | State                  | Info                 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 3414 | Waiting on empty queue | NULL                 |
| 10 | root            | localhost         | NULL | Query   |    0 | init                   | show processlist     |
| 19 | root            | 10.229.31.7:10556 | yxx  | Execute |  255 | executing              | select * from yxx.t1 |
+----+-----------------+-------------------+------+---------+------+------------------------+----------------------+
3 rows in set (0.00 sec)

Suggested fix:
nope
[2 Oct 2021 7:45] MySQL Verification Team
seen https://bugs.mysql.com/bug.php?id=78809 ?
[3 Oct 2021 2:01] Brian Yue
Hello,
  The problem I'm encountering is similar with `https://bugs.mysql.com/bug.php?id=78809`, but there is a difference.
  If the query is running with java client, the query will keep running forever util finished; But if the query is running (prepare & execute) through mysql client in linux shell, the query will stop in several seconds. So I don't think this problem is related with long query only, maybe some other reason is also related (implementation difference ?).

# 1. running the query with prepared statement in mysql shell client
mysql> prepare ps from 'select * from yxx.t1' ;
Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> execute ps;

# 2. we can find the process
mysql> show processlist;
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time  | State                  | Info                 |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 86058 | Waiting on empty queue | NULL                 |
| 26 | root            | 10.229.31.7:20085 | NULL | Query   |     2 | executing              | select * from yxx.t1 |
| 27 | root            | localhost         | NULL | Query   |     0 | init                   | show processlist     |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
3 rows in set (0.00 sec)

# 3. make the mysql cient die
[root@localhost ~]# ps -ef | grep mysql
yxx_sys+ 27076 25440  0 09:38 pts/2    00:00:00 mysql -uroot -px xxxxxx -h10.229.31.41 -P6310
root     28627 43682  0 09:40 pts/5    00:00:00 grep --color=auto mysql
[root@localhost ~]# kill -9 27076
[root@localhost ~]# ps -ef | grep mysql
root     29008 43682  0 09:41 pts/5    00:00:00 grep --color=auto mysql

mysql> execute ps;
Killed

# 4. After several seconds, the process vanished
mysql> show processlist;
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time  | State                  | Info                 |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 86099 | Waiting on empty queue | NULL                 |
| 26 | root            | 10.229.31.7:20085 | NULL | Query   |    43 | executing              | select * from yxx.t1 |
| 27 | root            | localhost         | NULL | Query   |     0 | init                   | show processlist     |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
3 rows in set (0.00 sec)

mysql> show processlist;
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time  | State                  | Info                 |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 86101 | Waiting on empty queue | NULL                 |
| 26 | root            | 10.229.31.7:20085 | NULL | Query   |    45 | executing              | select * from yxx.t1 |
| 27 | root            | localhost         | NULL | Query   |     0 | init                   | show processlist     |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
3 rows in set (0.00 sec)

mysql> show processlist;
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
| Id | User            | Host              | db   | Command | Time  | State                  | Info                 |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
|  6 | event_scheduler | localhost         | NULL | Daemon  | 86103 | Waiting on empty queue | NULL                 |
| 26 | root            | 10.229.31.7:20085 | NULL | Query   |    47 | executing              | select * from yxx.t1 |
| 27 | root            | localhost         | NULL | Query   |     0 | init                   | show processlist     |
+----+-----------------+-------------------+------+---------+-------+------------------------+----------------------+
3 rows in set (0.00 sec)

mysql> show processlist;
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
| Id | User            | Host      | db   | Command | Time  | State                  | Info             |
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
|  6 | event_scheduler | localhost | NULL | Daemon  | 86105 | Waiting on empty queue | NULL             |
| 27 | root            | localhost | NULL | Query   |     0 | init                   | show processlist |
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
2 rows in set (0.00 sec)

mysql> show processlist;
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
| Id | User            | Host      | db   | Command | Time  | State                  | Info             |
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
|  6 | event_scheduler | localhost | NULL | Daemon  | 86627 | Waiting on empty queue | NULL             |
| 27 | root            | localhost | NULL | Query   |     0 | init                   | show processlist |
+----+-----------------+-----------+------+---------+-------+------------------------+------------------+
2 rows in set (0.00 sec)
[4 Oct 2021 10:41] MySQL Verification Team
Hi Brian,

This is a duplicate of bug #78809 and if you see in the bug #78809 it is specifically mentioned that inconsistencies in how different queries behave (for some the query will stop if connection is lost and for others it will not) is part of the bug.

Thanks for your interest!