QueryContext() timeout can kill the db connection, but ExecContext() can't

[navygg]

Issue description

Tell us what should happen and what happens instead

I pass a timeout context to QueryContext(), then execute a long time running query sql. When the ctx timeout, QueryContext() return err, and the db connection is killed and missing from 'show processlist'.

Then I pass a timeout context to ExecContext(), execute a long time running sql. When the ctx timeout, ExecContext() return err, but the sql is still running and the db connection also exists in 'show processlist'.

Example code

If possible, please enter some example code here to reproduce the issue.

package main

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

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

func main() {
	db, err := sql.Open("mysql", "root:test@tcp(127.0.0.1:3306)/test?charset=latin1&autocommit=1&parseTime=true&loc=Local&timeout=3s")
	if err != nil {
		log.Fatalf("open db err: %v\n", err)
	}
	db.SetMaxOpenConns(10)

	if err := db.Ping(); err != nil {
		log.Fatalf("ping err: %v\n", err)
	}

	queryCtx(db)
	execCtx(db)

	time.Sleep(1000 * time.Second)
}

func queryCtx(db *sql.DB) {
	ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
	defer cancel()

	rows, err := db.QueryContext(ctx, "select sleep(100)")
	if err != nil {
		log.Printf("QueryContext err: %v\n", err)
		return
	}
	defer rows.Close()

	for rows.Next() {
		var sleepTime int
		if err := rows.Scan(&sleepTime); err != nil {
			log.Printf("Scan err: %v\n", err)
			return
		}

		log.Printf("sleep %d\n", sleepTime)
	}

	if err := rows.Err(); err != nil {
		log.Printf("rows err: %v\n", err)
		return
	}
}

func execCtx(db *sql.DB) {
	ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
	defer cancel()

	_, err := db.ExecContext(ctx, "select benchmark(99999999, md5('I like golang'))")
	if err != nil {
		log.Printf("ExecContext error: %v\n", err)
		return
	}
}

Error log

If you have an error log, please paste it here.

the above code snippets' output:
2020/11/25 11:44:55 QueryContext err: context deadline exceeded
2020/11/25 11:45:00 ExecContext error: context deadline exceeded

Configuration

Driver version (or git SHA):
github.com/go-sql-driver/mysql v1.5.0

Go version: run go version in your console
go1.14.2 darwin/amd64

Server version: E.g. MySQL 5.6, MariaDB 10.0.20
MySQL 5.7.17

Server OS: E.g. Debian 8.1 (Jessie), Windows 10
macOS Catalina

[methane]

I pass a timeout context to QueryContext(), then execute a long time running query sql. When the ctx timeout, QueryContext() return err, and the db connection is killed and missing from 'show processlist'.
Then I pass a timeout context to ExecContext(), execute a long time running sql. When the ctx timeout, ExecContext() return err, but the sql is still running and the db connection also exists in 'show processlist'.

This is not difference between Query and Exec. MySQL detects connection closed from client during sleep, but not during regular query.

See #731, and See #731 (comment) for workaround.

[navygg]

I pass a timeout context to QueryContext(), then execute a long time running query sql. When the ctx timeout, QueryContext() return err, and the db connection is killed and missing from 'show processlist'.
Then I pass a timeout context to ExecContext(), execute a long time running sql. When the ctx timeout, ExecContext() return err, but the sql is still running and the db connection also exists in 'show processlist'.

This is not difference between Query and Exec. MySQL detects connection closed from client during sleep, but not during regular query.

See #731, and See #731 (comment) for workaround.

Really appreciate! two questions:

1. Can you give me a reference of the point: "MySQL detects connection closed from client during sleep, but not during regular query."?
2. When debug the above example code use Wireshark, I found there is a RST from client to mysql during QuextContext() after FIN. But the RST not appear during ExecContext() instead of Keep-Alive every 30 seconds after FIN. Why? Which sentence of go-sql-driver triggered RST? If there is a RST during ExecContext(), does the sql server will cancel the exec?
   
   

[methane]

• Can you give me a reference of the point: "MySQL detects connection closed from client during sleep, but not during regular query."?

I don't have any reference. This is just my observations. I tested many MySQL behaviors by myself.
Anyway, please use same query to compare Exec and Query behavior. When query is different, behavior may be different.

When debug the above example code use Wireshark, I found there is a RST from client to mysql during QuextContext() after FIN. But the RST not appear during ExecContext() instead of Keep-Alive every 30 seconds after FIN. Why? Which sentence of go-sql-driver triggered RST? If there is a RST during ExecContext(), does the sql server will cancel the exec?

I don't know. But before the RST, MySQL server sent FIN, ACK to client in QueryContext. On the other hand, MySQL server didn't send FIN, ACK (because query is not sleep). That's why TCP connection is alive.

[navygg]

@methane very thanks!
I used same sql in Exec and Query, and proved your point: "This is not difference between Query and Exec. "
Is the sleep() sql, the MySQL server can send FIN, ACK, but the benchmark() can't. This is what you said: "MySQL detects connection closed from client during sleep, but not during regular query."