ClickHouse / ClickHouse/clickhouse-go
`ReadTimeout` is not applied correctly
- 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
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