ClickHouse / ClickHouse/clickhouse-go

`ReadTimeout` is not applied correctly

Open
#1,672 0 comments 2 reactions 0 assignees View on GitHub
bug investigate
Dominant language
Go
Stars
3.3k
Forks
680
Avg merge
2d 3h
Merged PRs (30d)
14

Description

## Observed

1. Start a CH query, with `ReadTimeout = X`
2. Read a few thousand rows.
3. In client code sleep for `ReadTimeout` or longer.
4. Some rows will be successfully be read.
5. Then query will fail with `i/o timeout`

## Expected behaviour
`ReadTimeout` should be applied to that actual time it takes for Clickhouse to respond, like this docs says. Shouldn't be affected by the time the client code takes to process the rows in the result.

## Cause and possible solution

The `processImpl` function in `conn_query.go` will set a fixed read deadline at the start, via `startReadWriteTimeout`.
The deadline is never updated, and is only cleared with the function returns.

This becomes a since the call to `c.handle(ctx, packet, on)` may block if the functions in `onProcess` blocks. Which it may in the case of `Query()`.

The example bellow will trigger the following scenario:
1. `query(...)` is called
2. `c.process(ctx, onProcess)` is called, `processImpl` starts running.
3. The timeout in `processImpl` is now active.
4. The client code will start to sleep in the `rows.Next()` loop.
5. The `stream` channel (created in `query`) will be filled up and will start to block.
6. The read loop in `processImpl` will start to block in `c.handle(ctx, packet, on)`.
7. The client start to process rows again, freeing up space in the `stream` channel.
8. The deadline set in `processImpl` will expire and the query will fail.

One solution would be to move the `startReadWriteTimeout` / `clearReadWriteTimeout` to inside the read loop.

## Code example

```go
package code

import (
"context"
"fmt"
"testing"
"time"

"github.com/ClickHouse/clickhouse-go/v2"
)

func Test(t *testing.T) {
readTimeout := 10 * time.Second

ctx := context.Background()
conn, err := clickhouse.Open(&clickhouse.Options{
Addr: []string{"localhost:9000"},
Auth: clickhouse.Auth{
Database: "somedatabase",
Username: "default",
Password: "password",
},
ReadTimeout: readTimeout,
})
if err != nil {
t.Fatal(err)
}
defer conn.Close()

rows, err := conn.Query(ctx, `SELECT number, rand() AS random_value FROM numbers(100000000)`)
if err != nil {
t.Fatal(err)
}
defer rows.Close()

var num uint64
sleepAt := uint64(100_000)
for rows.Next() {
var random uint32
if err := rows.Scan(&num, &random); err != nil {
fmt.Printf("failed after %d\n", num)
t.Fatal(err)
}

if num == sleepAt {
fmt.Printf("Sleeping for %v\n", readTimeout)
time.Sleep(readTimeout)
}
}

if err := rows.Err(); err != nil {
fmt.Printf("failed after %d\n", num)
t.Fatal(err)
}
}
```

## Error log

```log
Sleeping for 10s
failed after 196226
main_test.go:53: clickhouse [Decode]: number read full: read: read tcp 127.0.0.1:55102->127.0.0.1:9000: i/o timeout
--- FAIL: Test (10.02s)
```

## Details

### Environment
* [x] `clickhouse-go` version: `v2.40.1`
* [x] Go version: `1.24.0`
* [x] Operating system: Linux / Ubuntu

Contributor guide

Open the contributing guide

Research direction

Start by reading conn_query.go, focusing on processImpl, startReadWriteTimeout, clearReadWriteTimeout, and the c.handle callback path described in the issue. Run the supplied reproducer against ClickHouse, then verify that sleeping while processing rows does not cause a timeout caused by client-side backpressure, while the documented ReadTimeout behavior remains intact.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
database
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Clearly specified
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.