Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Whackamole queries when KILL'ing #295

Closed
xaprb opened this issue Dec 17, 2014 · 2 comments · Fixed by #302
Closed

Whackamole queries when KILL'ing #295

xaprb opened this issue Dec 17, 2014 · 2 comments · Fixed by #302
Labels

Comments

@xaprb
Copy link

xaprb commented Dec 17, 2014

Using the following code,

package main

import (
   "database/sql"
   _ "github.com/go-sql-driver/mysql"
   "log"
)

func main() {
   db, err := sql.Open("mysql", "root:@tcp(:12830)/")
   if err != nil {
      log.Fatal(err)
   }
   defer db.Close()

   var s string
   err = db.QueryRow("SELECT SLEEP(300)").Scan(&s)
   if err != nil {
      log.Fatal(err)
   }
   log.Println(s)
}

And running it, I can see in MySQL,

mysql> show full processlist;
+----+------+-----------------+------+---------+------+------------+-----------------------+
| Id | User | Host            | db   | Command | Time | State      | Info                  |
+----+------+-----------------+------+---------+------+------------+-----------------------+
| 95 | root | ::1:62318       | NULL | Query   |    0 | init       | show full processlist |
| 96 | root | 127.0.0.1:62446 | NULL | Query   |    7 | User sleep | SELECT SLEEP(300)     |
+----+------+-----------------+------+---------+------+------------+-----------------------+
2 rows in set (0.00 sec)

mysql> kill query 96;
Query OK, 0 rows affected (0.00 sec)

mysql> show full processlist;
+----+------+-----------+------+---------+------+-------+-----------------------+
| Id | User | Host      | db   | Command | Time | State | Info                  |
+----+------+-----------+------+---------+------+-------+-----------------------+
| 95 | root | ::1:62318 | NULL | Query   |    0 | init  | show full processlist |
+----+------+-----------+------+---------+------+-------+-----------------------+
1 row in set (0.00 sec)

The program prints out this:

2014/12/17 16:32:34 1

Now, if instead I kill the connection,

mysql> show full processlist;
+----+------+-----------------+------+---------+------+------------+-----------------------+
| Id | User | Host            | db   | Command | Time | State      | Info                  |
+----+------+-----------------+------+---------+------+------------+-----------------------+
| 95 | root | ::1:62318       | NULL | Query   |    0 | init       | show full processlist |
| 97 | root | 127.0.0.1:62452 | NULL | Query   |    5 | User sleep | SELECT SLEEP(300)     |
+----+------+-----------------+------+---------+------+------------+-----------------------+
2 rows in set (0.00 sec)

mysql> kill 97;
Query OK, 0 rows affected (0.00 sec)

mysql> show full processlist;
+----+------+-----------------+------+---------+------+------------+-----------------------+
| Id | User | Host            | db   | Command | Time | State      | Info                  |
+----+------+-----------------+------+---------+------+------------+-----------------------+
| 95 | root | ::1:62318       | NULL | Query   |    0 | init       | show full processlist |
| 98 | root | 127.0.0.1:62454 | NULL | Query   |    3 | User sleep | SELECT SLEEP(300)     |
+----+------+-----------------+------+---------+------+------------+-----------------------+
2 rows in set (0.00 sec)

So the statement got retried. This is, of course, because the connection got killed and the driver returned the error ErrBadConn. The program prints out:

[MySQL] 2014/12/17 16:35:41 packets.go:32: unexpected EOF

From the docs,

To prevent duplicate operations, ErrBadConn should NOT be returned if there's a possibility that the database server might have performed the operation. Even if the server sends back an error, you shouldn't return ErrBadConn.

What's happening here is that the query is a little bit unkillable if you kill the connection. It'll retry up to 10 times.

Is there any way we can detect that there was a kill? Given #185 I think the answer is "no" but I thought I should ask here anyway. From the client's point of view I think a KILL does look just like the connection was closed for some reason.

@arnehormann
Copy link
Member

@julienschmidt I think this is a bug, we violate the spec and driver.ErrBadConn must not be returned unless it's either in handshake code or before any packet hits the network.

Client code has to deal with query errors and reissuing them. I'm not sure about potential problems with legacy code, but we should change this.

After review of the code, I propose these fixes:
Change driver.ErrBadConn to ErrInvalidConn in packets.go for readPacket and writePacket and also in statement.go for Close (makes little sense to retry that anyway). In packets.go, intercept the return value from writeAuthPacket and writeOldAuthPacket, change it to driver.ErrBadConn if it's not nil.

Thoughts?

@tomponline
Copy link

@arnehormann I agree with your proposal, as currently if the connection is killed mid query, it is re-tried transparently and the calling app is not aware.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants