Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

database/sql: SetConnMaxIdleTime, SetConnMaxLifetime order impacts close time #45993

Open
eqinox76 opened this issue May 6, 2021 · 5 comments · May be fixed by #58490
Open

database/sql: SetConnMaxIdleTime, SetConnMaxLifetime order impacts close time #45993

eqinox76 opened this issue May 6, 2021 · 5 comments · May be fixed by #58490
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@eqinox76
Copy link

eqinox76 commented May 6, 2021

What version of Go are you using (go version)?

$ go version
go version go1.16.3 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/carsten/.cache/go-build"
GOENV="/home/carsten/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/carsten/go/pkg/mod"
GONOPROXY="dev.azure.com/xtp"
GONOSUMDB="dev.azure.com/xtp"
GOOS="linux"
GOPATH="/home/carsten/go"
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/snap/go/7360"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/snap/go/7360/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.16.3"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build3305456222=/tmp/go-build -gno-record-gcc-switches"
GOROOT/bin/go version: go version go1.16.3 linux/amd64
GOROOT/bin/go tool compile -V: compile version go1.16.3
uname -sr: Linux 5.8.0-50-generic
Distributor ID:	Ubuntu
Description:	Ubuntu 20.04.2 LTS
Release:	20.04
Codename:	focal
/lib/x86_64-linux-gnu/libc.so.6: GNU C Library (Ubuntu GLIBC 2.31-0ubuntu9.2) stable release version 2.31.
gdb --version: GNU gdb (Ubuntu 9.2-0ubuntu1~20.04) 9.2

What did you do?

When using

db.SetConnMaxIdleTime(5 * time.Second)
db.SetConnMaxLifetime(5 * time.Hour)

idle connections get closed after 5 hours. While setting the parameters in reverse order works fine.

db.SetConnMaxLifetime(5 * time.Hour)
db.SetConnMaxIdleTime(5 * time.Second)

What did you expect to see?

Closing idle connections after ~5s.

What did you see instead?

Closing connections after ~5h

I think this is due to sql.go#L1041 only checking if maxIdleTime has been reduced and not also if its smaller than maxLifetime.

@seankhliao
Copy link
Member

@Equinox76 both lines look the same?

@eqinox76
Copy link
Author

eqinox76 commented May 6, 2021

Thanks! Copy paste error which i corrected.

@seankhliao seankhliao added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label May 8, 2021
@seankhliao
Copy link
Member

cc @bradfitz @kardianos @kevinburke

@seankhliao seankhliao added this to the Unplanned milestone Aug 20, 2022
@latentflip
Copy link

I re-discovered this today and can add a little more context on how to reproduce it.

I believe @eqinox76's examples are actually backwards. Setting SetConnMaxIdleTime before SetConnMaxLifetime gives the correct behaviour, while setting SetConnMaxLifetime first gives the incorrect behavior.

Reproducing the bug

To trigger this bug, the following order of operations is required:

  1. We have an open connection
  2. We set SetConnMaxLifetime to something higher than our desired SetConnMaxIdleTime
  3. We set SetConnMaxIdleTime

If this is the order of operations, then no idle connections will be closed until one SetConnMaxLifetime time has passed. After that we will cleanup connections every SetConnMaxIdleTime seconds as expected

Example code that triggers the bug:

package main

// Import go-sql-driver and connect to a mysqL server and make a basic query
import (
	"database/sql"
	"fmt"
	"time"

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

func main() {
	db, _ := sql.Open("mysql", "root:@tcp(localhost:3306)/dbname")

        // Create a connection
	db.Ping()

	db.SetConnMaxLifetime(1000 * time.Second)
	db.SetConnMaxIdleTime(3 * time.Second)

	stats := db.Stats()
	fmt.Println("Open connections", stats.OpenConnections, "Idle connections", stats.Idle)

	fmt.Println("Sleep")
	// Should be long enough to clear idle connection
	time.Sleep(5 * time.Second)

	stats = db.Stats()
	fmt.Println("Open connections", stats.OpenConnections, "Idle connections", stats.Idle)
}

Expected output:

Open connections 1 Idle connections 1
Sleep
Open connections 0 Idle connections 0

Actual Output:

Open connections 1 Idle connections 1
Sleep
Open connections 1 Idle connections 1

Workarounds

To avoid the bug currently, either of the following changes will fix it:

  1. Call SetConnMaxIdleTime before SetConnMaxLifetime:
	db.SetConnMaxLifetime(1000 * time.Second)
	db.SetConnMaxIdleTime(3 * time.Second)
  1. Ensure that no active connections are setup when calling SetConnMaxLifetime and SetConnMaxIdleTime

Cause

When a connection exists and SetConnMaxLifetime is called, we will start the connectionCleaner with the interval set to our value of SetConnMaxLifetime.

https://github.com/golang/go/blob/master/src/database/sql/sql.go#L1046

Afterwards when we call SetConnMaxIdleTime we will not wake the cleaner because the existing logic only does so if we've reduced maxIdleTime, which we haven't. As suggested by @eqinox76 we probably should check additionally if if maxIdleTime has been set to less than maxLifetime and wake up the cleaner in that case too.

https://github.com/golang/go/blob/master/src/database/sql/sql.go#L1034

Why the workarounds work:

If there is no connection when we call these functions, then the cleaner is not started at all, and is only started after the first connection is allocated here, at which point it will use the lower maxIdleTime as expected.

https://github.com/golang/go/blob/master/src/database/sql/sql.go#L1521-L1523

Alternatively, calling SetConnMaxIdleTime before SetConnMaxLifetime ensures that the cleaner is setup with the shorter interval initially.

latentflip added a commit to latentflip/go that referenced this issue Feb 13, 2023
The existing implementation wouldn't wake the connection cleaner if
maxIdleTime was set to a value less than maxLifetime
resulting in idle connections being held
on to longer than expected.

Fixes golang#45993
@gopherbot
Copy link

Change https://go.dev/cl/467655 mentions this issue: database/sql: wake cleaner if maxIdleTime set to less than maxLifetime

latentflip added a commit to latentflip/go that referenced this issue Mar 9, 2023
The existing implementation wouldn't wake the connection cleaner if
maxIdleTime was set to a value less than maxLifetime
resulting in idle connections being held
on to longer than expected.

Fixes golang#45993
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants