diff --git a/go/pools/smartconnpool/pool.go b/go/pools/smartconnpool/pool.go index ecc3f827c7b..7eead7fe264 100644 --- a/go/pools/smartconnpool/pool.go +++ b/go/pools/smartconnpool/pool.go @@ -18,6 +18,7 @@ package smartconnpool import ( "context" + "fmt" "slices" "sync" "sync/atomic" @@ -509,8 +510,12 @@ func (pool *ConnPool[C]) get(ctx context.Context) (*Pooled[C], error) { // to other clients, wait until one of the connections is returned if conn == nil { start := time.Now() + + oldPool := fmt.Sprintf("%+v", pool) conn, err = pool.wait.waitForConn(ctx, nil) if err != nil { + log.Errorf("===================== ERROR: waitForConn err: %s", err.Error()) + log.Errorf("ctx:\n%+v\nOld pool: \n%s\n=================\nNew pool: \n%+v", ctx, oldPool, pool) return nil, ErrTimeout } pool.recordWait(start) @@ -568,6 +573,7 @@ func (pool *ConnPool[C]) getWithSetting(ctx context.Context, setting *Setting) ( start := time.Now() conn, err = pool.wait.waitForConn(ctx, setting) if err != nil { + log.Errorf("===================== getWithSetting ERROR: waitForConn err: %s", err.Error()) return nil, ErrTimeout } pool.recordWait(start) diff --git a/go/pools/smartconnpool/waitlist.go b/go/pools/smartconnpool/waitlist.go index f16215f4b14..06a08eb4b10 100644 --- a/go/pools/smartconnpool/waitlist.go +++ b/go/pools/smartconnpool/waitlist.go @@ -19,8 +19,10 @@ package smartconnpool import ( "context" "sync" + "time" "vitess.io/vitess/go/list" + "vitess.io/vitess/go/vt/log" ) // waiter represents a client waiting for a connection in the waitlist @@ -108,7 +110,12 @@ func (wl *waitlist[C]) expire(force bool) { func (wl *waitlist[D]) tryReturnConn(conn *Pooled[D]) bool { // fast path: if there's nobody waiting there's nothing to do if wl.list.Len() == 0 { - return false + // HACK: we're gonna sleep for a bit and try again, to see if there are still no waiters + time.Sleep(10 * time.Millisecond) + if wl.list.Len() == 0 { + log.Error("======================= WE HIT THE FAST PATH, WE'RE RETURNING") + return false + } } // split the slow path into a separate function to enable inlining return wl.tryReturnConnSlow(conn) diff --git a/go/vt/logutil/throttled.go b/go/vt/logutil/throttled.go index 4ee11912e71..07c7aadc5df 100644 --- a/go/vt/logutil/throttled.go +++ b/go/vt/logutil/throttled.go @@ -55,30 +55,32 @@ var ( ) func (tl *ThrottledLogger) log(logF logFunc, format string, v ...any) { - now := time.Now() + // now := time.Now() tl.mu.Lock() defer tl.mu.Unlock() - logWaitTime := tl.maxInterval - (now.Sub(tl.lastlogTime)) - if logWaitTime < 0 { - tl.lastlogTime = now - logF(2, fmt.Sprintf(tl.name+": "+format, v...)) - return - } - // If this is the first message to be skipped, start a goroutine - // to log and reset skippedCount - if tl.skippedCount == 0 { - go func(d time.Duration) { - <-time.After(d) - tl.mu.Lock() - defer tl.mu.Unlock() - // Because of the go func(), we lose the stack trace, - // so we just use the current line for this. - logF(0, fmt.Sprintf("%v: skipped %v log messages", tl.name, tl.skippedCount)) - tl.skippedCount = 0 - }(logWaitTime) - } - tl.skippedCount++ + // logWaitTime := tl.maxInterval - (now.Sub(tl.lastlogTime)) + // if logWaitTime < 0 { + // tl.lastlogTime = now + logF(2, fmt.Sprintf(tl.name+": "+format, v...)) + // return + // } + // // If this is the first message to be skipped, start a goroutine + // // to log and reset skippedCount + // + // if tl.skippedCount == 0 { + // go func(d time.Duration) { + // <-time.After(d) + // tl.mu.Lock() + // defer tl.mu.Unlock() + // // Because of the go func(), we lose the stack trace, + // // so we just use the current line for this. + // logF(0, fmt.Sprintf("%v: skipped %v log messages", tl.name, tl.skippedCount)) + // tl.skippedCount = 0 + // }(logWaitTime) + // } + // + // tl.skippedCount++ } // Infof logs an info if not throttled. diff --git a/go/vt/vttablet/tabletserver/query_executor.go b/go/vt/vttablet/tabletserver/query_executor.go index ccf0398d5e5..06135f85c7c 100644 --- a/go/vt/vttablet/tabletserver/query_executor.go +++ b/go/vt/vttablet/tabletserver/query_executor.go @@ -726,6 +726,7 @@ func (qre *QueryExecutor) execSelect() (*sqltypes.Result, error) { return nil, err } defer conn.Recycle() + res, err := qre.execDBConn(conn.Conn, sql, true) if err != nil { return nil, err