ExecContext should return error if it is canceled during execution

[cia-rana]

Issue description

mysqlConn.ExecContext uses mysqlConn.watchCancel to decide if the ctx passed as an argument is canceled, so if the ctx is canceled before the decision, it returns an error. However, mysqlConn.ExecContext does not return an error even if the ctx is cancelled during or after mysqlConn.Exec execution, or during mysqlConn.finish execution in defer. Is this the intended behavior?

Configuration

Driver version (or git SHA):

Go version: 1.17.2

Server version: E.g. MySQL 5.7

Server OS: amazonlinux:latest(Docker Image)

[methane]

Yes. It is intended. After Exec() succeeded, we don't have anything to cancel. What's wrong about it?

[cia-rana]

I understand that Exec() behaves that way after execution.
On the other hand, if ctx is cancelled while Exec() is running, it should return error, but I don't think it returns an error caused by ctx because ctx is not included in the argument of Exec().

For example, in the following code, if ctx is cancelled while Exec() is running, ExecContext() will not return error caused by ctx, but Commit() will return error.

ctx, cancel := context.WithCancel(context.Background())
tx, err := db.BeginTx(context.Background(), nil) // same with db.BeginTx(ctx, nil) 
if err != nil {
	fmt.Println(err)
	return
}

go func() {
	time.Sleep(time.Millisecond)
	cancel()
}()

_, err = tx.ExecContext(ctx, `query`)
if err != nil {
	fmt.Println(err)
	tx.Rollback()
	return
}

err = tx.Commit()
if err != nil {
	fmt.Println(err)
	tx.Rollback()
	return
}

[methane]

Could you provide a reproducible example, instead of your expectation?

[methane]

For your hint, you can use SELECT SLEEP(10) to emulate long running query.

[cia-rana]

Here is a sample code that can be reproduced.

We assume that we have MySQL server running that is accessible on localhost:4446.
The timing of when ExecContext() does not return error and Commit() does is very critical. Depending on the execution environment, ExecContext() may always return error, or both ExecContext() and Commit() may not return error. In this case, adjust the time of Sleep() in the goroutine.

package main

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

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

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

	if _, err = db.Exec(`CREATE DATABASE IF NOT EXISTS test_db;`); err != nil {
		log.Fatal(err)
	}

	if err = db.Close(); err != nil {
		log.Fatal(err)
	}

	db, err = sql.Open("mysql", "root:@tcp(localhost:4446)/test_db?multiStatements=true")
	if err != nil {
		log.Fatal(err)
	}
	defer db.Close()

	if _, err = db.Exec(`
		DROP TABLE IF EXISTS test_table;
		CREATE TABLE test_table (
		  id BIGINT,
		  value BIGINT,
		  PRIMARY KEY (id)
		) ENGINE = InnoDB COMMENT = 'test_table' DEFAULT CHARACTER SET utf8mb4;
	`); err != nil {
		log.Fatal(err)
	}

	wg := sync.WaitGroup{}
	for i := 0; i < 10000; i++ {
		ctx, cancel := context.WithCancel(context.Background())
		tx, err := db.BeginTx(context.Background(), nil)
		if err != nil {
			log.Fatal(err)
		}

		_, err = tx.ExecContext(ctx, `UPDATE test_table SET value = 1`)

		wg.Add(1)
		go func() {
			time.Sleep(1 * time.Millisecond) // adjust sleep time
			cancel()
			wg.Done()
		}()
		_, err = tx.ExecContext(ctx, `UPDATE test_table SET value = 2`)
		if err != nil && errors.Is(err, context.Canceled) {
			log.Println("ExecContext Error ", i)
			continue
		}

		if err = tx.Commit(); err != nil {
			log.Fatal("Commit Error ", i, err)
		}
		wg.Wait()
	}
}

[methane]

What is problem here? I think it is intended behavior.

[KoteiIto]

tx is created with context.Backgroud as an argument at the start. Is it the intended behavior that when the context of the ExecContext argument is canceled, the ExecContext rarely does not get an error, but an error when executing Commit?

[methane]

I don't think your "reproducer" don't reproduce the problem you are talking.

Have you really confirmed that "ExecContext rarely does not get an error"? Or is it just your thought?
Please write a reproducer that demonstrates the problem you are talking.

[methane]

When I replaced UPDATE test_table SET value = 2 in your example with SELECT SLEEP(4), "ExecContext Error" was happened always.

It demonstrates "rarely does not get an error" is not correct.

[KoteiIto]

Yes, I confirmed. Here is the result of executing the following code.

package main

import (
	"context"
	"database/sql"
	"errors"
	"fmt"
	"log"
	"sync"
	"time"

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

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

	if _, err = db.Exec(`CREATE DATABASE IF NOT EXISTS test_db;`); err != nil {
		log.Fatal(err)
	}

	if err = db.Close(); err != nil {
		log.Fatal(err)
	}

	db, err = sql.Open("mysql", "root:@tcp(localhost:4446)/test_db?multiStatements=true")
	if err != nil {
		log.Fatal(err)
	}
	defer db.Close()

	if _, err = db.Exec(`
		DROP TABLE IF EXISTS test_table;
		CREATE TABLE test_table (
		  id BIGINT,
		  value BIGINT,
		  PRIMARY KEY (id)
		) ENGINE = InnoDB COMMENT = 'test_table' DEFAULT CHARACTER SET utf8mb4;
	`); err != nil {
		log.Fatal(err)
	}

	execErrCount := 0
	commitErrCount := 0
	wg := sync.WaitGroup{}
	for i := 0; i < 10000; i++ {
		ctx, cancel := context.WithCancel(context.Background())
		tx, err := db.BeginTx(context.Background(), nil)
		if err != nil {
			log.Fatal(err)
		}

		_, err = tx.ExecContext(ctx, `UPDATE test_table SET value = 1`)

		wg.Add(1)
		go func() {
			time.Sleep(1 * time.Millisecond) // adjust sleep time
			cancel()
			wg.Done()
		}()
		_, err = tx.ExecContext(ctx, `UPDATE test_table SET value = 2`)
		if err != nil && errors.Is(err, context.Canceled) {
			execErrCount++
			continue
		}

		if err = tx.Commit(); err != nil {
			commitErrCount++
		}
		wg.Wait()
	}

	fmt.Printf("ExecErrCount=%d, CommitErrCount=%d", execErrCount, commitErrCount)
}

ExecErrCount=115, CommitErrCount=10

[methane]

Isn't it just because 1ms is too short?

Single UPDATE query is too fast to cancel. Use SELECT SLEEP(1) instead.

[KoteiIto]

It's also understandable that running your SLEEP (4) will always result in an error. This is because the event reported this time only occurs when the context cacncels during defer () after the query result is returned.

https://github.com/go-sql-driver/mysql/blob/v1.6.0/connection.go#L523

[KoteiIto]

If context is canceled during defer finish () after mc.Exec is successful, tx.ExecContext will treat the connection as a Bad Connection without returning an error.

[methane]

Context may be cancelled anywhere. It may be cancelled during database/sql part. It may be cancelled during returning from function. It may be cancelled during CPU is fetching next instruction.

How the problem you are reporting is different from that?

[methane]

OK, now I understand it.

db.BeginTx() takes Background(), not ctx. And tx.Commit() don't take ctx too.
So you want to avoid error caused by ctx cancel returned from tx.Commit().

That is definitely different from ctx is cancelled during database/sql or elsewhere, because mc.finish() marks it is bad connection.

In regular (e.g. autocommit) case, I don't want to throw away results when Exec() succeeded but connection is marked but by sad timing. Query is executed surely.

On the other hand, in the transactional case, you are right. Although we need to care about Commit error, I want to avoid it as possible.