↓Skip to main content

MySQL connection: "closing bad idle connection: EOF"

MySQL

Preface

Last year I encountered a Go MySQL connection error in production: ‘closing bad idle connection: EOF’. While this error doesn’t directly impact application functionality, it pollutes the logs with unnecessary messages. In this post, I’ll share my experience in diagnosing this unwanted error from source code.

Investigation Process

By searching the key terms from the error message, we can find related GitHub repository issues. From the issue comments, we learned that the maintainer doesn’t consider this a problem and suggests setting connMaxLifeTime to avoid these error messages. We also learned from the issue that this error occurs when the MySQL driver attempts to reuse a connection that has already been closed by the MySQL server."

Why MySQL Server Closes Connections

MySQL server has a configuration parameter called wait_timeout, which defines the number of seconds the server waits for activity on a non-interactive connection before closing it. By default, this value is set to 28800 seconds (8 hours). When a connection remains idle for longer than this timeout period, MySQL server will automatically close it to free up resources.

We can check the wait_timeout parameter using the following MySQL command. For more detailed information about this parameter, you can refer to my previous article about The difference between SESSION wait_timeout and GLOBAL wait_timeout.

MySQL [email protected]:(none)> SHOW VARIABLES LIKE '%timeout%';
+-----------------------------------+----------+
| Variable_name                     | Value    |
+-----------------------------------+----------+
| connect_timeout                   | 10       |
| delayed_insert_timeout            | 300      |
...
| wait_timeout                      | 28800    |
+-----------------------------------+----------+

Reproducing the Error

To better understand this error, let’s create a simple program to reproduce it with MySQL 5.7. The key is to make the MySQL server close an idle connection and then try to reuse it from the connection pool.

package main

import (
	"database/sql"
	"fmt"
	"log"
	"time"

	_ "github.com/go-sql-driver/mysql"
)

func main() {
	// Configure a DSN with minimal timeout settings to reproduce the error
	dsn := fmt.Sprintf("%s:%s@tcp(%s)/%s", "root", "123456", "127.0.0.1:3306", "playground")
	dsn += "?charset=utf8mb4&wait_timeout=10&parseTime=true"

	db, err := sql.Open("mysql", dsn)
	if err != nil {
		log.Fatal(err)
	}
	defer db.Close()

	// Set connection pool parameters
	db.SetMaxOpenConns(1) // Limit max connections to 1 to force connection reuse
	db.SetMaxIdleConns(1) // Keep one idle connection
	// Note: We don't set ConnMaxLifetime here to let connections expire naturally

	// First query to establish connection
	log.Println("First query at:", time.Now().Format("2006-01-02 15:04:05"))

	var result int
	err = db.QueryRow("SELECT 1").Scan(&result)
	if err != nil {
		log.Fatal(err)
	}

	// Wait long enough for MySQL server to close the connection
	log.Println("Waiting for connection to be closed by server...")
	time.Sleep(12 * time.Second)

	log.Println("Second query at:", time.Now().Format("2006-01-02 15:04:05"))
	err = db.QueryRow("SELECT 1").Scan(&result)
	if err != nil {
		log.Printf("Query error: %v", err)
	}
}

After running the program, we can see from the output that we have successfully reproduced the error:

2024/12/15 23:46:26 First query at: 2024-12-15 23:46:26
2024/12/15 23:46:26 Waiting for connection to be closed by server...
[mysql] 2024/12/15 23:46:38 packets.go:122: closing bad idle connection: EOF

Source Code Analysis

Now that we’ve reproduced the error, let’s dive into the Go MySQL driver source code to understand how this error occurs.

Go MySQL Driver is an implementation of Go’s database/sql/driver interface. You only need to import the driver and can use the full database/sql API then.

Since github.com/go-sql-driver/mysql implements all API interfaces of database/sql/driver, we can analyze the error by following the call sequence.

  1. High-level SQL Interface
// sql.go:1845
func (db *DB) QueryRow(query string, args ...any) *Row {
	return db.QueryRowContext(context.Background(), query, args...)
}

// sql.go:1831 
func (db *DB) QueryRowContext(ctx context.Context, query string, args ...any) *Row {
	rows, err := db.QueryContext(ctx, query, args...)
	return &Row{rows: rows, err: err}
}

// sql.go:1727
func (db *DB) QueryContext(ctx context.Context, query string, args ...any) (*Rows, error)
  1. Connection Management
// sql.go:1564
// maxBadConnRetries is the number of maximum retries if the driver returns
// driver.ErrBadConn to signal a broken connection before forcing a new
// connection to be opened.
const maxBadConnRetries = 2

func (db *DB) retry(fn func(strategy connReuseStrategy) error) error {
	for i := int64(0); i < maxBadConnRetries; i++ {
		err := fn(cachedOrNewConn)
		// retry if err is driver.ErrBadConn
		if err == nil || !errors.Is(err, driver.ErrBadConn) {
			return err
		}
	}

	return fn(alwaysNewConn)
}

// sql.go:1748
func (db *DB) query(ctx context.Context, query string, args []any, strategy connReuseStrategy) (*Rows, error)
  1. Connection Pool Logic
// sql.go:1309
// it will try to reuse the idle connection
func (db *DB) conn(ctx context.Context, strategy connReuseStrategy) (*driverConn, error) {
    ...

	// Prefer a free connection, if possible.
	last := len(db.freeConn) - 1
	if strategy == cachedOrNewConn && last >= 0 {
		// Reuse the lowest idle time connection so we can close
		// connections which remain idle as soon as possible.
		conn := db.freeConn[last]
		db.freeConn = db.freeConn[:last]
		conn.inUse = true
		if conn.expired(lifetime) {
			db.maxLifetimeClosed++
			db.mu.Unlock()
			conn.Close()
			return nil, driver.ErrBadConn
		}
		db.mu.Unlock()

		// Reset the session if required.
		if err := conn.resetSession(ctx); errors.Is(err, driver.ErrBadConn) {
			conn.Close()
			return nil, err
		}

		return conn, nil
	}
    ...
}
  1. Driver Implementation
// sql.go:1761
func (db *DB) queryDC(ctx, txctx context.Context, dc *driverConn, releaseConn func(error), query string, args []any) (*Rows, error)

// ctxutil.go:46
func ctxDriverQuery(ctx context.Context, queryerCtx driver.QueryerContext, queryer driver.Queryer, query string, nvdargs []driver.NamedValue) (driver.Rows, error)

// go-sql-driver/[email protected]/connection.go:502
func (mc *mysqlConn) QueryContext(ctx context.Context, query string, args []driver.NamedValue) (driver.Rows, error)

// go-sql-driver/[email protected]/connection.go:369
func (mc *mysqlConn) query(query string, args []driver.Value) (*textRows, error)

// go-sql-driver/[email protected]/packets.go:438
func (mc *mysqlConn) writeCommandPacketStr(command byte, arg string) error

// go-sql-driver/[email protected]/packets.go:92
func (mc *mysqlConn) writePacket(data []byte) error

Solution

The most straightforward way to avoid this error is setting an appropriate connMaxLifetime that is shorter than MySQL’s wait_timeout. Here’s how to configure it:

// Set maxConnLifetime less than wait_timeout (28800s)
db.SetConnMaxLifetime(time.Hour)  // 3600s < 28800s

Reference