はじめに

さかのぼること数年前、まだ未熟だった私は、こんな記事を書きました。

今考えると笑いどころしかありません。
ふと思い出して恥ずかしくなったので、今回はちゃんとパフォーマンスの出るログ管理システムを作っていこうと思います。

ツール紹介

ClickHouse

言わずと知れた列志向のDBMS。
NewSQLとか言われますね。

どんなツールなのかは中の人のQiitaを読んでいただければと思います。

Vector

軽量・高速・監視向けをうたうデータパイプラインです。
Rust製らしい。
データの変換処理がプログラマブルなので、いろいろ対応できます。

metabase

OSSのデータ可視化ツールです。
以上！

アーキテクチャ

Nginx

アクセスログをJSONで出力します。

Vector

ログファイルを監視し、パースしてClickHouseへBulk INSERTします。
Nginxのエラーログはフォーマットを変えられないため、パーサーを書きます。

ClickHouse

いっぱい頑張って保存してもらいます。

metabase

ClickHouseドライバを使用して接続し、ダッシュボードを構築します。
内部DBをPostgerSQLにし、安定化を図ります。

構築

Nginx

ログ形式変更

まずはNginxがJSONで吐けるようにします。

http {
    # ボディはPOST/PUTのみ記録
    map $request_method $log_body {
        POST    $request_body;
        PUT     $request_body;
        default "";
    }

    # Vector/ClickHouseに最適化したJSONフォーマット
    # ほしいパラメータがあれば勝手に追加してください
    log_format json escape=json
      '{"ts":$msec,'
      '"c":"$remote_addr",'
      '"m":"$request_method",'
      '"s":$status,'
      '"h":"$host",'
      '"uri":"$uri",'
      '"q":"$args",'
      '"ref":"$http_referer",'
      '"xff":"$http_x_forwarded_for",'
      '"b":$body_bytes_sent,'
      '"rt":$request_time,'
      '"ua":"$http_user_agent",'
      '"auth":"$http_authorization"}';

    # gzip圧縮はせず、フラッシュバッファのみ設定
    access_log /var/log/nginx/access.log json buffer=64k flush=5s;
    error_log  /var/log/nginx/error.log warn;

    # バックエンドの500エラー等をNginx側で確実に捕捉する
    proxy_intercept_errors on;
    
    # ... その他の設定 ...
}

ログローテートのシグナル設定

ログローテート時にVectorがファイルロストしないよう、シグナル送信設定を行います。

/etc/logrotate.d/nginx.conf

/var/log/nginx/*.log {
    daily
    missingok
    rotate 14
    compress
    delaycompress
    notifempty
    create 0640 nginx adm
    sharedscripts
    postrotate
        if [ -f /var/run/nginx.pid ]; then
            kill -USR1 `cat /var/run/nginx.pid`
        fi
    endscript
}

基盤構築

ディレクトリ作成

次のディレクトリを作成します。

$ mkdir -p ./clickhouse/init ./clickhouse/data ./metabase/plugins ./metabase/data vector

Docker

./docker-compose.yml

docker-compose.yml

services:
  metabase-db:
    image: postgres:15-alpine
    container_name: metabase-db
    environment:
      - POSTGRES_DB=metabase
      - POSTGRES_USER=metabase
      - POSTGRES_PASSWORD=metabase_password
    volumes:
      - ./metabase/db-data:/var/lib/postgresql/data

  clickhouse:
    image: clickhouse/clickhouse-server:latest
    container_name: clickhouse
    ports:
      - "8123:8123"
      - "9000:9000"
    volumes:
      - ./clickhouse/data:/var/lib/clickhouse
      - ./clickhouse/init:/docker-entrypoint-initdb.d
    environment:
      - CLICKHOUSE_DB=logs
      - CLICKHOUSE_USER=user
      - CLICKHOUSE_PASSWORD=password
    ulimits:
      nofile:
        soft: 262144
        hard: 262144

  vector:
    image: timberio/vector:latest-alpine
    container_name: vector
    command: ["--config", "/etc/vector/vector.toml"]
    volumes:
      - ./vector/vector.toml:/etc/vector/vector.toml:ro
      - /var/log/nginx:/var/log/nginx:ro
    environment:
      - CLICKHOUSE_PASSWORD=password
    depends_on:
      - clickhouse

  metabase:
    image: metabase/metabase:latest
    container_name: metabase
    ports:
      - "3000:3000"
    volumes:
      - ./metabase/plugins:/plugins
    environment:
      - MB_PLUGINS_DIR=/plugins
      - MB_DB_TYPE=postgres
      - MB_DB_DBNAME=metabase
      - MB_DB_PORT=5432
      - MB_DB_USER=metabase
      - MB_DB_PASS=metabase_password
      - MB_DB_HOST=metabase-db
    depends_on:
      - metabase-db
      - clickhouse

Vector

./vector/vector.toml

vector.toml

# --- Access Logs ---
[sources.nginx_access]
type      = "file"
include   = ["/var/log/nginx/access.log*"]
read_from = "end"
ignore_older_secs = 600

[transforms.parse_access]
type   = "remap"
inputs = ["nginx_access"]
source = '''
msg_str = string!(.message)
parsed, err = parse_json(msg_str)
if err != null {
    log("Skipping invalid JSON: " + err, level: "warn")
    abort
}

new_event = {}

ts_float = to_float(parsed.ts) ?? 0.0
ts_ms = to_int(ts_float * 1000.0)
ts_val = from_unix_timestamp!(ts_ms, unit: "milliseconds")
new_event.time = format_timestamp!(ts_val, "%Y-%m-%d %H:%M:%S")

client_str = string(parsed.c) ?? ""
if client_str == "" {
    new_event.client = "::"
} else {
    new_event.client = client_str
}

new_event.method = string(parsed.m) ?? "UNKNOWN"
new_event.status = to_int(parsed.s) ?? 0
new_event.host = string(parsed.h) ?? "unknown"
new_event.uri = string(parsed.uri) ?? ""
new_event.args = string(parsed.q) ?? ""

referer = string(parsed.ref) ?? ""
if referer == "-" { new_event.referer = "" } else { new_event.referer = referer }

new_event.bytes_sent = to_int(parsed.b) ?? 0
new_event.request_time = to_float(parsed.rt) ?? 0.0
new_event.user_agent = string(parsed.ua) ?? ""

xff_str = string(parsed.xff) ?? ""
if xff_str == "-" || xff_str == "" {
  new_event.xff = "::"
} else {
  xff_parts = split(xff_str, ",")
  xff_val = strip_whitespace!(xff_parts[0])
  if xff_val == "" {
      new_event.xff = "::"
  } else {
      new_event.xff = xff_val
  }
}

. = new_event
'''

[sinks.clickhouse_access]
type     = "clickhouse"
inputs   = ["parse_access"]
endpoint = "http://clickhouse:8123"
database = "logs"
table    = "access"
auth.strategy = "basic"
auth.user     = "user"
auth.password = "password"
skip_unknown_fields = true

# --- Error Logs ---
[sources.nginx_error]
type      = "file"
include   = ["/var/log/nginx/error.log*"]
read_from = "end"

[transforms.parse_error]
type   = "remap"
inputs = ["nginx_error"]
source = '''
msg_str = string!(.message)
parsed, err = parse_regex(msg_str, r'^(?P<timestamp>\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}) \[(?P<level>\w+)\] (?P<pid>\d+)#(?P<tid>\d+): (?P<message>.*?)(?:, client: (?P<client>[^,]+))?(?:, server: (?P<server>[^,]+))?(?:, request: "(?P<request>.*?)")?(?:, host: "(?P<host>.*?)")?$')
if err == null {
    new_event = {}
    new_event.level = parsed.level
    new_event.message = parsed.message
    
    ts_val = parse_timestamp!(string!(parsed.timestamp), "%Y/%m/%d %H:%M:%S")
    new_event.time = format_timestamp!(ts_val, "%Y-%m-%d %H:%M:%S")
    
    new_event.pid = to_int(parsed.pid) ?? 0
    new_event.tid = to_int(parsed.tid) ?? 0
    new_event.client = string(parsed.client) ?? ""
    new_event.server = string(parsed.server) ?? ""
    new_event.request = string(parsed.request) ?? ""
    new_event.host = string(parsed.host) ?? ""
    . = new_event
} else {
    log("Failed to parse error log: " + err, level: "error")
    abort
}
'''

[sinks.clickhouse_error]
type     = "clickhouse"
inputs   = ["parse_error"]
endpoint = "http://clickhouse:8123"
database = "logs"
table    = "errors"
auth.strategy = "basic"
auth.user     = "user"
auth.password = "password"
skip_unknown_fields = true

ClickHouse

./clickhouse/init/01_schema.sql

01_scheme.sql

```sql
CREATE DATABASE IF NOT EXISTS logs;

CREATE TABLE IF NOT EXISTS logs.access
(
    time          DateTime                 CODEC(DoubleDelta, ZSTD(1)),
    client        IPv6                     CODEC(ZSTD(1)),
    method        LowCardinality(String),
    status        UInt16,
    host          LowCardinality(String),
    uri           String                   CODEC(ZSTD(3)),
    args          String                   CODEC(ZSTD(3)),
    referer       String                   CODEC(ZSTD(3)),
    xff           IPv6                     CODEC(ZSTD(1)),
    bytes_sent    UInt64                   CODEC(Delta, ZSTD(1)),
    request_time  Float32,
    user_agent    LowCardinality(String)
)
ENGINE = MergeTree()
PARTITION BY toYYYYMM(time)
ORDER BY (time, status, host, client)
TTL time + INTERVAL 90 DAY DELETE;

CREATE TABLE IF NOT EXISTS logs.errors
(
    time      DateTime,
    level     LowCardinality(String),
    pid       UInt32,
    tid       UInt32,
    message   String                   CODEC(ZSTD(3)),
    client    String                   CODEC(ZSTD(1)),
    server    String                   CODEC(ZSTD(1)),
    request   String                   CODEC(ZSTD(3)),
    host      String                   CODEC(ZSTD(1))
)
ENGINE = MergeTree()
PARTITION BY toYYYYMM(time)
ORDER BY (time, level);

Metabase->ClickHouseドライバの準備

$ curl -L https://github.com/ClickHouse/metabase-clickhouse-driver/releases/latest/download/clickhouse.metabase-driver.jar -o ./metabase/plugins/clickhouse.metabase-driver.jar

起動

docker compose up -dでサービスを上げます。
初回はmetabaseのinitに時間がかかるので、しばらく待ちましょう。
docker logs -t -f metabaseとかで見ておくといいと思います。

スキーマ流し込みと事前集計用Viewの作成

これを抜かすと負荷がたいへんです。

$ docker exec -it clickhouse clickhouse-client --query "CREATE DATABASE IF NOT EXISTS logs"

$ docker exec -i clickhouse clickhouse-client -n < ./clickhouse/init/01_schema.sql

$ docker exec -i clickhouse clickhouse-client -d logs --query "
CREATE OR REPLACE VIEW access_view AS SELECT toTimeZone(time, 'Asia/Tokyo') AS time, CAST(client AS String) AS client, method, status, host, uri, args, referer, CAST(xff AS String) AS xff, bytes_sent, request_time, user_agent, concat(host, uri, if(args != '', concat('?', args), '')) AS full_url FROM access;

CREATE OR REPLACE VIEW errors_view AS SELECT toTimeZone(time, 'Asia/Tokyo') AS time, level, pid, tid, message, client, server, request, host FROM errors;

DROP TABLE IF EXISTS mv_traffic_minutely;
DROP TABLE IF EXISTS traffic_minutely_view;
CREATE MATERIALIZED VIEW mv_traffic_minutely ENGINE = SummingMergeTree() ORDER BY (minute, host, status) POPULATE AS SELECT toStartOfMinute(time) AS minute, host, status, count() AS total_requests, sum(bytes_sent) AS total_bytes, sum(request_time) AS sum_request_time FROM access GROUP BY minute, host, status;
CREATE OR REPLACE VIEW traffic_minutely_view AS SELECT toTimeZone(minute, 'Asia/Tokyo') AS time, host, status, total_requests, total_bytes, if(total_requests > 0, sum_request_time / total_requests, 0) AS avg_request_time FROM mv_traffic_minutely;

DROP TABLE IF EXISTS mv_url_stats_hourly;
DROP TABLE IF EXISTS url_stats_hourly_view;
CREATE MATERIALIZED VIEW mv_url_stats_hourly ENGINE = SummingMergeTree() ORDER BY (hour, full_url) POPULATE AS SELECT toStartOfHour(time) AS hour, concat(host, uri, if(args != '', concat('?', args), '')) AS full_url, count() AS total_requests, sum(request_time) AS sum_request_time, sum(bytes_sent) AS total_bytes FROM access GROUP BY hour, full_url;
CREATE OR REPLACE VIEW url_stats_hourly_view AS SELECT toTimeZone(hour, 'Asia/Tokyo') AS time, full_url, total_requests, if(total_requests > 0, sum_request_time / total_requests, 0) AS avg_request_time FROM mv_url_stats_hourly;
"

Metabase初回セットアップ

ユーザー作成・DB接続

http://<server>:3000にアクセスし、ユーザーを作成してください。
作成が終わったら、DB接続に移ります。
コネクタ一覧からClickHouseを選び、次のように設定します。

Host: clickhouse
Port: 8123
Database name: logs
User: user
Password: password

ローカライゼーション設定

ログインしたら、右上のボタンから管理を開きます。

管理画面が開いたら、設定 -> ローカライズ -> レポートのタイムゾーンでAsia/Tokyoにします。
ほかのタイムゾーンが良ければここはやらなくていいです。

セマンティックタイプの無効化

ClickHouseコネクタのバグで、IPv6だろうがIPv4だろうが勝手にtoIPv4()して検索できなくなるバグがあるので、対策します。
管理画面のテーブルメタデータ -> DB名 -> Access View -> Clientを開きます。

セマンティックタイプをなしにします。

Xffにも同じ設定をします。

これで基本的な設定は完了です。

チャート作成例

細かいところは調べてもらうかAIに聞いてもらうとして、次のチャートの作成方法を解説します。
それぞれ右上の新規 -> 質問で作成です。

毎分のトラフィック推移

データ: Traffic Minutely View
- カラム: Time, Status, Total Requests
カスタム列: case([Status] < 400, "正常", [Status] < 500, "クライアントエラー", "サーバーエラー")

ここまで設定したら、可視化を押します。

左下の可視化ボタンを押すと、グラフの種類などが選べるので折れ線にします。
可視化ボタンの右の歯車を押すとグラフ設定に入れるので、適当に色を付けたりします。

あとはダッシュボードに配置するなりご自由にどうぞ。

全期間のHTTPレスポンスステータス割合

こちらは円グラフです。

データ: Traffic Minutely View
- カラム: すべて？だった気がします
カスタム列: case([Status] < 400, "正常", [Status] < 500, "クライアントエラー", "サーバーエラー")
- カスタム列につけた名前を覚えておいてください。
集計: 合計...->Total Requests で カスタム列につけた名前

これで先ほどと同じように可視化画面に行き、円グラフを選べばいい感じになります。

おわり

ほかにほしい可視化などがあれば、この記事を読ませたうえでAIに聞いてみればポンと出してくれると思います。

今はこんな感じのダッシュボードを組んでます。