On server restart clients get this error: MySQL error: commands out of sync. You can't run this command now

[tomponline]

Issue description

When using a persistent connection to a MySQL server, if the server is restarted, the old connection is left in a CLOSE_WAIT state on the client (suggesting the Go program has not detected the socket was closed).

E.g.

 service mysql restart
 netstat -tnp 
 tcp       35     0 127.0.0.1:51890             127.0.0.1:3306              CLOSE_WAIT  7662/db

This means that the next time the Go program tries to run a query, the dead connection is used and we get the error:

MySQL error: commands out of sync. You can't run this command now

The dead connection is then removed by the SQL drive and reconnects to the server.

Further queries run OK.

Example code

package main

import _ "github.com/go-sql-driver/mysql"
import "database/sql"
import "fmt"
import "time"

func main() {

    db, err := sql.Open("mysql", "root:@tcp(127.0.0.1:3306)/mysql")

        if err != nil {
                fmt.Println("Open error: ", err)
                return
        }

    err = db.Ping()

        if err != nil {
                fmt.Println("Ping error: ", err)
                return
        }
    fmt.Println("Ping OK")

        var connId int

        for {
                if err := db.QueryRow("SELECT CONNECTION_ID()").Scan(&connId); err != nil {
                        fmt.Println("MySQL error: ", err)
                        time.Sleep(10 * time.Second)
                        continue
                }
                fmt.Println("Conn ID: ", connId)
                time.Sleep(10 * time.Second)
        }

}

Error log

[root@tpel6 ~]# go run db.go 
Ping OK
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
Conn ID:  1519
MySQL error:  commands out of sync. You can't run this command now
[mysql] 2016/04/21 11:55:38 packets.go:405: busy buffer
[mysql] 2016/04/21 11:55:38 packets.go:386: busy buffer
Conn ID:  11
Conn ID:  11
Conn ID:  11
Conn ID:  11

Configuration

Driver version (or git SHA):
"ImportPath": "github.com/go-sql-driver/mysql",
"Comment": "v1.2-194-g7ebe0a5",
"Rev": "7ebe0a500653eeb1859664bed5e48dec1e164e73"

Go version: run go version in your console
go version go1.6.2 linux/amd64

Server version: E.g. MySQL 5.6, MariaDB 10.0.20
Server version: 10.0.24-MariaDB MariaDB Server

Server OS: E.g. Debian 8.1 (Jessie), Windows 10
CentOS 6.7 x86_64

[tomponline]

I've been having a play with the source code and narrowed the issue down to line

https://github.com/go-sql-driver/mysql/blob/master/packets.go#L48

If I put this small change in place after line 51 it fixes it:

 if data[3] == 0 {
    mc.Close()
    return nil, driver.ErrBadConn
}

Is this OK do you think or does it break something else?

Thanks
Tom

[methane]

See #302.
We can't use ErrBadConn after sending any query.

[julienschmidt]

Is this fixed now since we merged #302?

[yakir-stratoscale]

Is this fixed? I encountered the same issue

[methane]

I don't think we will "fix" this issue because it's just an expected behavior.

When using connection pool, restarting server will cause some errors on client side.
[DB.SetConnMaxLifetime(]https://golang.org/pkg/database/sql/#DB.SetConnMaxLifetime) will mitigate this issue, but can't solve this issue completely.

True solutions are:

• Ignore these expected errors.
• Implement retry in application. (Driver can't do it automatically because driver can't understand the query)
• Stop clients before restarting server.

[sewi-cpan]

The issue seems to keep half-open connections in CLOSE_WAIT state running the process out of FDs.

MySQL doesn't show open connections for these in SHOW PROCESSLIST and has a relatively low wait_timeout set, so this probably happens if MySQL terminates a connection due to timeout and the Go part doesn't ever detect this.

[methane]

@sewi-cpan Have you used SetConnMaxLifetime?
It has many benefits. Closing CLOSE_WAIT connection is one of benefit of the API.
When you configured DB.SetConnMaxLifetime(time.Seconds * 10), CLOSE_WAIT connections
will disappear in 10 seconds.

When using this driver, I think short SetConnMaxLifetime is mandatory.
It's mandatory because of design of MySQL and database/sql, not a bug of this driver.