コードメカニック【Middleware】一行変えるのに、三十回ボンネットを開けた〜各車に貼った同じ点検を、通り抜ける一本のラインへ〜

三十ファイルの diff

ログ基盤を入れ替えるから、リクエストIDの形式を変えてくれ——そう頼まれたのは、今朝の朝会でのことだった。たった一行の話だと思った。req-<連番> の組み立て方を、ちょっと変えるだけ。午前のうちに片付けて、午後は別の仕事に移るつもりだった。

そうはならなかった。

一日が暮れるころ、ようやくコミットを打った。指が、もう何度なぞったか分からない動きを繰り返していた。ファイルを開く、同じ一行を探す、直す、保存する、閉じる。開く、探す、直す、保存する、閉じる。確認のつもりで git diff --stat を打つと、画面が、淡々と返してきた。

1
2
$ git diff --stat
 ... 30 files changed, 60 insertions(+), 60 deletions(-)

三十ファイル。リクエストIDを組み立てる、たった一行。それが三十個のハンドラーに、一つずつ、手で書き写されていた。だから三十回、ファイルを開いて、同じ一行を直して、閉じた。論理の上では一行の変更が、指の上では三十往復になった。またこれか、と思う。声には出さない。出すだけの気力も、もう惜しい。

僕は勤怠管理のSaaSで、サーバー側を受け持っている。打刻、休暇申請、承認、勤務表——APIのエンドポイントは三十本くらいあって、その面倒を、入社三年目の僕が、だいたいひとりで見ている。派手な障害は、めったに起きない。起きないかわりに、こういう、一行が三十回に化ける作業が、月に何度か僕の午後を静かに溶かしていく。

断っておくと、僕はコピペ猿じゃない。同じコードをそこらじゅうに貼って平気でいられる質じゃない。それが嫌で、認証チェックくらいは、ずっと前に setup() という共通関数に括り出してある。そこは、ちゃんとやった。三十本のうち、打刻を受けるハンドラーを開いてみる。

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
// agents/code-mechanic/tests/cross-cutting-middleware/before/handler.go
package before

import (
	"fmt"
	"log"
	"net/http"
	"time"
)

func validateToken(token string) bool {
	return token == "Bearer secret"
}

// 客がコピペを嫌って括り出したのは、認証だけ
func setup(w http.ResponseWriter, r *http.Request) bool {
	token := r.Header.Get("Authorization")
	if !validateToken(token) {
		http.Error(w, "unauthorized", 401)
		return false
	}
	return true
}

func handleClockIn(w http.ResponseWriter, r *http.Request) {
	// 開始時刻。あとで time.Since(start) との差で処理時間を測る
	start := time.Now()
	reqID := fmt.Sprintf("req-%d", time.Now().UnixNano()) // これを変えると全ハンドラを直す
	log.Printf("[%s] start %s %s", reqID, r.Method, r.URL.Path)
	defer func() { // deferはこの関数が戻るとき必ず走る予約。recover()はpanicを捕まえるが、deferを仕掛けたその関数の中でしか効かない
		if rec := recover(); rec != nil {
			log.Printf("panic: %v", rec)
			http.Error(w, "internal error", 500)
		}
	}()
	if !setup(w, r) {
		return
	}
	fmt.Fprintf(w, `{"clockIn":"ok"}`)
	log.Printf("[%s] done %s took %v", reqID, r.URL.Path, time.Since(start))
}

func handleRequestLeave(w http.ResponseWriter, r *http.Request) {
	start := time.Now()
	reqID := fmt.Sprintf("req-%d", time.Now().UnixNano()) // これを変えると全ハンドラを直す
	log.Printf("[%s] start %s %s", reqID, r.Method, r.URL.Path)
	defer func() {
		if rec := recover(); rec != nil {
			log.Printf("panic: %v", rec)
			http.Error(w, "internal error", 500)
		}
	}()
	if !setup(w, r) {
		return
	}
	fmt.Fprintf(w, `{"leave":"requested"}`)
	log.Printf("[%s] done %s took %v", reqID, r.URL.Path, time.Since(start))
}

認証は setup() に括った。そこは括れた。でも、それ以外——処理時間の計測（start）、リクエストIDの生成、開始ログ、defer で仕掛けた panic の受け止め、終了ログ——は、二つのハンドラーに、そっくり同じ形で並んでいる。handleClockIn と handleRequestLeave で違うのは、真ん中の一行（本体）だけだ。残りは、判で押したように同じ。これが三十本ある。今日の三十往復の正体は、これだ。

defer というのは、この関数が戻るときに必ず走る予約のことだ。中の recover() が、もし panic（実行時の異常終了）が起きていたら、それを捕まえて、500を返す。だから一応、どのハンドラーも panic で落ちはしない。ちゃんと書いてある。三十本、ぜんぶに。

障害が起きたわけじゃない。誰かが困っているわけでもない。ただ、三十ファイルの diff を見ていたら、これは何かが根本から間違っている、という気がした。こんな徒労で人を呼んでいいのか、と少し迷った。緊急でもないのに。それでも、社内の勉強会で誰かが話していた、出張整備の「親方」を呼ぶことにした。本番で詰んだ奴が最後に頼る人、と聞いていた。僕のは詰んでいるわけじゃない。ただ、すり減っていた。

ほどなく現れた親方は、噂で聞いていたとおり、世間話の一つもしなかった。僕が「これ、見てもらえますか」とエディタを開いて見せようとするより先に、画面の隅にまだ残っていた git diff --stat の出力——「30 files changed」——に、目を留めた。

「一行直すのに、三十回ボンネットを開けたのか」

責める口調では、なかった。声を張るでもなく、ただ、事実を一つ確かめるように。僕が午後ぜんぶを溶かして何をしていたのか、その一言で言い当てられた気がして、伝わった、と思った。

先頭で呼ぶだけでは挟めない

「分かってます」と、僕は先回りして言った。先に自分で答えを言っておきたかった。「コピペが良くないのは、分かってるんです。だから認証は括り出した。残りも、同じようにすればいいんですよね。setup() をもっと太らせて、リクエストIDも、ログも、処理時間も、panic の受け止めも、全部その中に入れて、各ハンドラーの先頭で呼ぶ」

僕はそう言いながら、もう手を動かしかけていた。これくらいは、言われる前に自分でやれる。そのつもりだった。

親方は、僕の手元のコードの、defer の行を指した。

「それは、入らない」

「……入らない?」

手が、止まった。

「recover() は、defer を仕掛けた、その関数の中でしか効かない」親方は続けた。指は defer の行に置いたまま。「setup() の中で defer を書いても、それは setup() が戻るときに走る。setup() は、ハンドラーの先頭で呼ばれて、すぐ戻ってくる。本体は、そのあとに動く。setup() が、もう帰ったあとだ。そこで panic が起きても、setup() の defer は、とっくに終わっている」

僕は、自分のコードをもう一度見た。インラインで書いた defer recover() が、これまでちゃんと panic を捕まえられていたのは——本体と同じ関数、つまりハンドラーそのものの中に、defer がいたからだ。それを setup() に追い出したら、本体は別の関数で動くことになる。setup() の中の recover() は、その別の関数の panic までは、手が届かない。

言われてみれば、当たり前だった。当たり前なのに、自分では見えていなかった。

「……じゃあ」と、それでも僕は食い下がった。せっかくの思いつきを、まだ手放したくなかった。「後処理用に teardown() も作って、各ハンドラーの末尾で呼べば、処理時間のログは——」

言いかけて、止まった。

recover は、末尾でも無理だ。それは今、自分で理解したばかりだ。それに——先頭で setup()、末尾で teardown()、その間に defer を自分の手で書いて。結局、三十個のハンドラーぜんぶに、その三点セットを並べることになる。一行変えれば、また三十回開く。何も、変わっていない。今朝の三十往復が、形を変えて戻ってくるだけだ。

「前置きは括れた」と親方は言った。僕が自分で気づくのを待っていたように。「だが、後ろの後始末と、全体を見張る一枚は、先頭で呼ぶ形では乗らない」

入口・出口・全体監視

「これは、横断的関心事だ」

親方は、僕の机にあったメモ用紙を一枚引き寄せて、ハンドラー of コアを描いた。そして、その前と後ろと、箱全体を囲むように、三本の線を引いた。たった三本の線だったが、僕がさっきまで指で三十往復していたものが、その紙の上に、急に整理されて見えた。

Cross-cutting concern diagram showing an overall guard outer plate containing inlet and outlet plates surrounding the core handler

そのメモ書きは、まさに僕たちが「横断的関心事」と呼ぶべき要素が、どうハンドラーを取り囲むべきかを示していた。

横断的関心事（cross-cutting concern）: ログ・認証・panic からの復帰・処理時間の計測のように、各ハンドラー本来の仕事とは別の軸で、多くのハンドラーに横断して必要になる処理。各所にコピペすると、一つ変えるだけで全箇所に変更が波及する。

「点検は、三方向にある」親方は、引いた線を順に指でなぞった。「受け付ける入口。送り出す出口。そして、火が出ないか見張る、全体。お前は入口に点検係を一人立てた。それが setup() だ。だが、出口で時間を測る係と、全体を見張る係——panic を受け止める recover——は、まだ三十台ぜんぶに、手で乗せている」

入口だけ。たしかに、僕が括れたのは、入口だけだった。

「最初は、エンドポイントも少なかったんです」僕は、言い訳のように口を開いていた。「二本か、三本で。ハンドラーに前置きを直接書くのが、一番手っ取り早かったんですよ。動けばよかったし」

「手っ取り早さは、台数が増えると逆になる」親方は淡々と返した。咎める響きはない。ただ、構造を述べていた。「一台ずつ点検を貼ると、点検項目を一つ変えるたびに、台数のぶんだけ貼り替える。今朝のお前の三十回が、それだ」

そこで、ようやく言葉になった。僕がずっと、何をやらされていたのか。点検そのものを、車に貼り付けている。だから、車の数だけ貼り替えになる。点検を車から剥がして、別のどこかに一本化できれば——三十が、一になる。

口に出してみる。「点検を、車に貼ってるから……車の数だけ、貼り替えなんだ。点検のほうを、車から剥がせればいい」

「そこまで来れば、あとは早い」親方は、メモを僕のほうへ少し滑らせた。

ハンドラーを包む

「点検を、車に貼るのをやめる」親方は、メモのハンドラーの箱の手前に、縦線を何本か引いた。検査ステーションが並んだ、一本のラインの絵だった。「ラインを一本作って、その上に車を流す。ラインの一区間が、一つの点検だ」

親方が組もうとしているのは、Middleware と呼ばれるものだ。

Middleware（ミドルウェア）: 同じ型のハンドラーを受け取り、その前後（と全体）に横断処理を足した新しいハンドラーを返す関数。Go では func(http.Handler) http.Handler。横断関心を層に分け、合成して土台のハンドラーに被せる。

親方は、僕のキーボードを借りると、横断処理を層に組み替えていった。手つきに、迷いがなかった。

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
// agents/code-mechanic/tests/cross-cutting-middleware/after/middleware.go
package after

import (
	"fmt"
	"log"
	"net/http"
	"time"
)

func validateToken(token string) bool {
	return token == "Bearer secret"
}

// Middleware はハンドラを受け取り、包んだ新しいハンドラを返す関数型。func(http.Handler) http.Handler = 包む高階関数
type Middleware func(http.Handler) http.Handler

// Logging はリクエストの開始・終了ログと処理時間を記録するミドルウェア。
// http.Handler は ServeHTTP(ResponseWriter, *Request) を持つインターフェース。
// http.HandlerFunc は func(w, r) を http.Handler に変えるアダプタ。
func Logging(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		start := time.Now()
		reqID := fmt.Sprintf("req-%d", time.Now().UnixNano()) // 形式を変えるのはこの一行だけ
		log.Printf("[%s] start %s %s", reqID, r.Method, r.URL.Path)
		next.ServeHTTP(w, r)
		log.Printf("[%s] done %s took %v", reqID, r.URL.Path, time.Since(start))
	})
}

// Auth はリクエストの認証を行うミドルウェア。
// 認証失敗時は next を呼ばずに打ち切る。
func Auth(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		token := r.Header.Get("Authorization")
		if !validateToken(token) {
			http.Error(w, "unauthorized", 401)
			return
		}
		next.ServeHTTP(w, r)
	})
}

// Recover はパニックを捕まえて 500 を返すミドルウェア。
// deferでnext全体を包むから本体のpanicも捕まえる
func Recover(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		defer func() {
			if rec := recover(); rec != nil {
				log.Printf("panic: %v", rec)
				http.Error(w, "internal error", 500)
			}
		}()
		next.ServeHTTP(w, r)
	})
}

// Chain はハンドラにミドルウェアを合成して返す。
// middlewares は可変長引数（...Middleware）。Recover, Logging, Auth のように何個でも渡せ、中ではスライスになる。
// 逆順ループで被せるので、先頭に渡したミドルウェアが最外層になる。
func Chain(h http.Handler, middlewares ...Middleware) http.Handler {
	for i := len(middlewares) - 1; i >= 0; i-- { // 先頭に渡したものが最外層
		h = middlewares[i](h)
	}
	return h
}

打ち終えた画面を、僕は端から目で追った。見たことのある単語と、見たことのない形が混じっている。まず、確かめたかったところを聞いた。

「http.Handler っていうのは……ServeHTTP を持っているやつ、ですよね」僕は確かめた。「その http.HandlerFunc は? 似てるけど、別物ですか」

「func(w, r) に、http.Handler の型を着せるものだ」親方は答えた。「http.HandlerFunc の ServeHTTP は、中で元の関数を呼ぶだけ。だから func(w, r) を包めば、その関数が ServeHTTP の中身になって、一人前のハンドラーとして通る。http.HandlerFunc(...) は関数呼び出しに見えるが、これは型を着せる書き方だ」

それだけだ、と言われると、それだけに見えてくる。僕は Logging を目で追った。return http.HandlerFunc(...)——Logging 自体も、ハンドラーを組み立てて返す関数だった。Logging(next) を呼んだ時点では、包んだハンドラーを返すだけ。中の func(w, r) が動くのは、リクエストが来て ServeHTTP が呼ばれたときだ。そのとき内側は、受け取った next をまだ覚えている。外で受け取った変数を、内側の関数が抱えたまま生きる——クロージャ、というらしい。next.ServeHTTP(w, r) という一行があって、その前にログの開始、後ろにログの終了と処理時間が書いてある。さっきの setup() には、なかった形だ。

「……分かった気がします」と僕は言った。確かめながら、ゆっくり。「next.ServeHTTP を挟んで、その前に書けば入口、後ろに書けば出口だ。setup() は、呼ばれて、戻ってくるだけだった。本体には、触れていなかった。でもこれは、本体を——next を——またいでいる。だから、前も後ろも、両方書ける」

「そうだ」

短い肯定だったが、それで十分だった。次に Recover を見て、さっき詰まったことが、ほどけた。

「これ、defer で next.ServeHTTP ごと包んでいる」僕は、指で Recover の中をなぞった。「さっき setup() では捕まえられなかったのは、本体が setup() の外で動いていたから、でした。setup() の defer は、本体が動く前に、もう終わっていた。でも今度は、本体が——next が——この Recover の defer の内側で動く。だから、本体の panic も、ここで捕まる」

II幕でつまずいた壁が、ここで、ちゃんと裏返って答えになっていた。捕まえられなかった理由と、捕まえられる理由が、同じ一つの事実——defer は仕掛けた関数の中でしか効かない——の表と裏だった。

Auth は、認証に失敗したら next を呼ばずに return していた。点検で引っかかった車は、ラインの先へ流さない。シンプルだ。

最後の Chain だけ、まだ腑に落ちなかった。「これ、なんで後ろから回すんですか」僕は逆順のループを指した。「for i := len-1; i >= 0; i-- って。前から順に被せちゃ、駄目なんですか」

「h = middlewares[i](h) を、末尾から順に被せていく」親方は言った。「Chain(本体, Recover, Logging, Auth) なら、末尾の Auth でまず本体を包む。その外を Logging、さらに外を Recover。最初に渡したものが、一番外側になる」

僕は頭の中で追った。Auth(本体)、Logging(Auth(本体))、Recover(Logging(Auth(本体)))。h が、被せるたびに外へ育っていく。最後に被せた Recover——先頭に渡したやつが、一番外のかっこだ。呼び出しのほうを見ると、Recover を Recover() と呼ばず、名前だけ渡している。関数そのものを値として渡し、...Middleware で受けた Chain が、それをスライスにまとめて順に被せていた。

「外側が、一番先に入口を通って、一番後に出口で戻る」親方は続けた。「panic を取り逃がさない Recover を、一番外に置く。内側の Logging や Auth の中で何かが起きても、外にいればまとめて受け止められる。内側に置いたら、その外側で起きた異常は、取り逃がす」

順番に、意味がある。並べた順がそのまま、外から内への重なりになる。僕は、ラインの絵を思い出した。一番外の検査ステーションが、一番手前で車を迎えて、一番奥で見送る。

Nested Middleware execution diagram representing request and response paths flowing through RECOVER, LOGGING, and AUTH nested steel plates

この入れ子状の多層構造こそが、Goのミドルウェアの本質だ。リクエストは外側のシールドから順に通過してコアエンジンに到達し、レスポンスは逆順に外へ向かって抜けていく。

そして親方は、ハンドラー本体を見せた。

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
// agents/code-mechanic/tests/cross-cutting-middleware/after/handlers.go
package after

import (
	"fmt"
	"net/http"
)

func handleClockIn(w http.ResponseWriter, r *http.Request) {
	fmt.Fprintf(w, `{"clockIn":"ok"}`)
}

func handleRequestLeave(w http.ResponseWriter, r *http.Request) {
	fmt.Fprintf(w, `{"leave":"requested"}`)
}

// NewRouter はミドルウェアを合成したルーターを返す。
func NewRouter() http.Handler {
	mux := http.NewServeMux()
	mux.Handle("/clock-in", Chain(http.HandlerFunc(handleClockIn), Recover, Logging, Auth))
	mux.Handle("/request-leave", Chain(http.HandlerFunc(handleRequestLeave), Recover, Logging, Auth))
	return mux
}

handleClockIn が、打刻の本体一行だけになっていた。リクエストIDも、ログも、計測も、recover も、ぜんぶ消えている。さっきまで、この一行の上下を、前置きと後始末がびっしり挟んでいた。それが、きれいに無くなっている。横断処理は Chain(..., Recover, Logging, Auth) の一行に並んで、土台のハンドラーに被さっている。末尾の NewRouter では、http.NewServeMux——パスとハンドラーを結びつけるルーター——に、mux.Handle("/clock-in", Chain(...)) の形で、合成済みのハンドラーをパスごと登録している。

念のため、僕は Before と After を、頭の中で並べた。ログを取る処理も、認証の判定も、panic を 500 にする手当ても、リクエストIDの形式も——中身は、さっきのコピペ版と、何も変わっていない。同じ fmt.Sprintf("req-%d", ...)、同じ recover()、同じ time.Since(start)。違うのは、それを「各ハンドラーに貼る」か「層に分けて被せる」か——置き方だけだ。挙動を直したわけじゃない。直したのは、変えるときの手数だ。

「点検係を、一台ずつ貼るんじゃない」僕は、自分の言葉で言い直してみた。さっきメモの上で見た絵を、コードに重ねながら。「ライン一本を作って、車をそこに流す。入口も、出口も、全体監視も、ぜんぶライン上にある。新しいエンドポイントは、本体だけ書いて、ラインに乗せるだけだ。……リクエストIDの形式を変えるのも、Logging の、この一行を直すだけ。三十回ボンネットを開けなくていい」

「前に、io.Writer を一枚ずつ被せる話をした奴がいた」親方は、工具をしまう手を止めずに言った。「あれ（Decorator）は、データを変換して積む。これは、リクエストの処理を、前と後ろで挟む。被せる形は似ていても、被せる相手が違う」

似ているから、混ぜるな、ということだろう。被せる、という所作は同じでも、何を被せているのか。片方はデータ。こっちは、処理そのもの。

ラインに流す

親方が、ひとつずつテストを走らせていく。認証が失敗したら本体まで届かないこと。panic を起こすハンドラーが、ちゃんと500になってサーバーごと落ちないこと。ログが本体の前と後ろの両方に出ること。そして、Chain で重ねた層が、外から内へ正しい順で通ること。一区間ずつ、別々に。

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
=== RUN   TestAuth
=== RUN   TestAuth/unauthorized
=== RUN   TestAuth/authorized
--- PASS: TestAuth (0.00s)
=== RUN   TestRecover
--- PASS: TestRecover (0.00s)
=== RUN   TestLogging
--- PASS: TestLogging (0.00s)
=== RUN   TestChainOrder
--- PASS: TestChainOrder (0.00s)
PASS
ok  	code-mechanic/cross-cutting-middleware/after	0.274s

緑が、四つ並んだ。ひとつずつ、点検の区間が、単体で確かめられている。さっきまで、点検は三十本のハンドラーに溶けていて、どこからどこまでが一つの点検なのか、切り出して確かめることもできなかった。それが今は、Logging だけ、Recover だけ、と取り出してテストにかけられる。

「ラインが通った」親方は言った。「あとは、流すだけだ」

「リクエストIDの形式を変えるのも、これからは Logging の一区間だけ」僕は、消えた横断処理のことを思った。三十本から剥がれて、ラインの上に畳まれていったやつらを。「新しいエンドポイントを足すときも、本体を書いて、ラインに乗せるだけ。……もう、一行のために三十回、ボンネットを開けなくていい」

親方は工具箱を閉じた。僕が財布のことを言いかけると、軽く首を振って、それを止めた。

親方は、メモに描いた点検ラインの図を、ペンの先で一度だけ叩いた。「この一本を、通したまま帰らせろ。横断処理は、ここに置く。車に貼り直した瞬間、今朝の三十回が、そっくり戻ってくる」

ペン先が、ラインの一区間を、軽くなぞった。「形式を変えるときは、ここを一度だけ。それで済む」

「はい」僕はうなずいた。「点検は、ラインの上だけに、します」

親方はペンを置き、工具箱を提げて立ち上がった。引き止める間も、礼を言い直す間もなかった。挨拶もなく、油と金属の匂いだけを、机のあたりにわずかに残して、フロアの出口へ歩いていく。その後ろ姿を見送ってから、僕は handleClockIn をもう一度開いた。打刻の本体が一行あるだけで、横断処理はどこにも残っていない。ぜんぶ、ラインの上に移った。

試しに、今朝あれだけ僕を往復させたリクエストIDの形式を、今度は Logging の、あの一行だけで書き換えてみる。保存して、git diff --stat を打つ。

1 file changed。

たった一行。今朝と、同じ一行の変更だ。なのに、画面に並ぶのは、一ファイル。指は、一往復で済んだ。今朝の三十回は、いったい何だったんだろう——と思いかけて、やめた。あれはもう、ラインの上に畳んだ。次からは、ここを一度開けば済む。

整備記録簿

症状と整備の対応表

こんな異音・症状が出たら	入れるべき整備（パターン）	まだ様子見でいい
ログ・認証・recover・計測などの同じ前置きが全ハンドラーにコピペされ、一つ変えると全部を直す	`✓` 横断処理を `func(http.Handler) http.Handler` の Middleware に分け、`Chain` で合成する
共通処理を関数に括ったのに、処理時間の締めや `recover` がハンドラーに残って剥がれない	`✓` 「先頭で呼ぶ」をやめ、`next.ServeHTTP` の前後を挟む形で包む
一部のエンドポイントだけ認証を外す・ログを足す等、付け外しを宣言的にしたい	`✓` `Chain` の引数を足し引きする
横断処理が1種類だけで、ハンドラーも数本・増える見込みもない		`✓` 各ハンドラーに直書きで十分。層に分けるのは過剰

整備手順

ハンドラー本体と無関係な横断処理（ログ・認証・recover・計測・リクエストID）を洗い出す。入口（前処理）・出口（後処理）・全体（recover）のどれに当たるかを意識する。
各横断処理を func(next http.Handler) http.Handler のミドルウェアにする。中で next.ServeHTTP(w, r) を呼び、その前に入口処理、後に出口処理を書く。
recover は defer で next.ServeHTTP を包む。defer は仕掛けた関数の中でしか効かないので、「先頭で呼ぶ共通関数」ではなく「包むミドルウェア」にする必要がある。
Chain(h, mw...) を for i := len-1; i >= 0; i-- の逆順ループで合成し、先頭に渡したミドルウェアを最外層にする。Recover は panic を取り逃がさないよう最外層に置く。
ハンドラー本体から横断処理を全部消し、自分の仕事だけにする。新しいエンドポイントは本体を書いて Chain に通すだけ。リクエストIDの形式変更は、該当ミドルウェア1箇所で済む。

親方より

コピペを嫌って関数に括ったのは、半分は正しい。だが「先頭で呼ぶ」では、入口の前置きしか剥がせない。出口の後始末と、全体を見張る recover は、車に貼ったまま残る。横断処理は、車に貼るな——ラインに置け。ハンドラーを包む層を一本通して、その上を流せ。点検項目を変えるのは、ラインの一区間だけ。新しい車が増えても、ラインに乗せるだけだ。一行直すのに三十回ボンネットを開ける、あれを二度とやるな。