`SELECT toString(number) FROM numbers(500000000)` is slow

[zhicwu]

Issue description

Using benchmark at here, I found somehow SELECT toString(number) FROM numbers(500000000) is very slow on my VM. Changing type to Decimal may have similar issue.

Query	Result
SELECT number FROM numbers(500000000)	5.6s 500000000 Command being timed: "go run main.go" User time (seconds): 5.19 System time (seconds): 3.99 Percent of CPU this job got: 154% Elapsed (wall clock) time (h:mm:ss or m:ss): 0:05.92 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 90576 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 1 Minor (reclaiming a frame) page faults: 64764 Voluntary context switches: 36844 Involuntary context switches: 15003 Swaps: 0 File system inputs: 8 File system outputs: 96 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0
SELECT toString(number) FROM numbers(500000000)	1m30.674s 500000000 Command being timed: "go run main.go" User time (seconds): 89.83 System time (seconds): 55.28 Percent of CPU this job got: 159% Elapsed (wall clock) time (h:mm:ss or m:ss): 1:31.05 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 89944 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 1 Minor (reclaiming a frame) page faults: 613890 Voluntary context switches: 165692 Involuntary context switches: 51110 Swaps: 0 File system inputs: 0 File system outputs: 16 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0

Example code

https://github.com/go-faster/ch-bench/blob/c2627b1d0fa1a8abc7d3560816d3b919b983600b/ch-bench-official/main.go#L26

Error log

N/A

Configuration

OS: Linux myserver 5.18.5-100.fc35.x86_64 # 1 SMP PREEMPT_DYNAMIC Thu Jun 16 14:44:38 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

Interface: E.g. native, database/sql

Driver version: v2.1.0

Go version: 1.18.3

ClickHouse Server version: 22.3

[gingerwizard]

Will test this prior to after #623 for the string layer.

[zhicwu]

You may want to check Decimal(e.g. toDecimal128(number, 0)) as well, not sure if it's the same cause or not.

[gingerwizard]

Ok i can reproduce this. Before i start #623 id like to understand why its soo bad.

[gingerwizard]

#646 doesnt provide any reasonable improvement. We need to see how much of this is in ch-go @ernado

[ernado]

The reason is strings are encoded as length-value, so for each row we first decode length and then read value.

That leads to much higher overhead compared to UInt64, because we can decode whole UInt64 data block at once.

I can achieve following results with ch-go:

UInt64   435ms 500000000 rows 4.0 GB 9.2 GB/s
String 18.424s 500000000 rows 4.0 GB 217 MB/s

That's it, String is 43 times slower.

However, for clickhouse-client the difference is much lower:

$ clickhouse-client -q "SELECT number FROM system.numbers_mt LIMIT 500000000" --format Null --time
0.474
$ clickhouse-client -q "SELECT toString(number) FROM system.numbers_mt LIMIT 500000000" --format Null --time
3.340

So there should be some room for optimizations.

[gingerwizard]

Ok lets move this issue to ch-go once #646 is merged.

[gingerwizard]

Using

func TestRead(b *testing.T) {
	conn := getConnection()
	start := time.Now()
	rows, err := conn.Query(context.Background(), fmt.Sprintf(`SELECT toString(number) FROM numbers(500000000)`))
	if err != nil {
		b.Fatal(err)
	}
	var (
		col1 string
	)
	for rows.Next() {
		if err := rows.Scan(&col1); err != nil {
			b.Fatal(err)
		}
	}
	elapsed := time.Since(start)
	log.Printf("Read took %s", elapsed)
}

=== RUN   TestRead
^[	2022/10/04 11:44:12 Read took 1m8.838745727s
--- PASS: TestRead (68.84s)

With a larger buffer (100 vs 2) - will PR

=== RUN   TestRead
2022/10/04 11:41:48 Read took 37.871352842s
--- PASS: TestRead (37.87s)