Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
45 changes: 25 additions & 20 deletions clickhouse-clickstack/README.md
Original file line number Diff line number Diff line change
@@ -1,38 +1,42 @@
# clickhouse-clickstack

How much disk do 10x compact events save in ClickHouse's ClickStack `otel_logs` schema? On 197,430 lines from the OpenTelemetry demo, the whole table came out 14.9% smaller, but the SQL functions that decode compact rows in ClickHouse returned the wrong text for 78% of them. Keeping the original text and adding the message type as a column inside the sort key took 13.1% off the table with no decoder and the text index intact.
On ClickHouse Cloud most of a log bill is compute, and only a little of it is the cost of keeping rows. This benchmark loaded 197,430 OpenTelemetry demo lines into ClickStack's published `otel_logs` schema, as original text and as 10x compact events. The compact table was 14.9% smaller, but the SQL that decodes it inside ClickHouse returned the wrong text for 78% of rows. Original text with a message-type column in the sort key was 13.1% smaller, with no decoder and the text index intact.

The 10x engine writes each message as a template hash plus its values and folds a multi-line event into one, so the lines became 159,170 compact events.
10x stores the text each log statement repeats once, as a template, and writes each message as the template's hash plus its values. The engine folds a multi-line event into one, so the lines became 159,170 compact events.

## Result
## Table size on disk at ZSTD(1)

Whole table on disk at ZSTD(1), with the 348,040-byte template dictionary in every compact total.
Every compact total includes the 348,040-byte template dictionary.

| Layout | Rows | Bytes on disk | Smaller than published | Full-text index on Body |
|---|---:|---:|---:|---|
| ClickStack as published | 197,430 | 8,225,547 | 0.0% | kept |
| Compact events in Body | 159,170 | 6,999,850 | 14.9% | kept |
| Compact, hash in sort key | 159,170 | 6,188,001 | 24.8% | kept |
| ClickStack as published | 197,430 | 8,225,547 | reference | kept |
| Original text, one row per event | 159,170 | 7,570,122 | 8% | kept |
| Compact events in Body | 159,170 | 6,999,850 | 14.9% | values only |
| Compact, hash in sort key | 159,170 | 6,188,001 | 24.8% | values only |
| Compact, typed value arrays | 159,170 | 4,376,741 | 46.8% | none |
| Original text, type in sort key | 197,430 | 7,148,605 | 13.1% | kept |
| Original text, sorted by type | 197,430 | 6,451,087 | 21.6% | kept |

Against the original text of the same events, the compact form takes 23.55% off the `Body` column. The larger savings come mostly from ClickStack's full-text index on Body shrinking or going away, and sorting by type first weakens the time-range primary key.
The message is a minority of a ClickStack row, and the skip indexes and attribute maps take most of the bytes. Against the same 159,170 events as original text, the compact form takes 23.55% off Body and 7.53% off the table. The larger savings come from the full-text index on Body shrinking or going away. Sorting by type first weakens the time-range primary key.

- Through the SQL decoder, 78.0% of compact rows matched no captured line, and a text filter took 531 ms against 6 ms on the original rows. A Python decoder with the four rules the SQL lacks returned 24,494 of the 24,501 events without a timestamp slot byte-identical, so the text is intact and the SQL misreads it. log10x does not offer the SQL decoder for ClickHouse.
- Row for row, the compact text cost the same insert CPU as the original (1.64 s). Removing rows cut CPU more than proportionally: half the rows cost 39% of insert-plus-merge CPU and a quarter cost 17%.
- TTL RECOMPRESS does nothing on ClickStack, which declares CODEC(ZSTD(1)) on every column. Without that codec, the original-text table at ZSTD(12) was 29.9% smaller than at ZSTD(1), more than any layout above that keeps the text index.
## Reading compact rows back with SQL

## How it was measured
A one-word filter through the SQL decoder took 531 ms at its fastest, against 6 ms on the original rows. A Python decoder with the four template rules the SQL lacks returned 24,494 of the 24,501 events without a timestamp slot byte-identical, and the other 134,669 were not checked. The text is there, and the SQL misreads it. 10x does not offer the SQL decoder for ClickHouse.

The data is `otel-sample-200mb.log` from the otel-sample-v2 release, loaded into the published ClickStack DDL with all eight skip indexes and its sort key, minus the TTL placeholder. ClickHouse 26.8.3.105 ran in one container with 8 GiB and 8 CPUs. Every byte count is read from system.parts and system.parts_columns after OPTIMIZE FINAL.
## Insert and merge CPU

## Limits
Row for row, compact text cost the same insert CPU as the original, 1.64 s. Half the rows, sampled uniformly, cost 39% of the insert-plus-merge CPU and a quarter cost 17%, because fewer parts merge fewer times. Removing the two largest message types left 73% of the rows and 83% of the CPU, because the remaining rows cost more each to compress.

- The data is one demo capture in one container.
- ClickHouse's own 45x figure comes from one typed table per service, which this single-table test does not reproduce.
- CPU covers ClickHouse's insert and merge time, not the collector and not the write cost of ZSTD(12).
- No price is attached.
## How the tables were built and read

The capture is otel-sample-200mb.log from the [otel-sample-v2 release](https://github.com/log-10x/config/releases/tag/otel-sample-v2), loaded into the ClickStack DDL as published minus its TTL placeholder, on ClickHouse 26.8.3.105 with 8 GiB and 8 CPUs. Bytes come from system.parts and system.parts_columns after OPTIMIZE FINAL, and CPU from system.query_log and system.part_log.

## Scope of the run

- One demo capture was measured, and its largest message type is the collector's debug exporter.
- [ClickHouse's 45x figure](https://clickhouse.com/blog/improve-compression-log-clustering) comes from one typed table per service, which this single-table test does not reproduce.
- CPU is ClickHouse's insert and merge time, without the collector.

## Run it

Expand All @@ -42,8 +46,9 @@ python3 reference_decode.py --self-test # decode rules only, no Docker or down
KEEP=1 ./run.sh # the storage tables, leaves ClickHouse up
./run_typed.sh # compact rows sorted by hash, and typed arrays
./run_labeled.sh # original text plus a message-type column
./run_compute.sh # insert and merge CPU against row count
```

The scripts need Docker and about 4 GB of disk. The storage run downloads the capture and takes roughly 20 minutes, and the other two reuse its container.
The shell scripts need Docker and about 4 GB of disk. The storage run downloads the capture and takes about 20 minutes.

The full record, with the decode diagnosis and the compute, TTL, batch-size and query-at-scale runs, is in [RECORD.md](RECORD.md).
[RECORD.md](RECORD.md) has the decode diagnosis and the TTL, batch-size, recompression and query runs.
38 changes: 18 additions & 20 deletions clickhouse-cloud-elasticity/README.md
Original file line number Diff line number Diff line change
@@ -1,44 +1,42 @@
# ClickHouse Cloud elasticity

When a ClickHouse Cloud service is sent fewer log rows, how far does its compute bill fall, and how soon? In three of four paired runs, writing 65.3% of the rows took the service from 4 units to 3, and billed compute settled at 0.749 of the full feed's rate. The step came 2.9 to 4.3 hours after the cut, and until then both arms paid for 4 units. In the other, which started at 3 units, the same cut changed nothing in 10.25 hours.
ClickHouse Cloud bills compute by the unit, so fewer rows show on the bill only when they let the autoscaler step down a size. One service took two feeds in four pairs of runs: the full feed of a 215 MB OpenTelemetry capture, then the 65.3% of its rows the 10x engine kept. From a 4-unit start, the kept rows took the service to 3 units in three pairs, and billed compute settled at 0.749 of the full feed's rate. The step came 2.9 to 4.3 hours after the cut, and until then both feeds paid for 4 units. From a 3-unit start, the same cut changed nothing in 10.25 hours.

The autoscaler's documented rule explains the difference: between 37.5% and 75% CPU it takes no action. On 4 units the busiest replica ran at a median 0.440 to 0.486 of its CPU with every row and 0.337 to 0.351 with the kept rows, below the band. On 3 units both arms stayed inside the band.
## Units and billed compute in each pair

## Result

One unit is 8 GiB and 2 vCPU. Arm A writes every row, arm B the 65.3% the 10x engine kept.

| Pair | Arm A's size set by | Settled units, A to B | Billed $ per 15 min, A to B | Hours from cut to step down |
| Pair | Full feed's size set by | Units, full feed to kept rows | Billed $ per 15 min | Hours from cut to step down |
|---|---|---:|---:|---:|
| 1 | the autoscaler | 4.0 to 2.997 | 0.298 to 0.224 | 4.33 |
| 2 | the autoscaler, after pair 1 | 3.0 to 3.0 | 0.224 to 0.224 | no step in 10.25 |
| 3 | config, released at the cut | 4.0 to 3.0 | 0.298 to 0.224 | 4.21 |
| 4 | config, released at the cut | 4.0 to 3.0 | 0.298 to 0.224 | 2.91 |
| 3 | a 16 GiB minimum | 4.0 to 3.0 | 0.298 to 0.224 | 4.21 |
| 4 | a 16 GiB minimum | 4.0 to 3.0 | 0.298 to 0.224 | 2.91 |

Billed compute is the usageCost API's 15-minute postings, $1.196 an hour at 4 units against $0.896 at 3. Rows fell to 0.653, and the service made one step, from 16 to 12 GiB per replica, which is 0.75.

The billed rate is $1.196 an hour at 4 units against $0.896 at 3. Size fell to 0.75 while rows fell to 0.653, because the service made one step, from 16 GiB to 12 GiB per replica.
- A service at its minimum saves nothing. Below the load that lifts the full feed off 2 units, between 50,000 and 70,000 rows a second, both feeds cost $0.60 an hour.
- Why pair 4 stepped down 1.3 hours sooner than pairs 1 and 3 was not measured.

- The autoscaler's documented scale-down window is 3 hours. Why pair 4 stepped 1.3 hours sooner than pairs 1 and 3 was not measured.
- Below the load that lifts the full feed off the 2-unit minimum, between 50,000 and 70,000 rows a second, both arms cost $0.60 an hour.
## The autoscaler's CPU band

## How it was measured
By its documentation, the autoscaler takes no action between 37.5% and 75% CPU. On 4 units the busiest replica ran at a median 0.440 to 0.486 of its CPU with the full feed, inside the band, and 0.337 to 0.351 with the kept rows, below it. In pair 2, on 3 units, both feeds stayed inside the band, at 0.637 and 0.455.

The service ran on the Scale tier in AWS us-east-1, ClickHouse 26.6, with 2 replicas autoscaling from 8 to 32 GiB each. Both arms wrote into the ClickStack `otel_logs` schema under seven queries a minute. Arm A replayed all 171,807 records of a 215 MB OpenTelemetry sample at 70,000 rows a second, arm B the 112,205 kept rows at 45,716. In pairs 3 and 4, config pinned arm A at 16 GiB per replica until the cut, so each step down was the autoscaler's own. Size and CPU were read every 60 seconds, dollars from the usageCost API every 10 minutes.
## How the service and its bill were read

The service ran on the Scale tier in AWS us-east-1, ClickHouse 26.6, with 2 replicas autoscaling from 8 to 32 GiB each, where a unit is 8 GiB and 2 vCPUs. Both feeds wrote into the ClickStack `otel_logs` schema under seven queries a minute, the full feed at 70,000 rows a second and the kept rows at 45,716. In pairs 3 and 4 a 16 GiB minimum set the full feed's size and was lowered to 8 GiB at the cut, so each step down was the autoscaler's own. Size and CPU were read every 60 seconds and billed compute every 10 minutes.

## Limits

- One service shape in one region, with seven queries a minute instead of a production mix.
- Both arms inserted from staged tables, so neither the engine nor the parsing of network inserts ran live.
- One service shape in one region, with a fixed query load.
- Both feeds were inserted from staged tables, so neither the engine nor network insert parsing ran live.
- Which replica the autoscaler reads, and how often it decides, was not measured.

## Run it

The pair ratios recompute from committed logs:
The pair ratios recompute offline from the committed logs:

```
cd clickhouse-cloud-elasticity
python3 cloud/arms_report.py --raw results/raw --lag-min 30
```

A full rerun needs a ClickHouse Cloud API key, Docker and a `clickhouse` client, and this run spent $42.61 of credit. The steps are in [RECORD.md](RECORD.md#rerun).

[RECORD.md](RECORD.md) has the run summary and rerun steps, and [RESULT.md](RESULT.md) every figure with the file it came from.
A full rerun needs a ClickHouse Cloud API key, Docker and a `clickhouse` client, and this run spent $42.61 of credit. [RECORD.md](RECORD.md#rerun) has the rerun steps, and [RESULT.md](RESULT.md) every figure with its source.
50 changes: 26 additions & 24 deletions clickhouse-inflate/README.md
Original file line number Diff line number Diff line change
@@ -1,46 +1,48 @@
# clickhouse-inflate

What does it cost ClickHouse to turn compact log events back into text at query time? Here the events sit in a table, and a view decodes them with SQL functions from the log10x ClickHouse app. With the SQL in `install-fixed.sql`, decoding all 137,418 rows took 548 ms and peaked at 41.1 MiB. The SQL in `install-buggy.sql` could not finish the same query at ClickHouse defaults and aborted at the server's memory cap.
A ClickHouse view runs its SQL each time a query reads it. Here a view decodes compact log events, each a template hash plus the line's values, with SQL functions from the log-10x/clickhouse-app repository. Decoding all 137,418 rows took 548 ms and peaked at 41.1 MiB when the decode lambda took its arrays as arrayMap arguments. With a lambda that reads the same arrays by subscript, the query hit the server's memory cap at ClickHouse defaults and aborted.

A `SELECT count()` over the view measures none of this, because ClickHouse answers it from a projection and prunes the decode out of the plan. The two SQL files differ by one line per function. The buggy lambda reaches its arrays by subscript, so ClickHouse copies each array once per mapped element. The fixed one passes them to arrayMap as arguments, which ClickHouse walks element by element.
A lambda that indexes into its arrays captures them, and ClickHouse copies a captured array once per mapped element, so a row with N literals materializes N copies of its N-element arrays. Arrays passed to arrayMap as arguments are walked element by element.

## Result
A `SELECT count()` over the view measures none of this, because ClickHouse answers it from a built-in count projection and its plan has no function nodes.

Figures are from results.json, with times averaged over 3 runs after discarding the first.
## What ClickHouse's query log recorded

| Query | SQL file | Outcome | Time | Peak memory |
Times average the second and third of three runs. Every figure is from [results.json](results.json).

| Query | Decode lambda | Outcome | Time | Peak memory |
|---|---|---|---:|---:|
| `SELECT count()` | buggy | 1 row, 24 bytes read | 16 ms | not recorded |
| `sum(length(decoded_log))` | buggy | aborts, code 241 | n/a | 7.20 GiB |
| `sum(length(decoded_log))`, bounded settings | buggy | completes | 4,290 ms | 2.86 GiB |
| `sum(length(decoded_log))` | fixed | completes | 548 ms | 41.1 MiB |
| `SELECT decoded_log`, `FORMAT Null` | buggy | aborts, code 241 | n/a | 7.20 GiB |
| `SELECT decoded_log`, `FORMAT Null` | fixed | completes | 535 ms | 40.9 MiB |
| `SELECT count()` | not in the plan | 1 row, 24 bytes read | 16 ms | not recorded |
| `sum(length(decoded_log))` | by subscript | aborts, code 241 | n/a | 7.2 GiB |
| same, bounded settings | by subscript | completes | 4,290 ms | 2.86 GiB |
| `sum(length(decoded_log))` | as arguments | completes | 548 ms | 41.1 MiB |
| `SELECT decoded_log`, `FORMAT Null` | by subscript | aborts, code 241 | n/a | 7.2 GiB |
| `SELECT decoded_log`, `FORMAT Null` | as arguments | completes | 535 ms | 40.9 MiB |
| `sum(length(decoded_log))`, format-preserving view | as arguments | completes | 600 ms | 78 MiB |

The 7.20 GiB is above this host's 6.89 GiB cap because ClickHouse records the usage a refused 4 GiB allocation would have reached. The buggy decode completed in 3 of 3 runs with a block size of 64, 4 threads and a per-query limit of 6000000000 bytes.
The 7.2 GiB is above this host's 6.89 GiB cap because ClickHouse records the usage a refused 4 GiB allocation would have reached. The bounded run, with a block size of 64, 4 threads and a per-query limit of 6000000000 bytes, completed in 3 of 3 runs.

- Both files give byte-identical output over all 137,418 rows, 29,065,810 bytes.
- The decode needs 800,397 array elements and the buggy SQL materializes 189,949,597. One template with 818 literals, on 275 rows, accounts for 96.9% of the materialized elements.
- Replacing the functions alone leaves the views on the old body, because ClickHouse copies a function body into a view when it creates the view. The fixed install file recreates the views.
- Both lambdas return byte-identical output over all 137,418 rows, 29,065,810 bytes.
- The decode needs 800,397 array elements and the subscript lambda materializes 189,949,597, 96.9% of them from one template with 818 literals on 275 rows.
- Replacing the functions alone leaves the views on the old body, because ClickHouse copies a function body into each view at creation. [install-fixed.sql](install-fixed.sql) recreates them.

## How it was measured
## How the queries were run

ClickHouse 25.8.28.1 ran in Docker, pinned to 8 GiB and 8 CPUs. The data is 500 compact events the 10x engine wrote from the OpenTelemetry demo's Kubernetes logs, cycled to 137,418 rows. The script runs every query on the buggy SQL, then the decodes on the fixed SQL, and compares the outputs byte for byte. Times and peak memory come from ClickHouse's query log.
ClickHouse 25.8.28.1 ran in Docker at default query settings, pinned to 8 GiB and 8 CPUs. The data is 500 compact events the 10x engine wrote from the OpenTelemetry demo's Kubernetes logs, repeated to 137,418 rows. The queries ran on the subscript version in [install-buggy.sql](install-buggy.sql), then on [install-fixed.sql](install-fixed.sql). For the byte comparison, the subscript version decodes at a block size of 64 so that it completes.

## Limits

- The test ran on one host with one ClickHouse version. Times move with hardware, and the abort point moves with the memory cap, which ClickHouse sets at 0.9 times the RAM it can see.
- The data set is small, 500 events cycled to fill the table.
- The byte-identity check compares the two files' output against each other, not against the original log text.
- One host and one ClickHouse version were tested. Times move with hardware, and the abort point moves with the memory cap, which ClickHouse sets by default at 0.9 times the RAM it can see.
- The byte comparison checks the two lambdas against each other, never against the original log text. [clickhouse-clickstack](../clickhouse-clickstack/) makes that check, and there this SQL returns the wrong text for most rows.

## Run it

```
cd clickhouse-inflate
./run.sh # pulls the pinned ClickHouse image and writes results.json
SKIP_PREFIX=1 ./run.sh # skips the two buggy-SQL queries that abort
./run.sh # pulls the pinned ClickHouse image and writes results.json
KEEP=1 ./run.sh # the same run, leaving the container up afterwards
```

A run needs Docker. The two aborting queries take 2 seconds to 10 minutes, depending on host memory pressure.
A run needs Docker, and the two aborting queries take between 2 seconds and 10 minutes, depending on the host's memory pressure.

The full record is in [RECORD.md](RECORD.md): the abort message, the memory cap, plan node counts, the SQL change and the figures this harness does not reproduce.
[RECORD.md](RECORD.md) has the abort message, how ClickHouse sets its memory cap, the plan node counts and the SQL of both lambdas.
Loading
Loading