diff --git a/internal/client/client_batch.go b/internal/client/client_batch.go index 78ce1e51..c5458394 100644 --- a/internal/client/client_batch.go +++ b/internal/client/client_batch.go @@ -924,8 +924,8 @@ func sendBatchRequest( case <-timer.C: return nil, errors.WithMessage(context.DeadlineExceeded, "wait sendLoop") } - waitDuration := time.Since(start) - metrics.TiKVBatchWaitDuration.Observe(float64(waitDuration)) + waitSendDuration := time.Since(start) + metrics.TiKVBatchWaitDuration.Observe(float64(waitSendDuration)) select { case res, ok := <-entry.res: @@ -944,7 +944,8 @@ func sendBatchRequest( return nil, errors.New("batchConn closed") case <-timer.C: atomic.StoreInt32(&entry.canceled, 1) - reason := fmt.Sprintf("wait recvLoop timeout,timeout:%s, wait_duration:%s:", timeout, waitDuration) + reason := fmt.Sprintf("wait recvLoop timeout, timeout:%s, wait_send_duration:%s, wait_recv_duration:%s", + timeout, util.FormatDuration(waitSendDuration), util.FormatDuration(time.Since(start)-waitSendDuration)) return nil, errors.WithMessage(context.DeadlineExceeded, reason) } } diff --git a/internal/client/client_test.go b/internal/client/client_test.go index a1fe349c..1491c09f 100644 --- a/internal/client/client_test.go +++ b/internal/client/client_test.go @@ -148,7 +148,7 @@ func TestSendWhenReconnect(t *testing.T) { req := tikvrpc.NewRequest(tikvrpc.CmdEmpty, &tikvpb.BatchCommandsEmptyRequest{}) _, err = rpcClient.SendRequest(context.Background(), addr, req, 5*time.Second) - require.Regexp(t, "wait recvLoop timeout,timeout:5s, wait_duration:.* context deadline exceeded", err.Error()) + require.Regexp(t, "wait recvLoop timeout, timeout:5s, wait_send_duration:.*, wait_recv_duration:.*: context deadline exceeded", err.Error()) server.Stop() }