From 32ccc2671299e4010fc1c84bc0582ba63dda75df Mon Sep 17 00:00:00 2001 From: Bastiaan Bakker Date: Wed, 24 Jan 2018 18:18:03 +0100 Subject: [PATCH] Add username in accesslog --- integration/access_log_test.go | 184 ++++++++++++++++++- integration/fixtures/access_log_config.toml | 18 +- integration/resources/compose/access_log.yml | 8 + middlewares/accesslog/logger.go | 3 +- middlewares/auth/authenticator.go | 5 +- 5 files changed, 200 insertions(+), 18 deletions(-) diff --git a/integration/access_log_test.go b/integration/access_log_test.go index 699e8153f..710883bf5 100644 --- a/integration/access_log_test.go +++ b/integration/access_log_test.go @@ -1,7 +1,10 @@ package integration import ( + "crypto/md5" + "crypto/rand" "fmt" + "io" "io/ioutil" "net/http" "os" @@ -25,6 +28,7 @@ type AccessLogSuite struct{ BaseSuite } type accessLogValue struct { formatOnly bool code string + user string value string backendName string } @@ -94,6 +98,7 @@ func (s *AccessLogSuite) TestAccessLogAuthFrontend(c *check.C) { { formatOnly: false, code: "401", + user: "-", value: "Auth for frontend-Host-frontend-auth-docker-local", backendName: "-", }, @@ -143,6 +148,7 @@ func (s *AccessLogSuite) TestAccessLogAuthEntrypoint(c *check.C) { { formatOnly: false, code: "401", + user: "-", value: "Auth for entrypoint", backendName: "-", }, @@ -184,14 +190,175 @@ func (s *AccessLogSuite) TestAccessLogAuthEntrypoint(c *check.C) { checkNoOtherTraefikProblems(traefikLog, err, c) } -func (s *AccessLogSuite) TestAccessLogEntrypointRedirect(c *check.C) { +func (s *AccessLogSuite) TestAccessLogAuthEntrypointSuccess(c *check.C) { // Ensure working directory is clean ensureWorkingDirectoryIsClean() + expected := []accessLogValue{ + { + formatOnly: false, + code: "200", + user: "test", + value: "Host-entrypoint-auth-docker", + backendName: "http://172.17.0", + }, + } + + // Start Traefik + cmd, display := s.traefikCmd(withConfigFile("fixtures/access_log_config.toml")) + defer display(c) + err := cmd.Start() + c.Assert(err, checker.IsNil) + defer cmd.Process.Kill() + + defer os.Remove(traefikTestAccessLogFile) + defer os.Remove(traefikTestLogFile) + + checkStatsForLogFile(c) + + s.composeProject.Container(c, "authEntrypoint") + + waitForTraefik(c, "authEntrypoint") + + // Verify Traefik started OK + traefikLog := checkTraefikStarted(c) + + // Test auth entrypoint + req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1:8004/", nil) + c.Assert(err, checker.IsNil) + req.Host = "entrypoint.auth.docker.local" + req.SetBasicAuth("test", "test") + + err = try.Request(req, 500*time.Millisecond, try.StatusCodeIs(http.StatusOK), try.HasBody()) + c.Assert(err, checker.IsNil) + + // Verify access.log output as expected + count := checkAccessLogExactValuesOutput(err, c, expected) + + c.Assert(count, checker.GreaterOrEqualThan, len(expected)) + + // Verify no other Traefik problems + checkNoOtherTraefikProblems(traefikLog, err, c) +} + +func (s *AccessLogSuite) TestAccessLogDigestAuthEntrypoint(c *check.C) { + ensureWorkingDirectoryIsClean() + + expected := []accessLogValue{ + { + formatOnly: false, + code: "401", + user: "-", + value: "Auth for entrypoint", + backendName: "-", + }, + { + formatOnly: false, + code: "200", + user: "test", + value: "Host-entrypoint-digest-auth-docker", + backendName: "http://172.17.0", + }, + } + + // Start Traefik + cmd, display := s.traefikCmd(withConfigFile("fixtures/access_log_config.toml")) + defer display(c) + err := cmd.Start() + c.Assert(err, checker.IsNil) + defer cmd.Process.Kill() + + defer os.Remove(traefikTestAccessLogFile) + defer os.Remove(traefikTestLogFile) + + checkStatsForLogFile(c) + + s.composeProject.Container(c, "digestAuthEntrypoint") + + waitForTraefik(c, "digestAuthEntrypoint") + + // Verify Traefik started OK + traefikLog := checkTraefikStarted(c) + + // Test auth entrypoint + req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1:8008/", nil) + c.Assert(err, checker.IsNil) + req.Host = "entrypoint.digest.auth.docker.local" + + resp, err := try.ResponseUntilStatusCode(req, 500*time.Millisecond, http.StatusUnauthorized) + c.Assert(err, checker.IsNil) + + digestParts := digestParts(resp) + digestParts["uri"] = "/" + digestParts["method"] = http.MethodGet + digestParts["username"] = "test" + digestParts["password"] = "test" + + req.Header.Set("Authorization", getDigestAuthorization(digestParts)) + req.Header.Set("Content-Type", "application/json") + + err = try.Request(req, 500*time.Millisecond, try.StatusCodeIs(http.StatusOK), try.HasBody()) + c.Assert(err, checker.IsNil) + + // Verify access.log output as expected + count := checkAccessLogExactValuesOutput(err, c, expected) + + c.Assert(count, checker.GreaterOrEqualThan, len(expected)) + + // Verify no other Traefik problems + checkNoOtherTraefikProblems(traefikLog, err, c) +} + +// Thanks to mvndaai for digest authentication +// https://stackoverflow.com/questions/39474284/how-do-you-do-a-http-post-with-digest-authentication-in-golang/39481441#39481441 +func digestParts(resp *http.Response) map[string]string { + result := map[string]string{} + if len(resp.Header["Www-Authenticate"]) > 0 { + wantedHeaders := []string{"nonce", "realm", "qop", "opaque"} + responseHeaders := strings.Split(resp.Header["Www-Authenticate"][0], ",") + for _, r := range responseHeaders { + for _, w := range wantedHeaders { + if strings.Contains(r, w) { + result[w] = strings.Split(r, `"`)[1] + } + } + } + } + return result +} + +func getMD5(data string) string { + digest := md5.New() + digest.Write([]byte(data)) + return fmt.Sprintf("%x", digest.Sum(nil)) +} + +func getCnonce() string { + b := make([]byte, 8) + io.ReadFull(rand.Reader, b) + return fmt.Sprintf("%x", b)[:16] +} + +func getDigestAuthorization(digestParts map[string]string) string { + d := digestParts + ha1 := getMD5(d["username"] + ":" + d["realm"] + ":" + d["password"]) + ha2 := getMD5(d["method"] + ":" + d["uri"]) + nonceCount := "00000001" + cnonce := getCnonce() + response := getMD5(fmt.Sprintf("%s:%s:%s:%s:%s:%s", ha1, d["nonce"], nonceCount, cnonce, d["qop"], ha2)) + authorization := fmt.Sprintf(`Digest username="%s", realm="%s", nonce="%s", uri="%s", cnonce="%s", nc=%s, qop=%s, response="%s", opaque="%s", algorithm="MD5"`, + d["username"], d["realm"], d["nonce"], d["uri"], cnonce, nonceCount, d["qop"], response, d["opaque"]) + return authorization +} + +func (s *AccessLogSuite) TestAccessLogEntrypointRedirect(c *check.C) { + ensureWorkingDirectoryIsClean() + expected := []accessLogValue{ { formatOnly: false, code: "302", + user: "-", value: "entrypoint redirect for frontend-", backendName: "-", }, @@ -237,13 +404,13 @@ func (s *AccessLogSuite) TestAccessLogEntrypointRedirect(c *check.C) { } func (s *AccessLogSuite) TestAccessLogFrontendRedirect(c *check.C) { - // Ensure working directory is clean ensureWorkingDirectoryIsClean() expected := []accessLogValue{ { formatOnly: false, code: "302", + user: "-", value: "frontend redirect for frontend-Path-", backendName: "-", }, @@ -289,7 +456,6 @@ func (s *AccessLogSuite) TestAccessLogFrontendRedirect(c *check.C) { } func (s *AccessLogSuite) TestAccessLogRateLimit(c *check.C) { - // Ensure working directory is clean ensureWorkingDirectoryIsClean() expected := []accessLogValue{ @@ -302,6 +468,7 @@ func (s *AccessLogSuite) TestAccessLogRateLimit(c *check.C) { { formatOnly: false, code: "429", + user: "-", value: "rate limit for frontend-Host-ratelimit", backendName: "/", }, @@ -348,13 +515,13 @@ func (s *AccessLogSuite) TestAccessLogRateLimit(c *check.C) { } func (s *AccessLogSuite) TestAccessLogBackendNotFound(c *check.C) { - // Ensure working directory is clean ensureWorkingDirectoryIsClean() expected := []accessLogValue{ { formatOnly: false, code: "404", + user: "-", value: "backend not found", backendName: "/", }, @@ -395,13 +562,13 @@ func (s *AccessLogSuite) TestAccessLogBackendNotFound(c *check.C) { } func (s *AccessLogSuite) TestAccessLogEntrypointWhitelist(c *check.C) { - // Ensure working directory is clean ensureWorkingDirectoryIsClean() expected := []accessLogValue{ { formatOnly: false, code: "403", + user: "-", value: "ipwhitelister for entrypoint httpWhitelistReject", backendName: "-", }, @@ -444,13 +611,13 @@ func (s *AccessLogSuite) TestAccessLogEntrypointWhitelist(c *check.C) { } func (s *AccessLogSuite) TestAccessLogFrontendWhitelist(c *check.C) { - // Ensure working directory is clean ensureWorkingDirectoryIsClean() expected := []accessLogValue{ { formatOnly: false, code: "403", + user: "-", value: "ipwhitelister for frontend-Host-frontend-whitelist", backendName: "-", }, @@ -578,10 +745,13 @@ func checkAccessLogExactValues(c *check.C, line string, i int, v accessLogValue) tokens, err := shellwords.Parse(line) c.Assert(err, checker.IsNil) c.Assert(tokens, checker.HasLen, 14) + if len(v.user) > 0 { + c.Assert(tokens[2], checker.Equals, v.user) + } c.Assert(tokens[6], checker.Equals, v.code) c.Assert(tokens[10], checker.Equals, fmt.Sprintf("%d", i+1)) c.Assert(tokens[11], checker.HasPrefix, v.value) - c.Assert(tokens[12], checker.Equals, v.backendName) + c.Assert(tokens[12], checker.HasPrefix, v.backendName) c.Assert(tokens[13], checker.Matches, `^\d+ms$`) } diff --git a/integration/fixtures/access_log_config.toml b/integration/fixtures/access_log_config.toml index 46b44ecf7..93947f0b8 100644 --- a/integration/fixtures/access_log_config.toml +++ b/integration/fixtures/access_log_config.toml @@ -1,15 +1,13 @@ -################################################################ -# Global configuration -################################################################ +logLevel = "ERROR" +defaultEntryPoints = ["http"] +checkNewVersion = false + [traefikLog] filePath = "traefik.log" [accessLog] filePath = "access.log" -logLevel = "ERROR" -defaultEntryPoints = ["http"] - [entryPoints] [entryPoints.http] address = ":8000" @@ -30,11 +28,13 @@ defaultEntryPoints = ["http"] address = ":8006" [entryPoints.httpRateLimit] address = ":8007" - -checkNewVersion = false + [entryPoints.digestAuth] + address = ":8008" + [entryPoints.digestAuth.auth.digest] + users = ["test:traefik:a2688e031edb4be6a3797f3882655c05", "test2:traefik:518845800f9e2bfb1f1f740ec24f074e"] [api] - dashboard = false + dashboard = true [docker] exposedByDefault = false diff --git a/integration/resources/compose/access_log.yml b/integration/resources/compose/access_log.yml index 4e51865e9..fad10bbab 100644 --- a/integration/resources/compose/access_log.yml +++ b/integration/resources/compose/access_log.yml @@ -51,6 +51,14 @@ authEntrypoint: - traefik.backend=backend3 - traefik.frontend.entryPoints=httpAuth - traefik.frontend.rule=Host:entrypoint.auth.docker.local +digestAuthEntrypoint: + image: emilevauge/whoami + labels: + - traefik.enable=true + - traefik.port=80 + - traefik.backend=backend3 + - traefik.frontend.entryPoints=digestAuth + - traefik.frontend.rule=Host:entrypoint.digest.auth.docker.local entrypointRedirect: image: emilevauge/whoami labels: diff --git a/middlewares/accesslog/logger.go b/middlewares/accesslog/logger.go index 8c27da6b6..620e66e6f 100644 --- a/middlewares/accesslog/logger.go +++ b/middlewares/accesslog/logger.go @@ -127,7 +127,6 @@ func (l *LogHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next h core[ClientAddr] = req.RemoteAddr core[ClientHost], core[ClientPort] = silentSplitHostPort(req.RemoteAddr) - core[ClientUsername] = usernameIfPresent(req.URL) if forwardedFor := req.Header.Get("X-Forwarded-For"); forwardedFor != "" { core[ClientHost] = forwardedFor @@ -137,6 +136,8 @@ func (l *LogHandler) ServeHTTP(rw http.ResponseWriter, req *http.Request, next h next.ServeHTTP(crw, reqWithDataTable) + core[ClientUsername] = usernameIfPresent(reqWithDataTable.URL) + logDataTable.DownstreamResponse = crw.Header() l.logTheRoundTrip(logDataTable, crr, crw) } diff --git a/middlewares/auth/authenticator.go b/middlewares/auth/authenticator.go index 56f47c3d9..f627f53fe 100644 --- a/middlewares/auth/authenticator.go +++ b/middlewares/auth/authenticator.go @@ -4,6 +4,7 @@ import ( "fmt" "io/ioutil" "net/http" + "net/url" "strings" goauth "github.com/abbot/go-http-auth" @@ -76,6 +77,7 @@ func createAuthDigestHandler(digestAuth *goauth.DigestAuth, authConfig *types.Au digestAuth.RequireAuth(w, r) } else { log.Debugf("Digest auth succeeded") + r.URL.User = url.User(username) if authConfig.HeaderField != "" { r.Header[authConfig.HeaderField] = []string{username} } @@ -89,10 +91,11 @@ func createAuthBasicHandler(basicAuth *goauth.BasicAuth, authConfig *types.Auth) log.Debugf("Basic auth failed") basicAuth.RequireAuth(w, r) } else { + log.Debugf("Basic auth succeeded") + r.URL.User = url.User(username) if authConfig.HeaderField != "" { r.Header[authConfig.HeaderField] = []string{username} } - log.Debugf("Basic auth succeeded") next.ServeHTTP(w, r) } })