mysql: packets.go: read tcp [ip-address]: connection timed out

I found it to be the state of the connection pool, where the pool thinks there still is a connection open. But in fact, it has been closed remotely by the mysqld.

Scroll up for my entire story and debugging: I verified this with netstat where I saw the Go application having a connection to port 3306 on the remote server. But yet, the remote server running MySql no longer had any open pipes (after the timeout I noted above). I did verify that upon making the application active again, opening many mysql connections, that I saw both open pipes on both servers. But again, after some time, the remote mysqld server would drop the open “idle” connection (still not sure if it is mysqld, or Windows Azure doing it).

The root problem is that the net package, and/or this mysql driver, does not detect the dropped connection and thinks that there is still an open idle connection - there isn’t. So upon the next attempt by the mysql driver to make a query, with this stale idle connection that doesn’t exist, it creates a block and eventually times out after a long period of time. Any additional hits to the mysql driver for queries works fine, as the connection pool simply creates new connections going forward - after that 1 idle connection (e.g. pooling the connections, use the idle open one for the first 1, then create new connections). New connections are fine; it is that idle one that is the problem because it simply isn’t connected.

I resolved my issues by getting rid of all idle connections. See my posts above for the history and resolutions. But in short:

db.SetMaxIdleConns(0) // this is the root problem! set it to 0 to remove all idle connections
db.SetMaxOpenConns(500) // or whatever is appropriate for your setup.

Had the same problem: Didn’t want to set SetMaxIdleConns to 0 since that would effectively disable connection pooling. What I did was changed SetConnMaxLifetime to a value that was less than the setting on MYSQL server that closed connections that were idle. MySQL was set to 10seconds before it closed an idle connection so I changed it to 9 seconds. Bug was fixed. The default value keeps idle connections as long as possible, so the connection pool thinks a particular connection is alive when in fact MySQL had already closed it. The connection pool then attempts to use the connection and you get the error.

So I had a theory… Since the MySql query is stalling on execution of an “idle” application for a long period of time, perhaps Windows Azure does something to that TCP connection. Was there a persistent connection in the goland mysql driver that maybe Azure doesn’t like across cloud services? (a cloud service is a collection of resources for scaling. e.g. all web servers in one cloud service to auto-scale up and down, all database servers in another cloud service, all backend jobs processing in another cloud service, etc). Perhaps Azure didn’t like a new tcp connection after being idle for so long?

So i set out to investigate these… Also, the SetMaxIdleConns() had me courious…

sudo netstat -tnp | grep wwwgo

Sure enough, this showed 1 single persistent connection from my wwwgo app to my mysql IP address and 3306 port - even after letting it sit for several hours without any interation, it was still open and persistent.

This got me thinking… Maybe Azure didn’t like long running tcp connections with no activity. So i set these:

db.SetMaxIdleConns(0)
db.SetMaxOpenConns(500) // matches my MySql my.cnf file settings

Running netstat shows no persistent connection now. And I have not seen the original problem since! I cannot reproduce the original problem any longer! Not only that, but now load-testing the site no longer gives too many files open error on a single CPu instance, nor do I have the i/o socket error error i got on multi-core MAXCPUS setting. Cool.

So the issue seems to be with a long running persistent connection that never closes.

I know I know… The next words out of anyone’s mouth are, “Are you sure you are calling rows.Close(), and that you are iterating over the entire collection? That will hold the connection open if you don’t!”

The answer is that I either do Scan() on single rows, or I follow this pattern for rows.Close() and iterating:

rows2, err := db.Query(
    "SELECT p.post_title, p.post_name "+
        "FROM wp_posts p "+
        "WHERE p.post_type='page' AND p.post_status='publish' AND p.post_date <= UTC_TIMESTAMP() "+
        "AND p.post_parent = (SELECT p2.ID FROM wp_posts p2 WHERE p2.post_name=? LIMIT 1) "+
        "ORDER BY p.menu_order",
    FooterPagesParentNameSlug)
if err != nil {
    log.Printf("ERROR in AllPages .Query() : %v", err)
} else {
    defer rows2.Close()
    c.AllFooterPages = make([]FooterPage, 0)
    for rows2.Next() {
        var name, slug string
        err := rows2.Scan(&name, &slug)
        if err != nil {
            log.Printf("ERROR in AllPages row.Scan() : %v", err)
        } else {
            p := FooterPage{
                Page: Page{
                    Title: name,
                    Slug:  slug,
                },
            }
            c.AllFooterPages = append(c.AllFooterPages, p)
        }
    }
}

Note that I call defer rows2.Close() only if there was no error. I have also guaranteed I am always iterating and always rows.Close() in this pattern. Some may say, “well, there still may be data in the rows and you should iterate over them.” well, during my load tests today of 1000 concurrent users off and on for 15m intervals several times today, there was only the 1 persistent connection open to mysql at all times. This tells me that rows.Close() is being called ,and I am iterating over all rows - else, I would have more persistent connections open, right?

Shouldn’t a long-running idle connection be dropped?

Entity Framework, for Microsoft SQL Server, doesn’t do this “long running” idle connection pooling. It closes all queries.

If it is to remain open, shouldn’t there be a timed “ping” across the wire to keep it active?

Similar to how Android tcp connections are handled in where you constantly send a ping to keep the connection alive.

Regarding your biggest question: read this part of our README and pay special attention to the link at the end. If I guess right, setting that parameter may help you and do what you expect from timeout. What you want is probably one of the server side timeouts, just read through the linked MySQL documentation for the matching one.

Answer 1: No, you should only Open() and Close() the DB once. It’s a connection pool, not a single connection. You only need one per user and server. Your main problem with the code above is to defer Close() in init - do not do that. Defer it in main. The deferred function is called when the scope is left - putting it in init will not help you there as init is done and Close is called before main is executed.

Answer 2: I don’t know what problems you have with Prepare, but I guess it’s that it is connected with the opening and closing of the connection pool. The prepared statements are invalid when the connection pool they are prepared in is closed.

Please get back to us here if that didn’t help you.

@eexit Did you read this comment?

14400 sec is too long. One minutes is enough for most use cases. Even if you configure entire your DC (OS, switch, router, etc…), TCP connection may be lost from various reasons. (bug in router firmware, unstable power voltage, electric nose, etc…)

(Happened to see this thread due to the Go ticket…)

This sounds like a plain, honest TCP timeout. I don’t know much about MySQL or the driver, but what usually happens is this:

1. The TCP connection is killed by some network device / server but it doesn’t tell the other end about it. This leaves the TCP connection in ESTABLISHED on the client’s end while its state is actually gone from the server.
2. Driver calls net.Conn.Write to send a query over, which ultimately effects a write() system call. The data fits into the OS’ buffers, and thus the call doesn’t block.
3. Now, with the data in its buffers, the operating system’s TCP stack starts sending the data to the remote end.
4. The driver calls net.Conn.Read. This will block since there’s nothing to read yet since the server hasn’t replied (it hasn’t even received the query, since there’s no healthy connection).
5. The TCP stack tries to send, re-send, re-send, etc. the data to the server. It will keep doing this for some specific amount of time (it was 15 minutes on our out-of-the-box Linux installation) before giving up, and then tells the client that the connection timed out.

The problem with setting a deadline is that for a lot of of apps it is either going to be annoyingly low and you’re risking failures on just genuinely slow queries (perhaps if the database is under heavier load), or it’ll still take annoyingly long before the deadline is reached, thus not really solving the problem.

What’s really worth looking into is why step number 1 happens in the first place, and fix that. TCP timeouts and/or reconfiguring the network settings/gear can usually get you quite far. For some apps, deadlines can be nice in addition, but I don’t think they’re usable as a general workaround.