SIGSEGV: segmentation violation on fast use of library

[pankajsoni19]

1. Data is being accessed sequentially, no parallel running queries

Describe the bug

panic: runtime error: invalid memory address or nil pointer dereference
--
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x99a69d]
goroutine 72134 [running]:
github.com/ClickHouse/ch-go/proto.(*Reader).readFull(...)
/go/pkg/mod/github.com/!click!house/ch-go@v0.54.0/proto/reader.go:68
github.com/ClickHouse/ch-go/proto.(*Reader).ReadByte(0x0)
/go/pkg/mod/github.com/!click!house/ch-go@v0.54.0/proto/reader.go:35 +0x1d
encoding/binary.ReadUvarint({0x1244160, 0x0})
/usr/local/go/src/encoding/binary/varint.go:136 +0x82
github.com/ClickHouse/ch-go/proto.(*Reader).UVarInt(0xfe14a0?)
/go/pkg/mod/github.com/!click!house/ch-go@v0.54.0/proto/reader.go:83 +0x25
github.com/ClickHouse/clickhouse-go/v2/lib/proto.(*ProfileInfo).Decode(0xc0004f06c0, 0x124d5a8?, 0x19f8a28?)
/go/pkg/mod/github.com/!click!house/clickhouse-go/v2@v2.8.2/lib/proto/profile_info.go:35 +0x2a
github.com/ClickHouse/clickhouse-go/v2.(*connect).handle(0xc0002683c0, {0x124d5a8?, 0xc000044058?}, 0x6?, 0xc000aaf2f0)
/go/pkg/mod/github.com/!click!house/clickhouse-go/v2@v2.8.2/conn_process.go:103 +0x255
github.com/ClickHouse/clickhouse-go/v2.(*connect).process(0xc0002683c0, {0x124d5a8, 0xc000044058}, 0x406a98?)
/go/pkg/mod/github.com/!click!house/clickhouse-go/v2@v2.8.2/conn_process.go:80 +0x105
github.com/ClickHouse/clickhouse-go/v2.(*connect).query.func1()
/go/pkg/mod/github.com/!click!house/clickhouse-go/v2@v2.8.2/conn_query.go:76 +0xc5
created by github.com/ClickHouse/clickhouse-go/v2.(*connect).query
/go/pkg/mod/github.com/!click!house/clickhouse-go/v2@v2.8.2/conn_query.go:72 +0x68c

Expected behaviour

Code example

func ClickhouseClient() driver.Conn {
	conf := clichouseConfig()

	if clickhouseClient != nil {
		return clickhouseClient
	}

	conn, err := clickhouse.Open(
		&clickhouse.Options{
			Addr: []string{
				fmt.Sprintf("%s:%d", conf.Hostname, conf.NativePort),
			},
			Auth: clickhouse.Auth{
				Database: conf.Database,
				Username: conf.Username,
				Password: conf.Password,
			},
			DialContext: func(ctx context.Context, addr string) (net.Conn, error) {
				var d net.Dialer
				return d.DialContext(ctx, "tcp", addr)
			},
			Debug: true,
			Debugf: func(format string, v ...interface{}) {
				if strings.HasPrefix(format, "[progress]") {
					return
				}

				if strings.HasPrefix(format, "[profile events]") {
					return
				}

				if strings.HasPrefix(format, "[profile info]") {
					return
				}

				if strings.HasPrefix(format, "[read data]") {
					return
				}

				if strings.HasPrefix(format, "[acquired] connection") {
					return
				}

				if strings.HasPrefix(format, "[send data]") {
					return
				}

				if strings.HasPrefix(format, "[end of stream]") {
					return
				}

				log.Info().Str("clickhouse", "query").Msgf(format, v)
			},
			Settings: clickhouse.Settings{
				"max_execution_time": 60,
			},
			Compression: &clickhouse.Compression{
				Method: clickhouse.CompressionLZ4,
			},
			DialTimeout:          time.Second * 30,
			MaxOpenConns:         5,
			MaxIdleConns:         1,
			ConnMaxLifetime:      time.Duration(10) * time.Minute,
			ConnOpenStrategy:     clickhouse.ConnOpenInOrder,
			BlockBufferSize:      10,
			MaxCompressionBuffer: 10240,
			HttpHeaders: map[string]string{
				"X-ClickHouse-User": conf.Username,
				"X-ClickHouse-Key":  conf.Password,
			},
		},
	)

	if err != nil {
		panic(err)
	}

	clickhouseClient = conn

	return clickhouseClient
}

func findCampaignStartDate(
	input *mInputData,
) time.Time {
	//TODO: find start date
	qe := `
	SELECT 
		MIN(range_hour) AS first_event
	FROM ch_recognitions 
	WHERE 
			range_hour BETWEEN ? AND ?
		AND product = ?
		AND brand = ?
		AND category = ?
	GROUP BY toDate(range_hour) 
	ORDER BY first_event DESC`

	var items []struct {
		FirstEvent time.Time `ch:"first_event"`
	}

	err := config.ClickhouseClient().
		Select(
			context.Background(),
			&items,
			qe,
			input.DTime.Add(-24*90*time.Hour), //90 days
			input.DTime,                       // previous
			input.Product, input.Brand, input.Category)
...

Error log

Configuration

Environment

go.mod > github.com/ClickHouse/clickhouse-go/v2 v2.8.2

ClickHouse server

• ClickHouse Server version: 23.3.1

• CREATE TABLE statements for tables involved:

CREATE TABLE prod.ch_recognitions
(
    `range_hour` DateTime('UTC'),
    `channel` LowCardinality(String),
    `product` LowCardinality(String),
    `brand` LowCardinality(String),
    `category` LowCardinality(String),
    `genre` LowCardinality(String),
    `duration` UInt16,
    `spend` UInt32,
    `count` UInt8,
    `creative` String,
    `creative_language` LowCardinality(String),
    `channel_language` LowCardinality(String),
    `programme` String
)
ENGINE = MergeTree
PARTITION BY toYYYYMM(range_hour)
PRIMARY KEY (range_hour, channel)
ORDER BY (range_hour, channel)
SETTINGS index_granularity = 8192

[jkaflik]

Hi @pankajsoni19
Thanks for submitting this. Do you know if this error behavior depends on some timing? Does it happen immediately after conn is open or maybe is related to ConnMaxLifetime option?

[pankaj-syncmedia]

This is definitely related to ConnMaxLifetime as it occurs just post that. I also tried adding a ping to validate the connection, but that doesn't help either. Ping is successful, but breaks on query

for now, I have switched driver to
https://github.com/uptrace/go-clickhouse, if error re-occurs, would update here.

[jkaflik]

@pankajsoni19 thanks. I confirm it's a race condition in a situation when the query is triggered at a time idle connection is being closed.

Please see a PR: #958. I added a test case there.

---

I will release a new version with a revert until I figure out these.

[crisismaple]

Looks like the connection would be force closed without checking the buffer status in connection.close func, we may need to acquire read lock while transfering data and block the closing process.