【Go 1.8】net/http の 400 Bad Request の扱いについて

Go の HTTPルータ github.com/julienschmidt/httprouter の Router型には NotFound http.Handler や MethodNotAllowed http.Handler があり, Handler 内で access.log に残すなどの追加の処理が書ける。

package main

import (
	"fmt"
	"github.com/julienschmidt/httprouter"
	"log"
	"net/http"
)

func Hello(w http.ResponseWriter, r *http.Request, ps httprouter.Params) {
	fmt.Fprintf(w, "hello, %s!\n", ps.ByName("name"))
	log.Printf("hello, %s!\n", ps.ByName("name"))
}

// Custom NotFound
func NotFoundHandler(w http.ResponseWriter, req *http.Request) {
	fmt.Fprintf(w, http.StatusText(http.StatusNotFound))
	log.Println(http.StatusText(http.StatusNotFound), req)
}

// Custom MethodNotAllowed
func MethodNotAllowedHandler(w http.ResponseWriter, req *http.Request) {
	fmt.Fprintf(w, http.StatusText(http.StatusMethodNotAllowed))
	log.Println(http.StatusText(http.StatusMethodNotAllowed), req)
}

// Custom Panic
func PanicHandler(w http.ResponseWriter, req *http.Request, v interface{}) {
	fmt.Fprintf(w, http.StatusText(http.StatusInternalServerError))
	log.Println(http.StatusText(http.StatusInternalServerError), req)
}

func main() {
	router := httprouter.New()
	router.GET("/hello/:name", Hello)

	router.NotFound = http.HandlerFunc(NotFoundHandler)
	router.MethodNotAllowed = http.HandlerFunc(MethodNotAllowedHandler)
	router.PanicHandler = PanicHandler

	log.Fatal(http.ListenAndServe(":8080", router))
}

上記のサーバに対して, curlコマンドでHTTPリクエストを送信してみる。

$ curl -vvv localhost:8080/hello/world -F a=b
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> POST /hello/world HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.49.1
> Accept: */*
> Content-Length: 137
> Expect: 100-continue
> Content-Type: multipart/form-data; boundary=------------------------fff3b8d9d88ac1e8
>
< HTTP/1.1 200 OK
< Allow: GET, OPTIONS
< Date: Mon, 20 Mar 2017 02:10:59 GMT
< Content-Length: 18
< Content-Type: text/plain; charset=utf-8
< Connection: close
<
* Closing connection 0
Method Not Allowed

$ curl -vvv localhost:8080/foo
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /foo HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.49.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Mon, 20 Mar 2017 02:11:30 GMT
< Content-Length: 9
< Content-Type: text/plain; charset=utf-8
<
* Connection #0 to host localhost left intact
Not Found

以下のように, サーバ側で 4xx 系のリクエストの中身を掴める。

$ go run custom-router.go
2017/03/20 11:17:43 Method Not Allowed &{POST /hello/world HTTP/1.1 1 1 map[User-Agent:[curl/7.49.1] Accept:[*/*] Content-Length:[137] Expect:[100-continue] Content-Type:[multipart/form-data; boundary=------------------------1dbb185f9029041f]] 0xc4200ec6c0 137 [] false localhost:8080 map[] map[]  map[] 127.0.0.1:56462 /hello/world    0xc420074580}
2017/03/20 11:17:48 Not Found &{GET /foo HTTP/1.1 1 1 map[User-Agent:[curl/7.49.1] Accept:[*/*]] 0x37c000 0 [] false localhost:8080 map[] map[]  map[] 127.0.0.1:56463 /foo    0xc420074800}

しかし, Router型に BadRequest http.Handler がないのが気になり調べていた所, net/http: reconsider bad request logging #18095 という issue を見つけた。

どうやら Go1.8 の `net/http` でHTTPステータスコード 431 と一部の 400 エラーはログに残らないようになっているようである。コードだと net/http/server.go の部分。

CLIENT ERRORS NOT LOGGED:
431 Request Header Fields Too Large
400 Bad Request (various reasons, mostly headers or url)

先ほどと同様のコードに対して, HTTPヘッダの値やURLに space を含め(URLエンコードしないで)リクエストを投げてみると http.Handler の処理の前にレスポンスが返される。

$ curl -vvv localhost:8080/hello/world  -H 'Host:example. com'
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /hello/world HTTP/1.1
> Host:example. com
> User-Agent: curl/7.49.1
> Accept: */*
>
< HTTP/1.1 400 Bad Request
< Content-Type: text/plain
< Connection: close
<
* Closing connection 0
400 Bad Request: malformed Host header

$ curl -vvv localhost:8080/hello/world  --get --data 'q= 12345'
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /hello/world?q= 12345 HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.49.1
> Accept: */*
>
< HTTP/1.1 400 Bad Request
< Content-Type: text/plain
< Connection: close
<
* Closing connection 0
400 Bad Request

Router型に BadRequest http.Handler がないのは, net/http が即座にレスポンスを返しているためのよう。
Go 1.9 に向けて Proposal が出されているみたいので対応されることに期待。
ちなみに < 文字 (URLエンコード後 %3C) と > 文字 (URLエンコード後 %3E) はそれぞれ "\u003c", "\u003e" にエスケープされる。