cat / 012
clone

a spreadsheet for the terminal: lotus 1-2-3 looks, google sheets keys and formulas, one go binary

Add an observability stack: Collector, ClickHouse and Grafana

Dami committed 7cf7e0f
deploy/observability runs in Docker with pinned images: the OpenTelemetry
Collector (contrib 0.161.0) takes OTLP over gRPC and HTTP and tails 012's
JSON event logs (.deps/obs/logs, O12_LOG) with its file_log receiver,
exporting to ClickHouse 26.3 (3 GB limit, named volumes). Grafana 13.2
comes provisioned with the ClickHouse datasource and two dashboards:
012 runtime (recalc, frame and key-to-frame times, heap and cells, JEV,
imports, slowest operations) and 012 stress runs (trends per benchmark,
memory per cell, the latest run against the previous one).

make obs-up, obs-down and obs-status manage it; make stress-load, and
make stress while the stack is up, load run records into
stress.results, the same columns DuckDB reads. The start event now
carries its event name too.
commit
7cf7e0f4cb4a55931985821c3f35aa12c3435482
parent
1afda19a6874322390f40e9768202697725b9bca
author
Dami <dami.etoile@gmail.com>
12 files changed, +1033 -2
MMakefile22++-
Adeploy/observability/clickhouse/config.d/memory.xml9+
Adeploy/observability/clickhouse/init.sql47++++
Adeploy/observability/docker-compose.yml82+++++++
Adeploy/observability/grafana/dashboards/runtime.json365++++++++++++++++++++++++++++++
Adeploy/observability/grafana/dashboards/stress.json319++++++++++++++++++++++++++
Adeploy/observability/grafana/provisioning/dashboards/012.yaml8+
Adeploy/observability/grafana/provisioning/datasources/clickhouse.yaml23++
Adeploy/observability/otel-collector.yaml73++++++
Minternal/telemetry/telemetry.go2+-
Ascripts/obs.sh52++++
Ascripts/stress/clickhouse-load.sh33+++
M Makefile +21 -1
A deploy/observability/clickhouse/config.d/memory.xml +9 -0
A deploy/observability/clickhouse/init.sql +47 -0
@@ -0,0 +1,47 @@
1+-- Stress run records, one row per benchmark per run: the same columns as2+-- the JSONL written by internal/stress/benchrec (and read by DuckDB in3+-- scripts/stress/load.sql). Loaded by scripts/stress/clickhouse-load.sh;4+-- loading a run twice is harmless (ReplacingMergeTree, query with FINAL).5+CREATE DATABASE IF NOT EXISTS stress;6+7+CREATE TABLE IF NOT EXISTS stress.results8+(9+ run_id String,10+ ts DateTime64(3, 'UTC'),11+ git_sha LowCardinality(String),12+ git_dirty Bool,13+ go_version LowCardinality(String),14+ goos LowCardinality(String),15+ goarch LowCardinality(String),16+ cpu LowCardinality(String),17+ host LowCardinality(String),18+ pkg LowCardinality(String),19+ name String,20+ procs UInt16,21+ n UInt64,22+ ns_op Float64,23+ b_op Float64,24+ allocs_op Float64,25+ mb_s Float64,26+ metrics Map(String, Float64)27+)28+ENGINE = ReplacingMergeTree29+ORDER BY (cpu, name, ts, run_id);30+31+-- The latest run against the one before it on the same CPU, per32+-- benchmark: what the Grafana regressions table and make stress-report33+-- (DuckDB) both show.34+CREATE VIEW IF NOT EXISTS stress.latest_vs_previous AS35+WITH ranked AS36+(37+ SELECT run_id, cpu, row_number() OVER (PARTITION BY cpu ORDER BY started DESC) AS age38+ FROM (SELECT run_id, cpu, min(ts) AS started FROM stress.results FINAL GROUP BY run_id, cpu)39+)40+SELECT l.cpu AS cpu, l.pkg AS pkg, l.name AS name,41+ p.ns_op AS before_ns, l.ns_op AS after_ns,42+ (l.ns_op - p.ns_op) / p.ns_op AS change43+FROM stress.results AS l FINAL44+JOIN ranked AS kl ON kl.run_id = l.run_id AND kl.cpu = l.cpu45+JOIN stress.results AS p FINAL ON p.cpu = l.cpu AND p.pkg = l.pkg AND p.name = l.name46+JOIN ranked AS kp ON kp.run_id = p.run_id AND kp.cpu = p.cpu47+WHERE kl.age = 1 AND kp.age = 2;
A deploy/observability/docker-compose.yml +82 -0
@@ -0,0 +1,82 @@
1+# Local observability stack for 012: an OpenTelemetry Collector feeding2+# ClickHouse, and Grafana on top. See docs/observability.md.3+#4+# make obs-up start it and print the environment for 0125+# make obs-status containers, endpoints and row counts6+# make obs-down stop it (data stays in the named volumes)7+#8+# Everything listens on 127.0.0.1 only. The credentials are for this9+# local stack; don't expose it.10+name: o12-obs11+12+services:13+ clickhouse:14+ image: clickhouse/clickhouse-server:26.3.34.13615+ environment:16+ CLICKHOUSE_DB: otel17+ CLICKHOUSE_USER: o1218+ CLICKHOUSE_PASSWORD: o1219+ CLICKHOUSE_DEFAULT_ACCESS_MANAGEMENT: "1"20+ ports:21+ - "127.0.0.1:8123:8123" # HTTP: stress-load, queries22+ - "127.0.0.1:9000:9000" # native23+ volumes:24+ - clickhouse-data:/var/lib/clickhouse25+ - ./clickhouse/config.d/memory.xml:/etc/clickhouse-server/config.d/memory.xml:ro26+ - ./clickhouse/init.sql:/docker-entrypoint-initdb.d/init.sql:ro27+ ulimits:28+ nofile: { soft: 262144, hard: 262144 }29+ mem_limit: 3g30+ healthcheck:31+ test: ["CMD", "wget", "-qO-", "http://127.0.0.1:8123/ping"]32+ interval: 3s33+ timeout: 3s34+ retries: 4035+36+ otel-collector:37+ image: otel/opentelemetry-collector-contrib:0.161.038+ user: "0:0" # to write its checkpoint volume and read the bind-mounted logs39+ command: ["--config=/etc/otelcol/config.yaml"]40+ depends_on:41+ clickhouse: { condition: service_healthy }42+ ports:43+ - "127.0.0.1:4317:4317" # OTLP gRPC44+ - "127.0.0.1:4318:4318" # OTLP HTTP45+ volumes:46+ - ./otel-collector.yaml:/etc/otelcol/config.yaml:ro47+ # 012 writes JSON logs here (O12_LOG); the filelog receiver tails them.48+ - ${O12_LOG_DIR:-../../.deps/obs/logs}:/var/log/012:ro49+ - collector-state:/var/lib/otelcol50+ mem_limit: 512m51+52+ grafana:53+ image: grafana/grafana:13.2.254+ depends_on:55+ clickhouse: { condition: service_healthy }56+ environment:57+ GF_INSTALL_PLUGINS: grafana-clickhouse-datasource 4.21.358+ GF_AUTH_ANONYMOUS_ENABLED: "true"59+ GF_AUTH_ANONYMOUS_ORG_ROLE: Viewer60+ GF_SECURITY_ADMIN_PASSWORD: o1261+ GF_DASHBOARDS_DEFAULT_HOME_DASHBOARD_PATH: /var/lib/grafana/dashboards/runtime.json62+ GF_NEWS_NEWS_FEED_ENABLED: "false"63+ GF_ANALYTICS_REPORTING_ENABLED: "false"64+ GF_ANALYTICS_CHECK_FOR_UPDATES: "false"65+ GF_ANALYTICS_CHECK_FOR_PLUGIN_UPDATES: "false"66+ ports:67+ - "127.0.0.1:3000:3000"68+ volumes:69+ - grafana-data:/var/lib/grafana70+ - ./grafana/provisioning:/etc/grafana/provisioning:ro71+ - ./grafana/dashboards:/var/lib/grafana/dashboards:ro72+ mem_limit: 512m73+ healthcheck:74+ test: ["CMD", "wget", "-qO-", "http://127.0.0.1:3000/api/health"]75+ interval: 3s76+ timeout: 3s77+ retries: 6078+79+volumes:80+ clickhouse-data:81+ collector-state:82+ grafana-data:
A deploy/observability/grafana/dashboards/runtime.json +365 -0
@@ -0,0 +1,365 @@
1+{2+ "uid": "o12-runtime",3+ "title": "012 runtime",4+ "description": "012's own event log (012 --log), via the collector's filelog receiver",5+ "tags": [6+ "012"7+ ],8+ "timezone": "browser",9+ "schemaVersion": 39,10+ "version": 1,11+ "editable": true,12+ "refresh": "10s",13+ "time": {14+ "from": "now-1h",15+ "to": "now"16+ },17+ "panels": [18+ {19+ "id": 1,20+ "type": "timeseries",21+ "title": "Recalculation time",22+ "description": "recalc events: incremental and full recalculations, in milliseconds",23+ "datasource": {24+ "type": "grafana-clickhouse-datasource",25+ "uid": "clickhouse"26+ },27+ "gridPos": {28+ "x": 0,29+ "y": 0,30+ "w": 12,31+ "h": 832+ },33+ "targets": [34+ {35+ "datasource": {36+ "type": "grafana-clickhouse-datasource",37+ "uid": "clickhouse"38+ },39+ "editorType": "sql",40+ "format": 0,41+ "queryType": "timeseries",42+ "rawSql": "SELECT $__timeInterval(Timestamp) AS time, quantile(0.5)(toFloat64OrZero(LogAttributes['dur_ms'])) AS p50, quantile(0.95)(toFloat64OrZero(LogAttributes['dur_ms'])) AS p95, max(toFloat64OrZero(LogAttributes['dur_ms'])) AS max FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] = 'recalc' GROUP BY time ORDER BY time",43+ "refId": "A"44+ }45+ ],46+ "fieldConfig": {47+ "defaults": {48+ "unit": "ms",49+ "custom": {50+ "lineWidth": 2,51+ "fillOpacity": 8,52+ "showPoints": "auto",53+ "spanNulls": true54+ }55+ },56+ "overrides": []57+ },58+ "options": {59+ "legend": {60+ "displayMode": "list",61+ "placement": "bottom"62+ },63+ "tooltip": {64+ "mode": "multi"65+ }66+ }67+ },68+ {69+ "id": 2,70+ "type": "timeseries",71+ "title": "Frame and key-to-frame time (p95 per second)",72+ "description": "frames summaries: View() time and the time from a key press to its frame; 16 ms is one frame at 60 Hz",73+ "datasource": {74+ "type": "grafana-clickhouse-datasource",75+ "uid": "clickhouse"76+ },77+ "gridPos": {78+ "x": 12,79+ "y": 0,80+ "w": 12,81+ "h": 882+ },83+ "targets": [84+ {85+ "datasource": {86+ "type": "grafana-clickhouse-datasource",87+ "uid": "clickhouse"88+ },89+ "editorType": "sql",90+ "format": 0,91+ "queryType": "timeseries",92+ "rawSql": "SELECT $__timeInterval(Timestamp) AS time, max(toFloat64OrZero(LogAttributes['render_p95_ms'])) AS render_p95, max(toFloat64OrZero(LogAttributes['key_p95_ms'])) AS key_to_frame_p95, max(toFloat64OrZero(LogAttributes['key_max_ms'])) AS key_to_frame_max FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] = 'frames' GROUP BY time ORDER BY time",93+ "refId": "A"94+ }95+ ],96+ "fieldConfig": {97+ "defaults": {98+ "unit": "ms",99+ "custom": {100+ "lineWidth": 2,101+ "fillOpacity": 8,102+ "showPoints": "auto",103+ "spanNulls": true104+ }105+ },106+ "overrides": []107+ },108+ "options": {109+ "legend": {110+ "displayMode": "list",111+ "placement": "bottom"112+ },113+ "tooltip": {114+ "mode": "multi"115+ }116+ }117+ },118+ {119+ "id": 3,120+ "type": "timeseries",121+ "title": "Heap and cells",122+ "description": "Live heap (left) and stored cells (right), from the per-second frame summaries",123+ "datasource": {124+ "type": "grafana-clickhouse-datasource",125+ "uid": "clickhouse"126+ },127+ "gridPos": {128+ "x": 0,129+ "y": 8,130+ "w": 12,131+ "h": 8132+ },133+ "targets": [134+ {135+ "datasource": {136+ "type": "grafana-clickhouse-datasource",137+ "uid": "clickhouse"138+ },139+ "editorType": "sql",140+ "format": 0,141+ "queryType": "timeseries",142+ "rawSql": "SELECT $__timeInterval(Timestamp) AS time, max(toFloat64OrZero(LogAttributes['heap_bytes'])) AS heap, max(toFloat64OrZero(LogAttributes['cells'])) AS cells FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] = 'frames' GROUP BY time ORDER BY time",143+ "refId": "A"144+ }145+ ],146+ "fieldConfig": {147+ "defaults": {148+ "unit": "bytes",149+ "custom": {150+ "lineWidth": 2,151+ "fillOpacity": 8,152+ "showPoints": "auto",153+ "spanNulls": true154+ }155+ },156+ "overrides": [157+ {158+ "matcher": {159+ "id": "byName",160+ "options": "cells"161+ },162+ "properties": [163+ {164+ "id": "custom.axisPlacement",165+ "value": "right"166+ },167+ {168+ "id": "unit",169+ "value": "short"170+ }171+ ]172+ }173+ ]174+ },175+ "options": {176+ "legend": {177+ "displayMode": "list",178+ "placement": "bottom"179+ },180+ "tooltip": {181+ "mode": "multi"182+ }183+ }184+ },185+ {186+ "id": 4,187+ "type": "timeseries",188+ "title": "JEV answer time",189+ "description": "jev events: request latency and questions still queued when it was sent",190+ "datasource": {191+ "type": "grafana-clickhouse-datasource",192+ "uid": "clickhouse"193+ },194+ "gridPos": {195+ "x": 12,196+ "y": 8,197+ "w": 12,198+ "h": 8199+ },200+ "targets": [201+ {202+ "datasource": {203+ "type": "grafana-clickhouse-datasource",204+ "uid": "clickhouse"205+ },206+ "editorType": "sql",207+ "format": 0,208+ "queryType": "timeseries",209+ "rawSql": "SELECT $__timeInterval(Timestamp) AS time, quantile(0.5)(toFloat64OrZero(LogAttributes['dur_ms'])) AS p50, quantile(0.95)(toFloat64OrZero(LogAttributes['dur_ms'])) AS p95, max(toFloat64OrZero(LogAttributes['queued'])) AS queued FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] = 'jev' GROUP BY time ORDER BY time",210+ "refId": "A"211+ }212+ ],213+ "fieldConfig": {214+ "defaults": {215+ "unit": "ms",216+ "custom": {217+ "lineWidth": 2,218+ "fillOpacity": 8,219+ "showPoints": "auto",220+ "spanNulls": true221+ }222+ },223+ "overrides": []224+ },225+ "options": {226+ "legend": {227+ "displayMode": "list",228+ "placement": "bottom"229+ },230+ "tooltip": {231+ "mode": "multi"232+ }233+ }234+ },235+ {236+ "id": 5,237+ "type": "table",238+ "title": "Imports and exports",239+ "description": "File operations with their sizes and throughput",240+ "datasource": {241+ "type": "grafana-clickhouse-datasource",242+ "uid": "clickhouse"243+ },244+ "gridPos": {245+ "x": 0,246+ "y": 16,247+ "w": 12,248+ "h": 8249+ },250+ "targets": [251+ {252+ "datasource": {253+ "type": "grafana-clickhouse-datasource",254+ "uid": "clickhouse"255+ },256+ "editorType": "sql",257+ "format": 1,258+ "queryType": "table",259+ "rawSql": "SELECT Timestamp AS time, LogAttributes['event'] AS event, LogAttributes['format'] AS format, toFloat64OrZero(LogAttributes['rows']) AS rows, toFloat64OrZero(LogAttributes['cells']) AS cells, round(toFloat64OrZero(LogAttributes['dur_ms']), 1) AS ms, round(toFloat64OrZero(LogAttributes['bytes']) / 1048576 / (toFloat64OrZero(LogAttributes['dur_ms']) / 1000), 1) AS mb_per_s FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] IN ('import', 'export', 'save', 'open') ORDER BY time DESC LIMIT 50",260+ "refId": "A"261+ }262+ ],263+ "fieldConfig": {264+ "defaults": {},265+ "overrides": []266+ },267+ "options": {268+ "showHeader": true,269+ "cellHeight": "sm"270+ }271+ },272+ {273+ "id": 6,274+ "type": "table",275+ "title": "Slowest operations",276+ "description": "The 25 slowest spans in the range: recalcs, commands, sorts, finds, imports",277+ "datasource": {278+ "type": "grafana-clickhouse-datasource",279+ "uid": "clickhouse"280+ },281+ "gridPos": {282+ "x": 12,283+ "y": 16,284+ "w": 12,285+ "h": 8286+ },287+ "targets": [288+ {289+ "datasource": {290+ "type": "grafana-clickhouse-datasource",291+ "uid": "clickhouse"292+ },293+ "editorType": "sql",294+ "format": 1,295+ "queryType": "table",296+ "rawSql": "SELECT Timestamp AS time, LogAttributes['event'] AS event, LogAttributes['id'] AS command, round(toFloat64OrZero(LogAttributes['dur_ms']), 2) AS ms, toFloat64OrZero(LogAttributes['evaluated']) AS evaluated, toFloat64OrZero(LogAttributes['cells']) AS cells FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' AND LogAttributes['event'] NOT IN ('frames', 'start', 'frame') ORDER BY ms DESC LIMIT 25",297+ "refId": "A"298+ }299+ ],300+ "fieldConfig": {301+ "defaults": {},302+ "overrides": []303+ },304+ "options": {305+ "showHeader": true,306+ "cellHeight": "sm"307+ }308+ },309+ {310+ "id": 7,311+ "type": "timeseries",312+ "title": "Events per minute",313+ "description": "What 012 has been doing, by event type",314+ "datasource": {315+ "type": "grafana-clickhouse-datasource",316+ "uid": "clickhouse"317+ },318+ "gridPos": {319+ "x": 0,320+ "y": 24,321+ "w": 24,322+ "h": 7323+ },324+ "targets": [325+ {326+ "datasource": {327+ "type": "grafana-clickhouse-datasource",328+ "uid": "clickhouse"329+ },330+ "editorType": "sql",331+ "format": 0,332+ "queryType": "timeseries",333+ "rawSql": "SELECT toStartOfMinute(Timestamp) AS time, LogAttributes['event'] AS event, count() AS n FROM otel.otel_logs WHERE $__timeFilter(Timestamp) AND ServiceName = '012' GROUP BY time, event ORDER BY time",334+ "refId": "A"335+ }336+ ],337+ "fieldConfig": {338+ "defaults": {339+ "custom": {340+ "lineWidth": 2,341+ "fillOpacity": 8,342+ "showPoints": "auto",343+ "spanNulls": true344+ }345+ },346+ "overrides": []347+ },348+ "options": {349+ "legend": {350+ "displayMode": "list",351+ "placement": "bottom"352+ },353+ "tooltip": {354+ "mode": "multi"355+ }356+ }357+ }358+ ],359+ "templating": {360+ "list": []361+ },362+ "annotations": {363+ "list": []364+ }365+}\ No newline at end of file
A deploy/observability/grafana/dashboards/stress.json +319 -0
@@ -0,0 +1,319 @@
1+{2+ "uid": "o12-stress",3+ "title": "012 stress runs",4+ "description": "make stress results over time (stress.results)",5+ "tags": [6+ "012"7+ ],8+ "timezone": "browser",9+ "schemaVersion": 39,10+ "version": 1,11+ "editable": true,12+ "refresh": "10s",13+ "time": {14+ "from": "now-30d",15+ "to": "now"16+ },17+ "panels": [18+ {19+ "id": 1,20+ "type": "timeseries",21+ "title": "Engine: edit latency by topology",22+ "description": "BenchmarkEdit: one Set and its incremental recalc, per run (log scale)",23+ "datasource": {24+ "type": "grafana-clickhouse-datasource",25+ "uid": "clickhouse"26+ },27+ "gridPos": {28+ "x": 0,29+ "y": 0,30+ "w": 12,31+ "h": 832+ },33+ "targets": [34+ {35+ "datasource": {36+ "type": "grafana-clickhouse-datasource",37+ "uid": "clickhouse"38+ },39+ "editorType": "sql",40+ "format": 0,41+ "queryType": "timeseries",42+ "rawSql": "SELECT ts AS time, name, ns_op / 1e6 AS ms FROM stress.results FINAL WHERE $__timeFilter(ts) AND match(name, '^Edit/') ORDER BY time",43+ "refId": "A"44+ }45+ ],46+ "fieldConfig": {47+ "defaults": {48+ "unit": "ms",49+ "custom": {50+ "lineWidth": 2,51+ "fillOpacity": 8,52+ "showPoints": "always",53+ "spanNulls": true,54+ "scaleDistribution": {55+ "type": "log",56+ "log": 1057+ },58+ "pointSize": 659+ },60+ "displayName": "${__field.labels.name}"61+ },62+ "overrides": []63+ },64+ "options": {65+ "legend": {66+ "displayMode": "list",67+ "placement": "bottom"68+ },69+ "tooltip": {70+ "mode": "multi"71+ }72+ }73+ },74+ {75+ "id": 2,76+ "type": "timeseries",77+ "title": "UI: frame and keystroke time",78+ "description": "Whole frames (View, parse, diff) and key presses through to their frame (log scale)",79+ "datasource": {80+ "type": "grafana-clickhouse-datasource",81+ "uid": "clickhouse"82+ },83+ "gridPos": {84+ "x": 12,85+ "y": 0,86+ "w": 12,87+ "h": 888+ },89+ "targets": [90+ {91+ "datasource": {92+ "type": "grafana-clickhouse-datasource",93+ "uid": "clickhouse"94+ },95+ "editorType": "sql",96+ "format": 0,97+ "queryType": "timeseries",98+ "rawSql": "SELECT ts AS time, name, ns_op / 1e6 AS ms FROM stress.results FINAL WHERE $__timeFilter(ts) AND match(name, '^(Frame/(dense-8192x256|longtext-8192x500|charts-20)/200x60|Keystroke/(arrow/dense-8192x256|extend-data/dense-8192x256|type/fanin-1000)/80x24)$') ORDER BY time",99+ "refId": "A"100+ }101+ ],102+ "fieldConfig": {103+ "defaults": {104+ "unit": "ms",105+ "custom": {106+ "lineWidth": 2,107+ "fillOpacity": 8,108+ "showPoints": "always",109+ "spanNulls": true,110+ "scaleDistribution": {111+ "type": "log",112+ "log": 10113+ },114+ "pointSize": 6115+ },116+ "displayName": "${__field.labels.name}"117+ },118+ "overrides": []119+ },120+ "options": {121+ "legend": {122+ "displayMode": "list",123+ "placement": "bottom"124+ },125+ "tooltip": {126+ "mode": "multi"127+ }128+ }129+ },130+ {131+ "id": 3,132+ "type": "timeseries",133+ "title": "Full recalc and file operations",134+ "description": "RecalcAll per topology, native save and open of 2.1M cells, CSV imports (log scale)",135+ "datasource": {136+ "type": "grafana-clickhouse-datasource",137+ "uid": "clickhouse"138+ },139+ "gridPos": {140+ "x": 0,141+ "y": 8,142+ "w": 12,143+ "h": 8144+ },145+ "targets": [146+ {147+ "datasource": {148+ "type": "grafana-clickhouse-datasource",149+ "uid": "clickhouse"150+ },151+ "editorType": "sql",152+ "format": 0,153+ "queryType": "timeseries",154+ "rawSql": "SELECT ts AS time, name, ns_op / 1e6 AS ms FROM stress.results FINAL WHERE $__timeFilter(ts) AND match(name, '^(RecalcAll/|Save/dense-8192x256|Open/dense-8192x256|Import/(owid|airport))') ORDER BY time",155+ "refId": "A"156+ }157+ ],158+ "fieldConfig": {159+ "defaults": {160+ "unit": "ms",161+ "custom": {162+ "lineWidth": 2,163+ "fillOpacity": 8,164+ "showPoints": "always",165+ "spanNulls": true,166+ "scaleDistribution": {167+ "type": "log",168+ "log": 10169+ },170+ "pointSize": 6171+ },172+ "displayName": "${__field.labels.name}"173+ },174+ "overrides": []175+ },176+ "options": {177+ "legend": {178+ "displayMode": "list",179+ "placement": "bottom"180+ },181+ "tooltip": {182+ "mode": "multi"183+ }184+ }185+ },186+ {187+ "id": 4,188+ "type": "timeseries",189+ "title": "Memory per cell",190+ "description": "Live heap per non-blank cell after loading",191+ "datasource": {192+ "type": "grafana-clickhouse-datasource",193+ "uid": "clickhouse"194+ },195+ "gridPos": {196+ "x": 12,197+ "y": 8,198+ "w": 12,199+ "h": 8200+ },201+ "targets": [202+ {203+ "datasource": {204+ "type": "grafana-clickhouse-datasource",205+ "uid": "clickhouse"206+ },207+ "editorType": "sql",208+ "format": 0,209+ "queryType": "timeseries",210+ "rawSql": "SELECT ts AS time, name, metrics['B/cell'] AS bytes_per_cell FROM stress.results FINAL WHERE $__timeFilter(ts) AND mapContains(metrics, 'B/cell') ORDER BY time",211+ "refId": "A"212+ }213+ ],214+ "fieldConfig": {215+ "defaults": {216+ "unit": "bytes",217+ "custom": {218+ "lineWidth": 2,219+ "fillOpacity": 8,220+ "showPoints": "always",221+ "spanNulls": true,222+ "pointSize": 6223+ },224+ "displayName": "${__field.labels.name}"225+ },226+ "overrides": []227+ },228+ "options": {229+ "legend": {230+ "displayMode": "list",231+ "placement": "bottom"232+ },233+ "tooltip": {234+ "mode": "multi"235+ }236+ }237+ },238+ {239+ "id": 5,240+ "type": "table",241+ "title": "Latest run against the previous one",242+ "description": "Changes over 10% and 2 us; positive is slower (a regression)",243+ "datasource": {244+ "type": "grafana-clickhouse-datasource",245+ "uid": "clickhouse"246+ },247+ "gridPos": {248+ "x": 0,249+ "y": 16,250+ "w": 12,251+ "h": 8252+ },253+ "targets": [254+ {255+ "datasource": {256+ "type": "grafana-clickhouse-datasource",257+ "uid": "clickhouse"258+ },259+ "editorType": "sql",260+ "format": 1,261+ "queryType": "table",262+ "rawSql": "SELECT pkg, name, round(before_ns / 1e6, 3) AS before_ms, round(after_ns / 1e6, 3) AS after_ms, round(change * 100, 1) AS change_pct FROM stress.latest_vs_previous WHERE abs(change) > 0.10 AND abs(after_ns - before_ns) > 2000 ORDER BY change DESC",263+ "refId": "A"264+ }265+ ],266+ "fieldConfig": {267+ "defaults": {},268+ "overrides": []269+ },270+ "options": {271+ "showHeader": true,272+ "cellHeight": "sm"273+ }274+ },275+ {276+ "id": 6,277+ "type": "table",278+ "title": "Runs",279+ "description": "",280+ "datasource": {281+ "type": "grafana-clickhouse-datasource",282+ "uid": "clickhouse"283+ },284+ "gridPos": {285+ "x": 12,286+ "y": 16,287+ "w": 12,288+ "h": 8289+ },290+ "targets": [291+ {292+ "datasource": {293+ "type": "grafana-clickhouse-datasource",294+ "uid": "clickhouse"295+ },296+ "editorType": "sql",297+ "format": 1,298+ "queryType": "table",299+ "rawSql": "SELECT run_id, min(ts) AS ts, any(git_sha) AS sha, max(git_dirty) AS dirty, any(cpu) AS cpu, any(go_version) AS go, count() AS benchmarks FROM stress.results FINAL GROUP BY run_id ORDER BY ts DESC LIMIT 20",300+ "refId": "A"301+ }302+ ],303+ "fieldConfig": {304+ "defaults": {},305+ "overrides": []306+ },307+ "options": {308+ "showHeader": true,309+ "cellHeight": "sm"310+ }311+ }312+ ],313+ "templating": {314+ "list": []315+ },316+ "annotations": {317+ "list": []318+ }319+}\ No newline at end of file
A deploy/observability/grafana/provisioning/dashboards/012.yaml +8 -0
A deploy/observability/grafana/provisioning/datasources/clickhouse.yaml +23 -0
A deploy/observability/otel-collector.yaml +73 -0
@@ -0,0 +1,73 @@
1+# OpenTelemetry Collector for 012: OTLP (gRPC and HTTP) for any2+# instrumented process, and the filelog receiver for 012's own JSON3+# event logs (012 --log .deps/obs/logs/012.jsonl), all into ClickHouse.4+extensions:5+ health_check:6+ endpoint: 0.0.0.0:131337+ file_storage:8+ directory: /var/lib/otelcol # remembers how far each log was read9+10+receivers:11+ otlp:12+ protocols:13+ grpc:14+ endpoint: 0.0.0.0:431715+ http:16+ endpoint: 0.0.0.0:431817+ file_log/012:18+ include: [/var/log/012/*.jsonl]19+ start_at: beginning20+ storage: file_storage21+ operators:22+ # One slog JSON object per line: time, level, msg, service, event,23+ # dur_ms and the event's counts become the record's attributes.24+ - type: json_parser25+ timestamp:26+ parse_from: attributes.time27+ layout_type: gotime28+ layout: "2006-01-02T15:04:05.999999999Z07:00"29+ severity:30+ parse_from: attributes.level31+ - type: move32+ from: attributes.msg33+ to: body34+ - type: move35+ from: attributes.service36+ to: resource["service.name"]37+ - type: remove38+ field: attributes.time39+ - type: remove40+ field: attributes.level41+42+processors:43+ memory_limiter:44+ check_interval: 1s45+ limit_mib: 40046+ spike_limit_mib: 10047+ batch:48+ timeout: 2s49+50+exporters:51+ clickhouse:52+ endpoint: tcp://clickhouse:9000?dial_timeout=10s53+ database: otel54+ username: o1255+ password: o1256+ ttl: 720h57+ create_schema: true58+59+service:60+ extensions: [health_check, file_storage]61+ pipelines:62+ logs:63+ receivers: [otlp, file_log/012]64+ processors: [memory_limiter, batch]65+ exporters: [clickhouse]66+ traces:67+ receivers: [otlp]68+ processors: [memory_limiter, batch]69+ exporters: [clickhouse]70+ metrics:71+ receivers: [otlp]72+ processors: [memory_limiter, batch]73+ exporters: [clickhouse]
M internal/telemetry/telemetry.go +1 -1
A scripts/obs.sh +52 -0
@@ -0,0 +1,52 @@
1+#!/usr/bin/env bash2+# obs.sh up|down|status - the local observability stack in3+# deploy/observability (OpenTelemetry Collector, ClickHouse, Grafana).4+# make obs-up, obs-down and obs-status call this.5+set -euo pipefail6+7+root=$(cd "$(dirname "$0")/.." && pwd)8+compose=(docker compose -f "$root/deploy/observability/docker-compose.yml")9+logs="$root/.deps/obs/logs"10+ch=${CLICKHOUSE_URL:-http://localhost:8123}11+auth="${CLICKHOUSE_USER:-o12}:${CLICKHOUSE_PASSWORD:-o12}"12+13+query() { curl -fsS -u "$auth" --get --data-urlencode "query=$1" "$ch/" 2>/dev/null; }14+15+case "${1:-}" in16+up)17+ mkdir -p "$logs"18+ "${compose[@]}" up -d --wait19+ cat <<EOF20+21+Observability stack is up:22+ Grafana http://localhost:3000 (dashboards: 012 runtime, 012 stress runs)23+ ClickHouse http://localhost:8123 (user o12, password o12; databases otel, stress)24+ Collector OTLP on localhost:4317 (gRPC) and localhost:4318 (HTTP)25+26+Point 012 at it (its JSON event log is tailed by the collector):27+ export O12_LOG=$logs/012.jsonl28+29+make stress loads each run into ClickHouse while the stack is up;30+make stress-load loads the runs recorded so far.31+EOF32+ ;;33+down)34+ "${compose[@]}" down35+ ;;36+status)37+ "${compose[@]}" ps38+ echo39+ if ! query "SELECT 1" >/dev/null; then40+ echo "ClickHouse: not answering at $ch"41+ exit 042+ fi43+ echo "ClickHouse row counts:"44+ query "SELECT database || '.' || name, total_rows FROM system.tables WHERE database IN ('otel', 'stress') AND engine NOT LIKE '%View%' ORDER BY 1 FORMAT PrettyCompactNoEscapes"45+ echo "012 events by type (last hour):"46+ query "SELECT LogAttributes['event'] AS event, count() AS n, round(quantile(0.95)(toFloat64OrZero(LogAttributes['dur_ms'])), 2) AS p95_ms FROM otel.otel_logs WHERE ServiceName = '012' AND Timestamp > now() - INTERVAL 1 HOUR GROUP BY event ORDER BY n DESC FORMAT PrettyCompactNoEscapes" || true47+ ;;48+*)49+ echo "usage: $0 up|down|status" >&250+ exit 251+ ;;52+esac
A scripts/stress/clickhouse-load.sh +33 -0
@@ -0,0 +1,33 @@
1+#!/usr/bin/env bash2+# clickhouse-load.sh - load the stress run records (runs.jsonl) into the3+# observability stack's ClickHouse, table stress.results, for Grafana.4+# Loading the same runs again is harmless: the table deduplicates, and5+# queries read it with FINAL. make stress runs this when the stack is up.6+set -euo pipefail7+8+root=$(cd "$(dirname "$0")/../.." && pwd)9+results=${RESULTS:-"$root/.deps/stress/results/runs.jsonl"}10+url=${CLICKHOUSE_URL:-http://localhost:8123}11+auth="${CLICKHOUSE_USER:-o12}:${CLICKHOUSE_PASSWORD:-o12}"12+compose="$root/deploy/observability/docker-compose.yml"13+14+if [ ! -s "$results" ]; then15+ echo "stress-load: no results in $results; run make stress first" >&216+ exit 117+fi18+if ! curl -fsS -o /dev/null "$url/ping"; then19+ echo "stress-load: ClickHouse isn't answering at $url; run make obs-up" >&220+ exit 121+fi22+23+# The schema is created when the stack first starts; this keeps an older24+# volume current.25+docker compose -f "$compose" exec -T clickhouse \26+ clickhouse-client --user "${auth%%:*}" --password "${auth#*:}" --multiquery \27+ <"$root/deploy/observability/clickhouse/init.sql"28+29+query='INSERT INTO stress.results SETTINGS date_time_input_format = '\''best_effort'\'' FORMAT JSONEachRow'30+# The body is the query, then the rows.31+{ echo "$query"; cat "$results"; } | curl -fsS -u "$auth" --data-binary @- -o /dev/null "$url/"32+runs=$(curl -fsS -u "$auth" --get --data-urlencode "query=SELECT uniqExact(run_id), count() FROM stress.results FINAL FORMAT TSV" "$url/")33+echo "stress-load: ClickHouse stress.results now holds $(echo "$runs" | cut -f1) runs, $(echo "$runs" | cut -f2) rows"