TCP ロギングプロキシを 400 行の Rust で書いてバイト列を覗く

既存ツールがハマらない

バックエンドエンジニアなら一度は聞いたことがある疑問: 「クライアントは本当に自分が思っている通りのバイト列を送っているのか?」。バイトはそこにあるのに、見るのがやたら面倒。

最近 Postgres、Redis、自作 RPC のフレーミングなど生の TCP プロトコルをデバッグすることが多く、手持ちのツールとのギャップに嫌気がさした。

tcpdump / Wireshark — パケットレベルでは最高だが、TCP セグメントとアプリケーションメッセージは別物。pcap からセッションを復元するのに毎回 1 分かかる。root がないとキャプチャすらできない
socat — TCP ポートの転送はできるが、通過するバイトのログは取れない。tee をつないでも方向の区別が消える
mitmproxy — HTTP 専用。Postgres ワイヤプロトコルには対応しない
使い捨て tokio スクリプト — 3 回書いた。毎回「色付き方向マーカーを追加して」「hex dump を切り詰めて」と要求が増えて書き直し

そこで、欲しかったツールを 400 行で書いた。

🔗 GitHub: https://github.com/sen-ltd/tcp-proxy

Screenshot

何を作ったか

tcp-proxy は CLI。--listen と --forward を渡す。listen 側で TCP 接続を受け、forward 側に接続し、双方向にバイトを中継しながら、各チャンクを hexdump -C 形式でログに出す。接続ごとにセッション ID 付き。

tcp-proxy --listen 127.0.0.1:6380 --forward 127.0.0.1:6379

Redis クライアントを :6380 に向けると:

listening on 127.0.0.1:6380, forwarding to 127.0.0.1:6379
[sid=0001] accepted from 127.0.0.1:55318
[sid=0001] C->S (14 bytes)
00000000  2a 31 0d 0a 24 34 0d 0a  50 49 4e 47 0d 0a        |*1..$4..PING..  |
[sid=0001] S->C (7 bytes)
00000000  2b 50 4f 4e 47 0d 0a                              |+PONG..         |
[sid=0001] closed: eof

これで全部。

設計判断 #1: `copy_bidirectional` を使わない

最初に手が伸びるのは tokio::io::copy_bidirectional。2 つの AsyncRead + AsyncWrite をつないでバイトを永遠にシャッフルする。1 関数呼び出しでプロキシ完成。

だがこの問題には使えない。copy_bidirectional はカーネルのソケットバッファを通してバイトを移動するが、途中で手元に落とすフックがない。「この 4096 バイトを印刷させて」と言う場所がない。

手書きのコピーループ:

async fn tee_loop<R, W>(
    src: &mut R,
    dst: &mut W,
    arrow: Arrow,
    sid: &str,
    cfg: &SessionConfig,
    sink: Arc<dyn LogSink>,
    shutdown: Arc<AtomicBool>,
) -> TeeOutcome
where
    R: AsyncReadExt + Unpin,
    W: AsyncWriteExt + Unpin,
{
    let mut buf = vec![0u8; 8 * 1024];
    loop {
        if shutdown.load(Ordering::Relaxed) {
            return TeeOutcome::Shutdown;
        }
        let read = match timeout(cfg.idle_timeout, src.read(&mut buf)).await {
            Ok(Ok(n)) => n,
            Ok(Err(_)) => return TeeOutcome::Error,
            Err(_) => return TeeOutcome::Timeout,
        };
        if read == 0 {
            let _ = dst.shutdown().await;
            return TeeOutcome::Eof;
        }
        let chunk = &buf[..read];

        // ログが先。転送は後。逆にすると遅い upstream で hex dump がズレる。
        let record = crate::logger::format_chunk(
            cfg.format, sid, arrow, chunk, cfg.max_dump, cfg.no_dump,
        );
        sink.write_blocking(&record);

        if dst.write_all(chunk).await.is_err() {
            return TeeOutcome::Error;
        }
    }
}

1 接続に 2 つのループが並行動作 — client→server と server→client。それぞれソケットの read half と write half を持つ（TcpStream::into_split）。ログシンクは Arc で共有。

「ログしてから転送」 の順序が重要。転送を先にすると、upstream が遅いときに hex dump のタイミングがバイト到着時刻とずれる。ログを先にすれば「tcp-proxy がこのバイトを見た時刻」が正確。

設計判断 #2: 純粋フォーマッタ + 不純なシンク

hex dump フォーマッタは純粋関数。&[u8] を受けて String を返す:

pub fn format_chunk(bytes: &[u8], limit: usize) -> String {
    let mut out = String::new();
    let shown = if limit == 0 { bytes.len() } else { limit.min(bytes.len()) };
    let head = &bytes[..shown];

    for (line_idx, row) in head.chunks(16).enumerate() {
        let address = line_idx * 16;
        render_line(&mut out, address, row);
        out.push('\n');
    }

    if shown < bytes.len() {
        out.push_str(&format!("... {} more bytes ...\n", bytes.len() - shown));
    }

    out
}

I/O なし、ロックなし、tokio なし。利点は 2 つ:

テスタビリティ — 既知の入力バイト → 既知の出力文字列。hex dump のレイアウトを 1 アサーションでテストできる。

アトミックなログレコード — ヘッダ + hex dump 全体を 1 つの String に組み立ててからシンクに渡す。4 MB チャンクの hex dump が 12 バイトの Redis PING と行単位でインターリーブすることはない。

設計判断 #3: セレモニーなしのグレースフルシャットダウン

Ctrl-C を押したときのルール: 1. 新規接続の受付を即停止 2. 進行中の接続は今の処理を完了させる 3. でも永遠には待たない — docker stop がハングしてはいけない

let shutdown = Arc::new(AtomicBool::new(false));

// シグナルタスク: SIGINT / SIGTERM でフラグを立てる
tokio::spawn(async move {
    let ctrl_c = async { let _ = signal::ctrl_c().await; };
    let term = async {
        if let Ok(mut s) = signal::unix::signal(SignalKind::terminate()) {
            s.recv().await;
        }
    };
    tokio::select! { _ = ctrl_c => {} _ = term => {} }
    shutdown_sig.store(true, Ordering::Relaxed);
});

// ドレインループ: デッドライン内で in-flight の完了を待つ
let deadline = Duration::from_secs(5);
let _ = tokio::time::timeout(deadline, async {
    while in_flight.load(Ordering::Relaxed) > 0 {
        drained.notified().await;
    }
}).await;

AtomicBool + AtomicUsize（in-flight カウンタ）+ Notify。tee ループは各パスで shutdown フラグをチェックし、idle タイムアウトで読み取りがバウンドされるので、無反応な接続もいつかは終了する。

トレードオフ

TLS 終端なし — TLS が掛かっていれば暗号文が見えるだけ。アプリケーション層のデバッグには mitmproxy か SSLKEYLOGFILE
記録/再生なし — ログはテキストの追記のみ。セッションリプレイは別プロジェクト
バイト正確、フレーム非対応 — Redis の RESP フレーミングや Postgres のメッセージエンベロープは知らない。カーネルの read 境界で分割されたフレームは 2 チャンクとして表示される
メモリはチャンクサイズに比例 — 各 tee ループが 8 KiB バッファ。--max-dump でログ出力をバウンドできる

試してみる

git clone https://github.com/sen-ltd/tcp-proxy && cd tcp-proxy
docker build -t tcp-proxy .

# Redis が :6379 で動いているなら:
docker run --rm --network host tcp-proxy \
  --listen 127.0.0.1:6380 --forward 127.0.0.1:6379

# 別シェルで:
redis-cli -p 6380 PING
redis-cli -p 6380 SET hello world
redis-cli -p 6380 GET hello

全バイトが見える。それが全て。

SEN 合同会社の 100 超ポートフォリオシリーズ #167。