フェーズ: 上級者 (Phase 3) | 問題タイプ: 設計・アーキテクチャ | テーマ: ミドルウェア設計パターン
Day 070 の次回予告どおり「設計」。Day 070 で直した積み方(Observe → Recover → Adapt → AnnotateE)は、件数は正しくなった(error 1 件につきログ 1 行、リクエスト 1 件につき集計 1 点)。今日は中身を決める。ログ・メトリクス・トレースの 3 つの出口に、どの部品が・何を・1 回だけ書くか。そして 499(相手が先に切った)と aborted(送信後に切った)を SLO にどう入れるか。
📚 背景知識(読んでから問題へ)
Day 070 の修正版で、まだ困ること
Day 070 の修正版を 8 つの場面に流して、3 つの出口に何が来たかを数えました(2026-10-11 実測。下の「実測 1」に全表)。
| 場面 | エラーログ | panic ログ | 集計 Record |
|---|---|---|---|
| S4 送信前の panic | なし | assignment to entry in nil map | {500 false} |
| S5 送信後の error | 200 user=alice: bad conn | なし | {200 true} |
| S6 送信後の panic | なし | assignment to entry in nil map | {200 true} |
件数はどれも 1 です。でも、問い合わせ対応の担当者がログだけを見ると困ります。
- S4・S6 の panic ログには「誰の」が無い。user を足していたのは AnnotateE で、error にしか効かない
- S5 のエラーログには
200と書いてある。クライアントが壊れた CSV を受け取ったこと(aborted)は、別の出口(Record)にしか無い。Record には user も route も無いので、2 つを突き合わせる鍵が無い - 成功(S1)はログに 1 行も出ない。「alice さんが 10:03 に落としたファイルは正常だったか」に答えられない
情報が 3 つの部品(Adapt・Recover・Observe)に分かれて記録されているのが原因です。各部品は自分の知っていることしか書けません。
世界の実物はどうしているか(一次資料・実測)
| 実物 | 何をどこで記録するか | 確認方法 |
|---|---|---|
otelhttp v0.70.0(go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp、手元のモジュールキャッシュ) | 最外側で span を作り(defer span.End() は handler.go 128 行)、next.ServeHTTP の後にステータスを span に書き(193 行)、メトリクスを記録する(203 行)。この 2 つは defer の中ではない。何も書かれなければ 200 とみなす(internal/request/resp_writer_wrapper.go 40 行 statusCode: http.StatusOK, // default status code in case the Handler doesn't write anything) | ソースを読み、実物を動かして測った(実測 2)。v0.71.0 も同じ行番号・同じ構造 |
OTel の HTTP サーバー span の状態(otelhttp の internal/semconv/server.go 64〜78 行) | 5xx だけ codes.Error。コメントは "Status codes in the 400-499 range are not returned as errors."(サーバーから見て 4xx は自分の失敗ではない) | ソースを読んだ |
| log/slog(Go 1.27.1 標準) | Logger.LogAttrs(ctx, level, msg, attrs...)(log/slog/logger.go 193 行)で属性付きの 1 行を書く | ソースを読み、今日の解答で使った |
| Stripe の "canonical log lines"(1 リクエストにつき、最後に情報をまとめた 1 行を出す) | 最外側で 1 行 | 今回記事を開いていない・記憶のみ |
| Honeycomb などの "wide events" | 同じ考え方(1 リクエスト = 属性の多い 1 イベント) | 記憶のみ |
| Google SRE Workbook の SLI 定義(良いイベント ÷ 有効なイベント) | — | 記憶のみ |
用語(今日の表で使う)
| 用語 | 意味 |
|---|---|
| 出口 | 記録の行き先。ログ(1 件ずつ読む)・メトリクス(数えて集計する。ラベルの種類に上限がある)・トレース(1 リクエストの区間 = span) |
| 袋(Outcome) | 1 リクエストの事実(user・error・panic・スタック)を集める入れ物。今日の案 B で使う |
| class | 結果の分類。ok・client_error(4xx)・client_closed(499)・server_error(5xx)・aborted(送信後に切断)の 5 つ |
| SLI | 可用性の指標 = 良い要求 ÷ 有効な要求 |
📝 問題
状況
CSV エクスポート(/export)に、3 つの要望が来ました。
- 問い合わせ対応:「user と時刻を言われたら、1 行見ればそのリクエストの結末(成功・どの error・どの panic・途中で切れたか)が分かるようにしたい」
- SRE:「可用性 SLO をメトリクスから出したい。相手が先に切った要求(499)と、送信後に切れた要求(aborted)の扱いを決めてほしい」
- 基盤チーム:「来月からトレースは otelhttp(v0.70.0)で取る。今のミドルウェアの外側に
otelhttp.NewHandlerを被せる予定」
場面は次の 8 つです(Day 069・070 で扱ったもの)。
| 場面 | ハンドラがすること | クライアントに届くもの |
|---|---|---|
| S1 成功 | ok を書く | 200 ok |
| S2 404 | ErrNotFound を包んで返す | 404 |
| S3 送信前の error | pq: connection refused を返す | 500 internal error |
| S4 送信前の panic | nil map に代入 | 500 internal error |
| S5 送信後の error | CSV を 1 行送ってから error | 200 で始まり unexpected EOF |
| S6 送信後の panic | CSV を 1 行送ってから panic | 200 で始まり unexpected EOF |
| S7 相手が先に切った | r.Context().Err() を返す | (相手はいない) |
| S8 期限切れ | context.DeadlineExceeded を返す | 503 |
課題
- 表を埋める: 8 場面 × 3 出口(ログ/メトリクス/トレース)について「どの部品が書くか」「level・class・span の状態」を決める
- 記録の位置を 3 案から選ぶ。選ばなかった案の理由と、前提が変わったら判断がどう変わるかも書く
・案 A: 部品ごとに記録(Day 070 の修正版のまま。Adapt が error、Recover が panic、Observe が集計)
・案 B: 最外側の 1 か所(Edge)だけが書く。内側の部品は袋に書き込むだけ
・案 C: 最外側に otelhttp を置き、メトリクスとトレースは otelhttp に任せる。ログは案 A のまま - 499 と aborted を SLI にどう入れるか決める
- 予想してから実測で確かめる(自己評価欄へ)
・P1: 案 C(otelhttp v0.70.0 を最外側)で S5・S6・S7 のメトリクスと span は何になるか
・P2: 案 B で Recover を付け忘れたルートが S4 を起こすと、クライアントとログに何が出るか - 案 B を選んだ場合は
edge.goを実装し、下のedge_test.go(R1〜R8)を通す
準備
mkdir d71 && cd d71 # 作業ディレクトリを作って入る
printf 'module d71\n\ngo 1.22\n' > go.mod # モジュールを作る(標準ライブラリだけ)
# Day 070 の types.go・adapt.go をそのまま置く(Day 069 の模範解答と同じ。変えない)
# 下の recover.go・edge_test.go を保存し、edge.go を書く
go test -race -count=1 -v ./... # R1〜R8 がすべて PASS すれば完成
ファイル: recover.go(Day 070 の修正版から Recover と obsWriter を取り出したもの。変えない)
recover.go(47 行)
package main
import "net/http"
// obsWriter は最初に送った番号だけを覚える(Day 070 と同じ)。
type obsWriter struct {
http.ResponseWriter
status int
}
func (o *obsWriter) WriteHeader(c int) {
if o.status == 0 && c >= 200 {
o.status = c
}
o.ResponseWriter.WriteHeader(c)
}
func (o *obsWriter) Write(b []byte) (int, error) {
if o.status == 0 {
o.status = http.StatusOK
}
return o.ResponseWriter.Write(b)
}
func (o *obsWriter) Unwrap() http.ResponseWriter { return o.ResponseWriter }
// Recover は Day 070 の修正版そのまま。panic を回収して 500、送信後なら切断。
func Recover(logPanic func(*http.Request, any)) func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
cw := &commitWriter{ResponseWriter: w}
defer func() {
p := recover()
if p == nil {
return
}
if p == http.ErrAbortHandler {
panic(p)
}
logPanic(r, p)
if cw.status != 0 {
panic(http.ErrAbortHandler)
}
http.Error(cw, "internal error", http.StatusInternalServerError)
}()
next.ServeHTTP(cw, r)
})
}
}
edge.go に書くもの(型と関数の形)
type Outcome struct { User string; Err error; ErrStatus int; Panic any; Stack []byte }
func ErrInto(r *http.Request, status int, err error) // Adapt に渡す LogFunc
func PanicInto(r *http.Request, p any) // Recover に渡す
func Identify(next http.Handler) http.Handler // 認証の代役。X-User を袋に書く
const ClassOK, ClassClientError, ClassClientClosed, ClassServerError, ClassAborted = "ok", "client_error", "client_closed", "server_error", "aborted"
type Metrics interface { Observe(route, class string, status int, d time.Duration) }
func Edge(log *slog.Logger, m Metrics, routeOf func(*http.Request) string) func(http.Handler) http.Handler
func Stack(h HandlerE, log *slog.Logger, m Metrics, routeOf func(*http.Request) string) http.Handler
func SLI(n map[string]int) float64
ファイル: edge_test.go(変えない。R1〜R8 とベンチマーク)
edge_test.go(321 行)
package main
import (
"bytes"
"context"
"encoding/json"
"errors"
"fmt"
"io"
"log"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"sync"
"testing"
"time"
)
// ---- 出口の受け皿(実サーバーのハンドラ goroutine から呼ばれるので Mutex) ----
type lockedBuf struct {
mu sync.Mutex
b bytes.Buffer
}
func (l *lockedBuf) Write(p []byte) (int, error) { l.mu.Lock(); defer l.mu.Unlock(); return l.b.Write(p) }
func (l *lockedBuf) lines(t *testing.T) []map[string]any {
l.mu.Lock()
defer l.mu.Unlock()
var out []map[string]any
for _, s := range strings.Split(strings.TrimSpace(l.b.String()), "\n") {
if s == "" {
continue
}
var m map[string]any
if err := json.Unmarshal([]byte(s), &m); err != nil {
t.Fatalf("JSON でない行: %q", s)
}
out = append(out, m)
}
return out
}
type obs struct {
Route, Class string
Status int
}
type fakeMetrics struct {
mu sync.Mutex
got []obs
}
func (f *fakeMetrics) Observe(route, class string, status int, d time.Duration) {
f.mu.Lock()
defer f.mu.Unlock()
f.got = append(f.got, obs{route, class, status})
}
func (f *fakeMetrics) snap() []obs { f.mu.Lock(); defer f.mu.Unlock(); return append([]obs(nil), f.got...) }
func route(*http.Request) string { return "GET /export" }
// ---- 8 つの場面 ----
func explodeBeforeCommit(w http.ResponseWriter, r *http.Request) error {
var m map[string]int
m["x"]++ // panic: assignment to entry in nil map
return nil
}
func explodeAfterCommit(w http.ResponseWriter, r *http.Request) error {
io.WriteString(w, "id,name\n1,alice\n")
http.NewResponseController(w).Flush()
var m map[string]int
m["x"]++
return nil
}
func streamThenFail(w http.ResponseWriter, r *http.Request) error {
io.WriteString(w, "id,name\n1,alice\n")
http.NewResponseController(w).Flush()
return errors.New("rows.Next: driver: bad connection")
}
type scenario struct {
name string
h HandlerE
clientGone bool // 実サーバーでなく、切れた ctx で直接呼ぶ
class string // メトリクスとログの class
status int // ログとメトリクスの status
level string // ログの level
errSub string // err 属性に含まれるべき文字列("" なら err 属性なし)
panicFn string // stack に含まれるべき関数名("" なら panic 属性なし)
client string // クライアントが見るもの: "200 ok" / "500" / "EOF" / "-"
}
var scenarios = []scenario{
{"S1 成功", func(w http.ResponseWriter, r *http.Request) error { io.WriteString(w, "ok"); return nil },
false, ClassOK, 200, "INFO", "", "", "200"},
{"S2 404", func(w http.ResponseWriter, r *http.Request) error { return fmt.Errorf("repo.Get(42): %w", ErrNotFound) },
false, ClassClientError, 404, "INFO", "repo.Get(42)", "", "404"},
{"S3 送信前の error", func(w http.ResponseWriter, r *http.Request) error { return errors.New("pq: connection refused") },
false, ClassServerError, 500, "ERROR", "connection refused", "", "500"},
{"S4 送信前の panic", explodeBeforeCommit, false, ClassServerError, 500, "ERROR", "", "explodeBeforeCommit", "500"},
{"S5 送信後の error", streamThenFail, false, ClassAborted, 200, "ERROR", "bad connection", "", "EOF"},
{"S6 送信後の panic", explodeAfterCommit, false, ClassAborted, 200, "ERROR", "", "explodeAfterCommit", "EOF"},
{"S7 相手が先に切った", func(w http.ResponseWriter, r *http.Request) error { return fmt.Errorf("query: %w", r.Context().Err()) },
true, ClassClientClosed, 499, "INFO", "context canceled", "", "-"},
{"S8 期限切れ", func(w http.ResponseWriter, r *http.Request) error { return fmt.Errorf("query: %w", context.DeadlineExceeded) },
false, ClassServerError, 503, "ERROR", "deadline exceeded", "", "503"},
}
type result struct {
code int
body string
readErr error
lines []map[string]any
obs []obs
}
func run(t *testing.T, sc scenario) result {
t.Helper()
buf, m := &lockedBuf{}, &fakeMetrics{}
h := Stack(sc.h, slog.New(slog.NewJSONHandler(buf, nil)), m, route)
var res result
if sc.clientGone {
ctx, cancel := context.WithCancel(context.Background())
cancel()
r := httptest.NewRequest("GET", "/export", nil).WithContext(ctx)
r.Header.Set("X-User", "alice")
h.ServeHTTP(httptest.NewRecorder(), r)
} else {
srv := httptest.NewServer(h)
req, _ := http.NewRequest("GET", srv.URL+"/export", nil)
req.Header.Set("X-User", "alice")
resp, err := http.DefaultClient.Do(req)
if err != nil {
res.readErr = err
} else {
b, err := io.ReadAll(resp.Body)
resp.Body.Close()
res.code, res.body, res.readErr = resp.StatusCode, string(b), err
}
srv.Close() // ハンドラの終了を待つ
}
res.lines, res.obs = buf.lines(t), m.snap()
return res
}
// R1: どの場面でもメトリクスは 1 点。class と status は表のとおり。
func TestR1_OneMetricPerRequest(t *testing.T) {
for _, sc := range scenarios {
r := run(t, sc)
want := obs{"GET /export", sc.class, sc.status}
if len(r.obs) != 1 || r.obs[0] != want {
t.Errorf("%s: metrics=%v; want [%v]", sc.name, r.obs, want)
}
}
}
// R2: どの場面でもログは 1 行。level は 5xx と aborted だけ ERROR。
func TestR2_OneLogLinePerRequest(t *testing.T) {
for _, sc := range scenarios {
r := run(t, sc)
if len(r.lines) != 1 {
t.Errorf("%s: ログ %d 行; want 1", sc.name, len(r.lines))
continue
}
l := r.lines[0]
if l["level"] != sc.level || l["class"] != sc.class || l["status"] != float64(sc.status) {
t.Errorf("%s: level=%v class=%v status=%v; want %s %s %d", sc.name, l["level"], l["class"], l["status"], sc.level, sc.class, sc.status)
}
}
}
// R3: その 1 行に、誰の・何の error・どこの panic かがそろっている。無いものは出さない。
func TestR3_LineHasAllFacts(t *testing.T) {
for _, sc := range scenarios {
r := run(t, sc)
if len(r.lines) != 1 {
t.Errorf("%s: ログ %d 行", sc.name, len(r.lines))
continue
}
l := r.lines[0]
if l["user"] != "alice" {
t.Errorf("%s: user=%v", sc.name, l["user"])
}
e, hasErr := l["err"].(string)
if (sc.errSub != "") != hasErr || !strings.Contains(e, sc.errSub) {
t.Errorf("%s: err=%q; want 含む %q", sc.name, e, sc.errSub)
}
st, hasStack := l["stack"].(string)
if (sc.panicFn != "") != hasStack || !strings.Contains(st, sc.panicFn) {
t.Errorf("%s: stack に %q が無い(stack あり=%v)", sc.name, sc.panicFn, hasStack)
}
if strings.Contains(st, "net/http: abort Handler") || l["panic"] == "net/http: abort Handler" {
t.Errorf("%s: 意図した切断を panic として出した", sc.name)
}
}
}
// R4: メトリクスのラベルは有限。user や error の文言が入らない(系列が爆発しない)。
func TestR4_MetricLabelsBounded(t *testing.T) {
allowed := map[string]bool{ClassOK: true, ClassClientError: true, ClassClientClosed: true, ClassServerError: true, ClassAborted: true}
for _, sc := range scenarios {
for _, o := range run(t, sc).obs {
if !allowed[o.Class] || o.Route != "GET /export" {
t.Errorf("%s: labels=%v", sc.name, o)
}
}
}
}
// R5: クライアントに届くもの。送信後の失敗は完全な 200 にしない。
func TestR5_ClientView(t *testing.T) {
for _, sc := range scenarios {
if sc.clientGone {
continue
}
r := run(t, sc)
switch sc.client {
case "EOF":
if !errors.Is(r.readErr, io.ErrUnexpectedEOF) {
t.Errorf("%s: readErr=%v body=%q; want unexpected EOF", sc.name, r.readErr, r.body)
}
default:
if r.readErr != nil || fmt.Sprint(r.code) != sc.client {
t.Errorf("%s: %d %v; want %s", sc.name, r.code, r.readErr, sc.client)
}
if r.code >= 500 && r.body != "internal error\n" {
t.Errorf("%s: 5xx の本文 %q(中身を漏らしていないか)", sc.name, r.body)
}
}
}
}
// R6: SLI。499 は分母から外す。aborted は失敗。4xx は成功。
func TestR6_SLI(t *testing.T) {
n := map[string]int{ClassOK: 900, ClassClientError: 40, ClassClientClosed: 30, ClassAborted: 20, ClassServerError: 10}
if got, want := SLI(n), 940.0/970.0; got != want {
t.Fatalf("SLI=%v; want %v", got, want)
}
if SLI(map[string]int{ClassClientClosed: 5}) != 1 {
t.Fatal("有効な要求が 0 件なら 1(違反なし)")
}
}
// R7: 200 本同時。袋がリクエストごとに分かれている(user と err が混ざらない。-race で)。
func TestR7_Concurrent(t *testing.T) {
buf, m := &lockedBuf{}, &fakeMetrics{}
h := Stack(func(w http.ResponseWriter, r *http.Request) error {
if u := r.Header.Get("X-User"); u[len(u)-1]%2 == 0 {
return fmt.Errorf("fail for %s", u)
}
io.WriteString(w, "ok")
return nil
}, slog.New(slog.NewJSONHandler(buf, nil)), m, route)
var wg sync.WaitGroup
for i := 0; i < 200; i++ {
wg.Add(1)
go func(i int) {
defer wg.Done()
r := httptest.NewRequest("GET", "/export", nil)
r.Header.Set("X-User", fmt.Sprintf("u%03d", i))
h.ServeHTTP(httptest.NewRecorder(), r)
}(i)
}
wg.Wait()
lines := buf.lines(t)
if len(lines) != 200 || len(m.snap()) != 200 {
t.Fatalf("lines=%d metrics=%d; want 200 200", len(lines), len(m.snap()))
}
for _, l := range lines {
u, _ := l["user"].(string)
e, hasErr := l["err"].(string)
if hasErr != (u[len(u)-1]%2 == 0) || (hasErr && e != "fail for "+u) {
t.Fatalf("混ざった: user=%s err=%q", u, e)
}
}
}
// R8: Recover を付け忘れたルートでも、panic の場所は Edge の 1 行に残る(net/http も別にスタックを出す)。
func TestR8_NoRecoverStillOneLine(t *testing.T) {
buf, m, srvLog := &lockedBuf{}, &fakeMetrics{}, &lockedBuf{}
h := Edge(slog.New(slog.NewJSONHandler(buf, nil)), m, route)(Identify(Adapt(explodeBeforeCommit, ErrInto)))
srv := httptest.NewUnstartedServer(h)
srv.Config.ErrorLog = log.New(srvLog, "", 0)
srv.Start()
_, err := http.Get(srv.URL)
srv.Close()
lines := buf.lines(t)
t.Logf("R8: client err=%v / net/http のログ %d バイト", err, len(srvLog.b.String()))
if err == nil || len(lines) != 1 || lines[0]["class"] != ClassAborted ||
!strings.Contains(fmt.Sprint(lines[0]["stack"]), "explodeBeforeCommit") {
t.Fatalf("err=%v lines=%v", err, lines)
}
}
func BenchmarkEdgeStackOK(b *testing.B) {
h := Stack(func(w http.ResponseWriter, r *http.Request) error { io.WriteString(w, "ok"); return nil },
slog.New(slog.NewJSONHandler(io.Discard, nil)), &nopMetrics{}, route)
r := httptest.NewRequest("GET", "/export", nil)
b.ReportAllocs()
for i := 0; i < b.N; i++ {
h.ServeHTTP(httptest.NewRecorder(), r)
}
}
func BenchmarkEdgeStackNotFound(b *testing.B) {
h := Stack(func(w http.ResponseWriter, r *http.Request) error { return ErrNotFound },
slog.New(slog.NewJSONHandler(io.Discard, nil)), &nopMetrics{}, route)
r := httptest.NewRequest("GET", "/export", nil)
b.ReportAllocs()
for i := 0; i < b.N; i++ {
h.ServeHTTP(httptest.NewRecorder(), r)
}
}
type nopMetrics struct{}
func (*nopMetrics) Observe(string, string, int, time.Duration) {}
💡 ヒント
ヒント1(方向性)
「1 行で結末が分かる」ためには、その行を書く部品がすべての事実を知っている必要があります。8 場面すべてで最後に通るのはどの部品でしょうか。panic が通り抜ける場面(S5・S6)でも動く書き方は何でしょうか。
ヒント2(アプローチ)
- 内側の部品(Adapt・Recover)は「記録する関数」を引数で受け取っています(
LogFunc・logPanic)。この関数を記録しないで袋に書く関数に差し替えれば、Adapt・Recover は 1 行も変えずに済む - 袋は Edge がリクエストごとに作り、
context.WithValueで内側に渡す。内側はr.Context().Value(key)で取り出す - panic のスタックは、Recover の
deferの中(PanicIntoが呼ばれる時点)でしか panic の場所を含まない。Edge まで来た時点では、Recover が投げ直したhttp.ErrAbortHandlerのスタックしか無い - Edge は Day 070 の Observe と同じく
deferでrecover()して数え、必ず投げ直す - メトリクスのラベルに user や error の文言を入れると、系列の数が利用者数・文言の種類だけ増える。ラベルは route と class だけにする
- 予想 P1 のために、otelhttp の
handler.go185〜203 行がdeferの中かどうかを見る
ヒント3(コード骨格)
func Edge(log *slog.Logger, m Metrics, routeOf func(*http.Request) string) func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start, o, ow := time.Now(), &Outcome{}, &obsWriter{ResponseWriter: w}
r = r.WithContext(context.WithValue(r.Context(), outcomeKey{}, o))
defer func() {
p := recover()
// status: ow.status。0 なら 200、ただし r.Context().Err() != nil なら 499
// class: p != nil → aborted / 499 → client_closed / 5xx / 4xx / ok
// m.Observe(...) を 1 回、log.LogAttrs(...) を 1 回(5xx と aborted は ERROR)
// p != nil → panic(p)
}()
next.ServeHTTP(ow, r)
})
}
}
// Stack: Edge(...)(Identify(Recover(PanicInto)(Adapt(h, ErrInto))))
✅ 模範解答
1. 誰が何を 1 回だけ書くか(案 B を採用)
| 場面 | クライアント | ログ(Edge が 1 行) | メトリクス(Edge が 1 点、ラベル = route・class) | トレース(otelhttp の span) | SLI |
|---|---|---|---|---|---|
| S1 成功 | 200 | INFO class=ok | ok | Unset | 良い |
| S2 404 | 404 | INFO class=client_error err=repo.Get(42): not found | client_error | Unset(4xx はサーバーの失敗ではない) | 良い |
| S3 送信前の error | 500 | ERROR class=server_error err=pq: connection refused | server_error | Error | 悪い |
| S4 送信前の panic | 500 | ERROR class=server_error panic=… stack=… | server_error | Error | 悪い |
| S5 送信後の error | 200→EOF | ERROR class=aborted status=200 err=…bad connection | aborted | Error(Edge の内側で付ける。otelhttp だけだと Unset) | 悪い |
| S6 送信後の panic | 200→EOF | ERROR class=aborted panic=… stack=… | aborted | Error(同上) | 悪い |
| S7 相手が先に切った | — | INFO class=client_closed status=499 err=…context canceled | client_closed | Unset(otelhttp は 200 と書く。今日は直していない) | 数えない(分母から外す) |
| S8 期限切れ | 503 | ERROR class=server_error err=…deadline exceeded | server_error | Error | 悪い |
- 書く部品はどの出口も Edge の 1 か所。Adapt・Recover・Identify は袋に書くだけで、何も出力しない
- メトリクスは otelhttp に任せない。otelhttp v0.70.0 は S5・S6 でメトリクスを 1 点も記録しない(実測 2)。可用性の分子・分母から「壊れた CSV を受け取った人」が消える
- トレースは otelhttp に任せるが、aborted の span 状態だけは Edge の内側で
codes.Errorを付ける(実測 2 で効くことを確認。今日のedge.goは標準ライブラリだけなので、この部分は実測用のコードにだけ入れた) - 499 は分母から外す。ただし件数は
client_closedとして残るので、急増は別のアラートで見る(下の「迷った他案」)
2. edge.go(143 行)
package main
import (
"context"
"log/slog"
"net/http"
"runtime/debug"
"time"
)
// Outcome は 1 リクエストの「事実」を集める袋。中の部品は書き込むだけで、出力しない。
// 出力(ログ 1 行・メトリクス 1 点・span の状態)は Edge の defer が 1 回だけ行う。
// ハンドラが goroutine を起こして袋に書く場合は想定しない(書くのはリクエストの goroutine だけ)。
type Outcome struct {
User string
Err error // Adapt が受け取った error(1 件。後勝ちにしない)
ErrStatus int // その error に Adapt が付けた番号
Panic any // Recover が回収した panic の値
Stack []byte
}
type outcomeKey struct{}
func outcomeOf(r *http.Request) *Outcome {
o, _ := r.Context().Value(outcomeKey{}).(*Outcome)
return o
}
// ErrInto は Adapt に渡す LogFunc。記録せずに袋に書く。
func ErrInto(r *http.Request, status int, err error) {
if o := outcomeOf(r); o != nil && o.Err == nil {
o.Err, o.ErrStatus = err, status
}
}
// PanicInto は Recover に渡す。panic の場所はこの時点のスタックにしか無いので、ここで取る。
func PanicInto(r *http.Request, p any) {
if o := outcomeOf(r); o != nil && o.Panic == nil {
o.Panic, o.Stack = p, debug.Stack()
}
}
// Identify は認証の代役。誰のリクエストかを袋に書く(エラーの文言には足さない)。
func Identify(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if o := outcomeOf(r); o != nil {
o.User = r.Header.Get("X-User")
}
next.ServeHTTP(w, r)
})
}
// Class はメトリクスのラベルと SLI に使う結果の分類。値は 5 つに固定(ラベルの種類を増やさない)。
const (
ClassOK = "ok"
ClassClientError = "client_error" // 4xx(499 を除く)
ClassClientClosed = "client_closed" // 499。相手が先に切った
ClassServerError = "server_error" // 5xx
ClassAborted = "aborted" // 送信後に切断。相手は壊れた応答を受け取った
)
func classOf(status int, aborted bool) string {
switch {
case aborted:
return ClassAborted
case status == StatusClientClosed:
return ClassClientClosed
case status >= 500:
return ClassServerError
case status >= 400:
return ClassClientError
}
return ClassOK
}
// Metrics は 1 リクエストにつき 1 回呼ばれる。ラベルは route と class だけ(user・error 文言は入れない)。
type Metrics interface {
Observe(route, class string, status int, d time.Duration)
}
// Edge は最も外側に 1 つだけ置く。袋を作り、defer で 3 つの出口に 1 回ずつ書き、panic は投げ直す。
func Edge(log *slog.Logger, m Metrics, routeOf func(*http.Request) string) func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
o := &Outcome{}
ow := &obsWriter{ResponseWriter: w}
r = r.WithContext(context.WithValue(r.Context(), outcomeKey{}, o))
defer func() {
p := recover() // 通り抜ける panic は切断。数えてから必ず投げ直す
status, aborted := ow.status, p != nil
if aborted && p != http.ErrAbortHandler && o.Panic == nil {
o.Panic, o.Stack = p, debug.Stack() // Recover を通らなかった panic(Recover の付け忘れ)
}
if status == 0 {
status = http.StatusOK // 何も書かなければ net/http が 200 を送る
if r.Context().Err() != nil {
status = StatusClientClosed // ……ただし相手がもういないなら何も送っていない
}
}
class := classOf(status, aborted)
d := time.Since(start)
route := routeOf(r)
m.Observe(route, class, status, d)
level := slog.LevelInfo
if class == ClassServerError || class == ClassAborted {
level = slog.LevelError
}
attrs := make([]slog.Attr, 0, 9)
attrs = append(attrs,
slog.String("method", r.Method), slog.String("route", route),
slog.Int("status", status), slog.String("class", class),
slog.Int64("dur_us", d.Microseconds()), slog.String("user", o.User))
if o.Err != nil {
attrs = append(attrs, slog.String("err", o.Err.Error()))
}
if o.Panic != nil {
attrs = append(attrs, slog.Any("panic", o.Panic), slog.String("stack", string(o.Stack)))
}
log.LogAttrs(r.Context(), level, "request", attrs...)
if p != nil {
panic(p)
}
}()
next.ServeHTTP(ow, r)
})
}
}
// Stack は Day 070 の積み方から Observe を Edge に、AnnotateE を Identify に替えたもの。
func Stack(h HandlerE, log *slog.Logger, m Metrics, routeOf func(*http.Request) string) http.Handler {
return Edge(log, m, routeOf)(Identify(Recover(PanicInto)(Adapt(h, ErrInto))))
}
// SLI は可用性。499 は分母から外し(相手の都合)、aborted と 5xx は失敗、4xx は成功(サーバーは正しく断った)。
func SLI(n map[string]int) float64 {
valid := n[ClassOK] + n[ClassClientError] + n[ClassServerError] + n[ClassAborted]
if valid == 0 {
return 1
}
return float64(n[ClassOK]+n[ClassClientError]) / float64(valid)
}
3. 実行結果(Go 1.27.1、2026-10-11、M1 MacBook Pro 8GB)
$ go test -race -count=1 -v ./... 2>&1 | grep -E '^(---|ok)|R8:'
--- PASS: TestR1_OneMetricPerRequest (0.03s)
--- PASS: TestR2_OneLogLinePerRequest (0.02s)
--- PASS: TestR3_LineHasAllFacts (0.01s)
--- PASS: TestR4_MetricLabelsBounded (0.01s)
--- PASS: TestR5_ClientView (0.02s)
--- PASS: TestR6_SLI (0.00s)
--- PASS: TestR7_Concurrent (0.03s)
edge_test.go:292: R8: client err=Get "http://127.0.0.1:59025": EOF / net/http のログ 2283 バイト
--- PASS: TestR8_NoRecoverStillOneLine (0.00s)
ok d71 2.017s
各場面で Edge が出した 1 行(time を除き、stack は長さに置き換えた):
S1 {"class":"ok","dur_us":7,"level":"INFO","method":"GET","msg":"request","route":"GET /export","status":200,"user":"alice"}
S2 {"class":"client_error","dur_us":58,"err":"repo.Get(42): not found","level":"INFO",…,"status":404,"user":"alice"}
S3 {"class":"server_error","dur_us":28,"err":"pq: connection refused","level":"ERROR",…,"status":500,"user":"alice"}
S4 {"class":"server_error","dur_us":291,"level":"ERROR",…,"panic":"assignment to entry in nil map",…,"stack":2678,"status":500,"user":"alice"}
S5 {"class":"aborted","dur_us":113,"err":"rows.Next: driver: bad connection","level":"ERROR",…,"status":200,"user":"alice"}
S6 {"class":"aborted","dur_us":172,"level":"ERROR",…,"panic":"assignment to entry in nil map",…,"stack":2685,"status":200,"user":"alice"}
S7 {"class":"client_closed","dur_us":5,"err":"query: context canceled","level":"INFO",…,"status":499,"user":"alice"}
S8 {"class":"server_error","dur_us":12,"err":"query: context deadline exceeded","level":"ERROR",…,"status":503,"user":"alice"}
🪜 Step-by-Step 解説
Step 1: 出口ごとに「何を知っている必要があるか」を並べる
| 事実 | 知っている部品 | いつ分かるか |
|---|---|---|
| user | Identify(認証) | 最初 |
| error の中身 | Adapt | ハンドラが戻った後 |
| panic の値と場所(スタック) | Recover | panic の直後(Recover の defer の中だけ) |
| 送ったステータス | 応答を包んだ writer | 最初の WriteHeader/Write |
| 接続を切ったか(aborted) | Recover より外側で panic を見た部品 | 最後 |
| 相手が先に切ったか(499) | ctx を見た部品 | 最後 |
「1 行ですべて」を書けるのは、最後に事実がそろう場所=最外側の defer だけです。案 A はこれを 3 か所に分けて書いていたので、どの 1 行にも全部はそろいませんでした。
Step 2: 内側は「書く」を「袋に入れる」に差し替える
Day 069 の Adapt(h, log LogFunc) と Day 070 の Recover(logPanic) は、記録の関数を引数で受け取っていました。ここに ErrInto・PanicInto を渡すだけで、Adapt・Recover のコードは 1 行も変えずに案 B に移れます。小さい関数を引数で渡す形にしておいたことが、ここで効きます。
PanicInto で debug.Stack() を取るのが要点です。Recover の defer の中ではまだスタックが巻き戻っていないので、panic した関数(explodeBeforeCommit)が載ります(R3 で確認)。Edge まで来た時点のスタックには、Recover が投げ直した場所しかありません。
Step 3: Edge の defer で 3 つを 1 回ずつ書き、投げ直す
Day 070 の Observe と同じ骨格です。違いは、Record を返す代わりに、袋と自分の観察を合わせてログ 1 行・メトリクス 1 点を書くことです。数えた後の panic(p) を忘れると(変異 M1)、Edge が切断を飲み込み、S5・S6 のクライアントが完全な 200 を受け取ります(R5 が落ちる)。
Step 4: ラベルとログ属性を分ける
メトリクスのラベルは route と class の 2 つだけにしました。class は 5 値に固定です。user や error の文言はログの属性にだけ入れます。ラベルに user を入れると(変異 M10)、系列の数が利用者の数だけ増えます。ログは 1 行ずつ読むものなので、属性がいくつあっても系列は増えません。
Step 5: SLI を決める
- aborted は失敗: クライアントは壊れた CSV を受け取った。ステータスは 200 でも良い要求ではない
- 4xx は成功: サーバーは正しく断った(OTel の span 状態の規則と同じ考え方)
- 499 は分母から外す: 相手の都合で終わった要求は、サーバーの良し悪しを語らない。件数は
client_closedとして残し、急増は別に見る
📏 実測(予想と外れた所を含む)
1. 案 A(Day 070 修正版)と案 B の出口の中身(8 場面、2026-10-11)
| 場面 | 案 A: エラーログ | 案 A: panic ログ | 案 A: Record | 案 B: Edge の 1 行 |
|---|---|---|---|---|
| S1 | — | — | {200 false} | INFO ok(user あり) |
| S2 | 404 user=alice: repo: not found | — | {404 false} | INFO client_error |
| S3 | 500 user=alice: pq: refused | — | {500 false} | ERROR server_error |
| S4 | — | assignment to entry in nil map(user なし・status なし) | {500 false} | ERROR server_error+panic+stack |
| S5 | 200 user=alice: bad conn(切れたことが書いていない) | — | {200 true} | ERROR aborted+err |
| S6 | — | assignment to entry in nil map(user なし) | {200 true} | ERROR aborted+panic+stack |
| S7 | 499 user=alice: context canceled | — | {499 false} | INFO client_closed |
| S8 | 503 user=alice: context deadline exceeded | — | {503 false} | ERROR server_error |
- 案 A も件数は全場面で 1(Day 070 で直した)。困るのは中身が分かれていること
- 案 A の Record には user も route も無く、ログと突き合わせる鍵が無い(リクエスト ID を足せば突き合わせられるが、読む側が 2 か所を引くことになる)
2. otelhttp v0.70.0 を最外側に置く(案 C。予想 P1 の答え合わせ)
手元のモジュールキャッシュ(otel v1.45.0・sdk v1.45.0・GOPROXY=off)で、otelhttp.NewHandler の内側に Day 070 風の Recover → Adapt を置き、tracetest.SpanRecorder と sdkmetric.ManualReader で span と http.server.request.duration を読んだ。
| 場面 | span の状態 | span の http.response.status_code | メトリクスの点 |
|---|---|---|---|
| S1 | Unset | 200 | 1(200) |
| S2 | Unset | 404 | 1(404) |
| S3 | Error | 500 | 1(500) |
| S4 | Error | 500 | 1(500) |
| S5 | Unset | なし | 0 |
| S6 | Unset | なし | 0 |
| S7 | Unset | 200 | 1(200) |
| S8 | Error | 503 | 1(503) |
- S5・S6 はメトリクスから消える。otelhttp は
next.ServeHTTPの後でメトリクスを書く(handler.go185〜203 行、defer ではない)。panic(http.ErrAbortHandler) が通り抜けると、その行に届かない。span はdefer span.End()(128 行)で閉じられるが、状態を書く 193 行にも届かないので Unset のまま - S7 は 200 として数えられる。何も書かれないと 200 とみなす(
resp_writer_wrapper.go40 行)。Day 070 の B3 と同じ形 - 予想と外れた所: span は S5・S6 で「閉じられない(記録されない)」と予想していた。実際は
defer span.End()があるので span は出る。出るが、状態もステータスも無い span になる。トレースの画面では成功に見える
Edge の内側に「panic を見たら span に Error を付けて投げ直す」小さな中間件を足した版(同じ条件で実測):
| 場面 | span の状態 | メトリクスの点(otelhttp) |
|---|---|---|
| S5 | Error | 0(変わらない) |
| S6 | Error | 0(変わらない) |
| その他 | 上の表と同じ | 上の表と同じ |
- span の状態は内側から直せる(
trace.SpanFromContext(r.Context()).SetStatus(codes.Error, "aborted"))。しかし otelhttp のメトリクスは、otelhttp 自身の処理に届かない限り直らない - だから「メトリクスは Edge が書く、otelhttp はトレースだけ」に決めた(
otelhttp.WithMeterProviderに何もしない MeterProvider を渡す想定。今日は実測していない)
3. 予想 P2 の答え合わせ(R8: Recover を付け忘れたルートで S4)
- クライアント: 500 ではなく
Get "http://127.0.0.1:…": EOF(応答が 1 バイトも届かない)。Edge が数えた後に投げ直した panic を net/http が受け、接続を切る - ログ: Edge の 1 行(
class=aborted、stackにexplodeBeforeCommitあり)と、net/http 自身のスタック出力 2,283 バイト(srv.Config.ErrorLogに出る)。記録が 2 か所になる - Edge の 1 行は
status=200と書く(何も送っていないのに、0 を 200 に直す規則が効く)。Recover を付ける前提の設計なので今日は直していない(扱わなかった範囲)
4. スタブと変異(-race 付き)
Edge を素通し・ErrInto/PanicInto/Identify を何もしない・SLI を 0 にしたスタブでは R1 R2 R3 R6 R7 R8 の 6 本が落ちる。R4(ラベルの上限)は点が 0 個なので素通り、R5(クライアントに届くもの)は Recover と Adapt が既に正しいので素通り。
| 変異 | 検出したテスト |
|---|---|
| M1 Edge が投げ直さない | R5 |
| M2 Edge が recover しない | R1, R2 |
| M3 Edge の 499 判定を消す | R1, R2 |
| M4 ErrInto を後勝ちにする | 生存 |
| M5 PanicInto がスタックを取らない | R3 |
| M6 aborted を INFO にする | R2 |
| M7 499 を client_error に入れる | R1, R2 |
| M8 袋を合成時に 1 個だけ作る | R7(-race) |
| M9 Identify が袋に書かない | R3, R7 |
| M10 route ラベルに user を足す | R1, R4 |
| M11 Recover を Edge の外に出す | R1, R2 |
| M12 SLI の分母に 499 を入れる | R6 |
| M13 ErrInto が何もしない | R3, R7 |
| M14 Edge が Recover なしの panic を記録しない | R8(最初の R1〜R7 では生存。R8 を足して検出) |
- M4 は生存: Adapt は 1 リクエストにつき
LogFuncを 1 回しか呼ばないので、先勝ちと後勝ちの差が出る場面が今日のテストに無い。中間件を足して 2 回目の書き込みが起きる構成になったら効く - M11(Recover を Edge の外に): Recover が袋を見つけられず(袋は Edge が作る ctx の中)、Edge は生の panic を見て
abortedと数えるのに、クライアントには Recover の 500 が届く。数えた結果と線の上の結果が食い違う。積む順は Day 065 の「Observe > Recover」と同じ結論
5. 可用性の数字は定義でどれだけ動くか(配分は仮定、計算は導出)
1000 リクエスト。配分は仮定(ok 900・404 が 40・499 が 30・aborted 20・5xx 10)。
| 数え方 | 良い | 有効 | 可用性 |
|---|---|---|---|
| 案 B(今日の決定): 499 を外す・aborted は失敗 | 940 | 970 | 96.91% |
| 499 も失敗に数える | 940 | 1000 | 94.00% |
| 案 C(otelhttp のメトリクス): aborted が消え、499 は 200 | 970 | 980 | 98.98% |
| Day 070 のバグ入り(参考) | 990 | 1000 | 99.00% |
- 案 C は「壊れた CSV を受け取った 20 人」を分子からも分母からも消し、「相手が切った 30 件」を成功に足す。2 ポイント高く出る
- 99.5% の SLO なら、案 B では違反、案 C では違反に見えない
6. 費用(割り当ては決定的、時間は参考)
B/op allocs/op
BenchmarkDay070StackOK 1088 13 (案 A。成功時はログを書かない)
BenchmarkEdgeStackOK 1585 17 (案 B。成功時も JSON 1 行を io.Discard へ)
BenchmarkEdgeStackNotFound 1673 20
- 成功 1 件あたり +497 B・+4 allocs(袋・ctx の複製・リクエストの複製・slog の 1 行)
- 時間は案 A 1,665〜1,811 ns、案 B 3,655〜3,952 ns だったが、計測中のロードアベレージが 19 台(M1 8GB で他の処理が並走)なので比較に使わない
- ログの量(導出): 成功の 1 行は 165 バイト(実測)、panic の行はスタック込みで約 2,950 バイト(実測)。1,000 rps(仮定)なら成功だけで 165 × 1,000 × 86,400 ≈ 14.3 GB/日。案 A は成功で 0 バイト
⚖️ 迷った他案と採らなかった理由
| 論点 | 採った案 | 迷った他案と採らなかった理由 | 前提が変わったら |
|---|---|---|---|
| 記録の位置 | 案 B: 最外側の Edge が 3 出口に 1 回ずつ | 案 A(部品ごと): 件数は正しいが、1 行に事実がそろわない(実測 1)。案 C(otelhttp に任せる): aborted がメトリクスから消え、499 が 200 になる(実測 2)。可用性が 2 ポイント高く出る(実測 5) | otelhttp が将来 defer でメトリクスを書くようになれば、メトリクスだけ案 C に戻せる(そのときは実測 2 を再実行して確かめる) |
| 袋の渡し方 | context.WithValue で *Outcome を渡す | ResponseWriter に袋を持たせる(w.(interface{ Outcome() *Outcome })): ctx の複製は要らないが、途中の中間件が w を包むと見えなくなる(Day 060 の包み方の問題)。引数で渡す: Adapt・Recover の型を変える必要がある | 袋に書く部品が Adapt と Recover の 2 つから増えないなら、引数で渡す方が型で守れる |
| 成功もログに出すか | 出す(INFO で 1 行) | 失敗だけ出す(案 A と同じ量): 「その人のリクエストは正常だったか」に答えられない | ログ量が予算を超えたら、class=ok だけ 1/100 に間引く。数えるのはメトリクスなので、間引いても SLI は変わらない |
| メトリクスのラベル | route と class(5 値) | status(数値)をラベルに: 種類が数十に増え、499 と 200 の区別は status だけでは aborted を表せない。error の種類をラベルに: 文言が増えると系列が爆発する | エラーの種類別に見たいなら、OTel の error.type のように固定の小さな集合に写してからラベルにする |
| 499 の扱い | 分母から外す。件数は client_closed で残す | 失敗に数える: モバイルの切断が多い日に SLO が落ちる。時間で分ける(2 秒以上待たせてから切られたら失敗): 遅さが原因の切断を拾えるが、閾値の根拠が今は無い | 遅延の SLO(p99)を別に持たないなら、「長く待たせてから切られた 499」は失敗に数える案に寄せる |
| span の状態 | 5xx と aborted は Error、4xx と 499 は Unset | 4xx も Error: OTel の規則(server.go 68 行のコメント)と違い、トレースの画面がクライアントの誤りで赤くなる | — |
| 袋への同時書き込み | 想定しない(Mutex なし) | Mutex を付ける: ハンドラが goroutine を起こして袋に書くなら要る。今日の部品は書かない | ハンドラ内の goroutine が error を報告する設計(errgroup など)を入れたら、袋に Mutex を足し R7 に同時書き込みを足す |
🧭 設計思想・なぜこう書くのか
- 「error は 1 回だけ扱う」を出口全体に広げた: Day 070 では「記録するか返すか、どちらか 1 つ」でした。今日はそれを「事実は内側で集め、出力は外側の 1 か所」に広げました。内側の部品は出力の形式(slog か、OTel か)を知らずに済みます
- 小さい関数を引数で受け取る形が、移行を安くする: Adapt・Recover は
LogFunc・logPanicを受け取る形だったので、渡す関数を差し替えるだけで案 A から案 B に移れました。Go の「インターフェースではなく関数 1 つ」で十分な場面です - ctx はリクエストの範囲の値を運ぶ場所:
context.WithValueは「プロセスや API の境界を越える、リクエストの範囲のデータ」に使うと標準のドキュメントにあります(context/context.go718 行 "Use context Values only for request-scoped data that transits processes and APIs")。袋はまさにそれです。ただし ctx の値は型で守られないので、取り出し関数(outcomeOf)を 1 つにして、型アサーションを 1 か所に閉じ込めました
🌐 他言語との比較
| 言語・FW | 1 リクエスト 1 行の作り方 | 送信後の失敗の見え方 | 今日の Go との違い |
|---|---|---|---|
| Go(今日の Edge) | 最外側の defer で slog.LogAttrs | aborted として 1 行 | panic は recover()→数える→panic(p) と手で渡し直す |
| Java(Spring+Logback の MDC) | MDC(スレッドに紐づく辞書)に user などを積み、アクセスログで出す(記憶) | 例外は自動で上がる | MDC はスレッドに紐づくので、非同期処理で値が消える問題がある(記憶)。Go の ctx は明示的に渡すので消えない代わりに、渡し忘れる |
| Python(structlog の contextvars) | bind_contextvars で積み、最後に 1 行(記憶) | — | contextvars は暗黙に伝わる。Go の ctx は引数で渡す |
| Node(Express+pino-http) | res.on("finish") で 1 行(記憶) | 途中で切れると "finish" でなく "close" が来る(記憶) | 終わり方ごとにイベントが分かれる。Go は 1 つの defer で全部を見る |
🏭 実務での使いどころ
- otelhttp を入れるとき: メトリクスを otelhttp に任せる前に、ストリーミング応答(CSV・JSON Lines・SSE)があるかを確かめる。あるなら aborted がメトリクスから消える(実測 2)。メトリクスは自前の Edge から出し、otelhttp はトレースだけにする
- ダッシュボードの監査:
class=abortedの件数が 0 のまま動かないなら、数えていない(案 C の状態)を疑う - 問い合わせ対応の手順:
user=… route=…でログを 1 行引けば結末が分かる。panic なら同じ行に stack がある - コードレビューの観点: 中間件の差分で
slog.Error/log.Printfを見つけたら「それは Edge の 1 行に載せられないか」を聞く。メトリクスのラベルに変数(user・path・error 文言)が入っていないかを見る
⚠️ よくある誤解・ミス
| 誤解・ミス | なぜ起こるか | 正しい理解 |
|---|---|---|
| 件数が 1 なら記録は正しい | Day 070 で件数を直したので安心する | 中身が 3 か所に分かれていると、1 行で結末が分からない(実測 1) |
| otelhttp を被せればメトリクスは全部取れる | 最外側に置けばすべて見えると思う | next.ServeHTTP の後で書くので、通り抜ける panic(aborted)は記録されない(実測 2) |
| span が出ていれば成功/失敗は分かる | span の存在と状態を混同する | S5・S6 の span は出るが Unset。画面では成功に見える |
| 何も書かれていなければ 200 | net/http の既定動作 | otelhttp も同じ規則で、相手が切った要求を 200 にする(S7) |
| 4xx も span を Error にする | 失敗はすべて赤くしたい | サーバーから見た 4xx は正しく断った結果。OTel の規則も Unset |
| user をメトリクスのラベルに入れると便利 | ダッシュボードで人ごとに見たい | 系列が利用者数だけ増える。人ごとに見るのはログ |
| スタックは最外側で取ればよい | 1 か所に集めたいので | 最外側では panic の場所が巻き戻った後。Recover の defer の中で取る |
🚧 扱わなかった範囲と理由
| 範囲 | 理由 |
|---|---|
| Stripe の canonical log lines・Honeycomb の wide events・Google SRE Workbook の本文 | 今回 URL を開いていない。表の行は記憶 |
edge.go に OTel をつなぐ(span に Error を付ける・Edge からメトリクスを OTel で出す) | 解答は標準ライブラリだけに保った。span に Error を付ける部分は実測 2 の検証コードでだけ動かした。何もしない MeterProvider を otelhttp に渡す構成は未実測 |
| otelhttp の S7(499 を 200 と書く)を直す | span の属性を内側から上書きできるかは未確認 |
| R8 で status が 200 と出る件 | Recover を付ける前提の設計なので直していない。直すなら「aborted かつ何も送っていない」を status 0 として出す |
| ログの間引き(class=ok を 1/100) | 方針だけ書いた。実装・実測していない |
| リクエスト ID・trace_id をログの 1 行に載せる | Day 065 の RequestID と、OTel の trace_id の両方が要る。次回の候補 |
| HTTP/2 での切断 | Day 069・070 と同じく未測定 |
| 時間の比較 | ロードアベレージ 19 台。割り当てだけを根拠にした |
| Java・Python・Node の行 | 「記憶」と書いた行は、今回ソースも実行も確認していない |
➡️ 次のステップ
- 発展: Edge の 1 行に trace_id を載せ、ログからトレースへ飛べるようにする(
trace.SpanContextFromContext(r.Context()).TraceID())。ログとトレースの突き合わせが 1 か所の値で済むか - 次回予告: 同テーマで「実装」——Edge を本物の OTel につなぐ。otelhttp はトレースだけにし、Edge から
http.server.request.durationを自前で出し(class ラベル付き)、slog の Handler で trace_id・request_id を 1 行に自動で載せる。実測 2 の表が全場面で埋まることをテストで固定する