Request ID Logging (#1087)

* Add RequestID to the RequestScope

* Expose RequestID to auth & request loggers

* Use the RequestID in templated HTML pages

* Allow customizing the RequestID header

* Document new Request ID support

* Add more cases to scope/requestID tests

* Split Get vs Generate RequestID funtionality

* Add {{.RequestID}} to the request logger tests

* Move RequestID management to RequestScope

* Use HTML escape instead of sanitization for Request ID rendering
This commit is contained in:
Nick Meves
2021-03-21 18:20:57 +00:00
committed by GitHub
parent 4d9de06b1d
commit c1267bb92d
23 changed files with 274 additions and 72 deletions
+8 -5
View File
@@ -13,7 +13,7 @@ import (
. "github.com/onsi/gomega"
)
const RequestLoggingFormatWithoutTime = "{{.Client}} - {{.Username}} [TIMELESS] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
const RequestLoggingFormatWithoutTime = "{{.Client}} - {{.RequestID}} - {{.Username}} [TIMELESS] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
var _ = Describe("Request logger suite", func() {
type requestLoggerTableInput struct {
@@ -37,7 +37,10 @@ var _ = Describe("Request logger suite", func() {
req.RemoteAddr = "127.0.0.1"
req.Host = "test-server"
scope := &middlewareapi.RequestScope{Session: in.Session}
scope := &middlewareapi.RequestScope{
RequestID: "11111111-2222-4333-8444-555555555555",
Session: in.Session,
}
req = middlewareapi.AddRequestScope(req, scope)
handler := NewRequestLogger()(testUpstreamHandler(in.Upstream))
@@ -47,7 +50,7 @@ var _ = Describe("Request logger suite", func() {
},
Entry("standard request", &requestLoggerTableInput{
Format: RequestLoggingFormatWithoutTime,
ExpectedLogMessage: "127.0.0.1 - standard.user [TIMELESS] test-server GET standard \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n",
ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - standard.user [TIMELESS] test-server GET standard \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n",
Path: "/foo/bar",
ExcludePaths: []string{},
Upstream: "standard",
@@ -55,7 +58,7 @@ var _ = Describe("Request logger suite", func() {
}),
Entry("with unrelated path excluded", &requestLoggerTableInput{
Format: RequestLoggingFormatWithoutTime,
ExpectedLogMessage: "127.0.0.1 - unrelated.exclusion [TIMELESS] test-server GET unrelated \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n",
ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - unrelated.exclusion [TIMELESS] test-server GET unrelated \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n",
Path: "/foo/bar",
ExcludePaths: []string{"/ping"},
Upstream: "unrelated",
@@ -69,7 +72,7 @@ var _ = Describe("Request logger suite", func() {
}),
Entry("ping path", &requestLoggerTableInput{
Format: RequestLoggingFormatWithoutTime,
ExpectedLogMessage: "127.0.0.1 - mr.ping [TIMELESS] test-server GET - \"/ping\" HTTP/1.1 \"\" 200 4 0.000\n",
ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - mr.ping [TIMELESS] test-server GET - \"/ping\" HTTP/1.1 \"\" 200 4 0.000\n",
Path: "/ping",
ExcludePaths: []string{},
Upstream: "",
+14 -1
View File
@@ -3,18 +3,31 @@ package middleware
import (
"net/http"
"github.com/google/uuid"
"github.com/justinas/alice"
middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware"
)
func NewScope(reverseProxy bool) alice.Constructor {
func NewScope(reverseProxy bool, idHeader string) alice.Constructor {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) {
scope := &middlewareapi.RequestScope{
ReverseProxy: reverseProxy,
RequestID: genRequestID(req, idHeader),
}
req = middlewareapi.AddRequestScope(req, scope)
next.ServeHTTP(rw, req)
})
}
}
// genRequestID sets a request-wide ID for use in logging or error pages.
// If a RequestID header is set, it uses that. Otherwise, it generates a random
// UUID for the lifespan of the request.
func genRequestID(req *http.Request, idHeader string) string {
rid := req.Header.Get(idHeader)
if rid != "" {
return rid
}
return uuid.New().String()
}
+66 -8
View File
@@ -4,11 +4,19 @@ import (
"net/http"
"net/http/httptest"
"github.com/google/uuid"
middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware"
. "github.com/onsi/ginkgo"
. "github.com/onsi/gomega"
)
const (
testRequestHeader = "X-Request-Id"
testRequestID = "11111111-2222-4333-8444-555555555555"
// mockRand io.Reader below counts bytes from 0-255 in order
testRandomUUID = "00010203-0405-4607-8809-0a0b0c0d0e0f"
)
var _ = Describe("Scope Suite", func() {
Context("NewScope", func() {
var request, nextRequest *http.Request
@@ -24,10 +32,11 @@ var _ = Describe("Scope Suite", func() {
Context("ReverseProxy is false", func() {
BeforeEach(func() {
handler := NewScope(false)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler := NewScope(false, testRequestHeader)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler.ServeHTTP(rw, request)
})
@@ -52,10 +61,11 @@ var _ = Describe("Scope Suite", func() {
Context("ReverseProxy is true", func() {
BeforeEach(func() {
handler := NewScope(true)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler := NewScope(true, testRequestHeader)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler.ServeHTTP(rw, request)
})
@@ -65,5 +75,53 @@ var _ = Describe("Scope Suite", func() {
Expect(scope.ReverseProxy).To(BeTrue())
})
})
Context("Request ID header is present", func() {
BeforeEach(func() {
request.Header.Add(testRequestHeader, testRequestID)
handler := NewScope(false, testRequestHeader)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler.ServeHTTP(rw, request)
})
It("sets the RequestID using the request", func() {
scope := middlewareapi.GetRequestScope(nextRequest)
Expect(scope.RequestID).To(Equal(testRequestID))
})
})
Context("Request ID header is missing", func() {
BeforeEach(func() {
uuid.SetRand(mockRand{})
handler := NewScope(true, testRequestHeader)(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nextRequest = r
w.WriteHeader(200)
}))
handler.ServeHTTP(rw, request)
})
AfterEach(func() {
uuid.SetRand(nil)
})
It("sets the RequestID using a random UUID", func() {
scope := middlewareapi.GetRequestScope(nextRequest)
Expect(scope.RequestID).To(Equal(testRandomUUID))
})
})
})
})
type mockRand struct{}
func (mockRand) Read(p []byte) (int, error) {
for i := range p {
p[i] = byte(i % 256)
}
return len(p), nil
}
+1
View File
@@ -401,6 +401,7 @@ var _ = Describe("Stored Session Suite", func() {
}
req := httptest.NewRequest("", "/", nil)
req = middlewareapi.AddRequestScope(req, &middlewareapi.RequestScope{})
refreshed, err := s.refreshSessionWithProvider(nil, req, in.session)
if in.expectedErr != nil {
Expect(err).To(MatchError(in.expectedErr))