Commit 8ca069af authored by Nick Thomas's avatar Nick Thomas

Merge branch '71-hide-query-string' into 'master'

Filter query-string secrets out of logged URLs

See merge request !165
parents 221b11d7 00fffebd
...@@ -11,12 +11,15 @@ import ( ...@@ -11,12 +11,15 @@ import (
"net/url" "net/url"
"os" "os"
"os/exec" "os/exec"
"regexp"
"strings" "strings"
"syscall" "syscall"
) )
const NginxResponseBufferHeader = "X-Accel-Buffering" const NginxResponseBufferHeader = "X-Accel-Buffering"
var scrubRegexp = regexp.MustCompile(`([\?&](?:private|authenticity|rss)[\-_]token)=[^&]*`)
func Fail500(w http.ResponseWriter, r *http.Request, err error) { func Fail500(w http.ResponseWriter, r *http.Request, err error) {
http.Error(w, "Internal server error", 500) http.Error(w, "Internal server error", 500)
if err != nil { if err != nil {
...@@ -42,7 +45,7 @@ func RequestEntityTooLarge(w http.ResponseWriter, r *http.Request, err error) { ...@@ -42,7 +45,7 @@ func RequestEntityTooLarge(w http.ResponseWriter, r *http.Request, err error) {
func printError(r *http.Request, err error) { func printError(r *http.Request, err error) {
if r != nil { if r != nil {
log.Printf("error: %s %q: %v", r.Method, r.RequestURI, err) log.Printf("error: %s %q: %v", r.Method, ScrubURLParams(r.RequestURI), err)
} else { } else {
log.Printf("error: %v", err) log.Printf("error: %v", err)
} }
...@@ -188,3 +191,9 @@ func CloneRequestWithNewBody(r *http.Request, body []byte) *http.Request { ...@@ -188,3 +191,9 @@ func CloneRequestWithNewBody(r *http.Request, body []byte) *http.Request {
newReq.ContentLength = int64(len(body)) newReq.ContentLength = int64(len(body))
return &newReq return &newReq
} }
// ScrubURLParams replaces the content of any sensitive query string parameters
// in an URL with `[FILTERED]`
func ScrubURLParams(url string) string {
return scrubRegexp.ReplaceAllString(url, "$1=[FILTERED]")
}
...@@ -110,3 +110,25 @@ func TestFail500WorksWithNils(t *testing.T) { ...@@ -110,3 +110,25 @@ func TestFail500WorksWithNils(t *testing.T) {
assert.Equal(t, http.StatusInternalServerError, w.Code) assert.Equal(t, http.StatusInternalServerError, w.Code)
assert.Equal(t, "Internal server error\n", body.String()) assert.Equal(t, "Internal server error\n", body.String())
} }
func TestScrubURLParams(t *testing.T) {
for before, expected := range map[string]string{
"http://example.com": "http://example.com",
"http://example.com?foo=1": "http://example.com?foo=1",
"http://example.com?authenticity_token=1": "http://example.com?authenticity_token=[FILTERED]",
"http://example.com?private_token=1": "http://example.com?private_token=[FILTERED]",
"http://example.com?rss_token=1": "http://example.com?rss_token=[FILTERED]",
"http://example.com?foo&authenticity_token=blahblah&bar": "http://example.com?foo&authenticity_token=[FILTERED]&bar",
"http://example.com?private-token=1": "http://example.com?private-token=[FILTERED]",
"http://example.com?foo&private-token=blahblah&bar": "http://example.com?foo&private-token=[FILTERED]&bar",
"http://example.com?private-token=foo&authenticity_token=bar": "http://example.com?private-token=[FILTERED]&authenticity_token=[FILTERED]",
"https://example.com:8080?private-token=foo&authenticity_token=bar": "https://example.com:8080?private-token=[FILTERED]&authenticity_token=[FILTERED]",
"/?private-token=foo&authenticity_token=bar": "/?private-token=[FILTERED]&authenticity_token=[FILTERED]",
"?private-token=&authenticity_token=&bar": "?private-token=[FILTERED]&authenticity_token=[FILTERED]&bar",
"?private-token=foo&authenticity_token=bar": "?private-token=[FILTERED]&authenticity_token=[FILTERED]",
"?private_token=foo&authenticity-token=bar": "?private_token=[FILTERED]&authenticity-token=[FILTERED]",
} {
after := ScrubURLParams(before)
assert.Equal(t, expected, after, "Scrubbing %q", before)
}
}
...@@ -109,8 +109,8 @@ func (l *loggingResponseWriter) Log(r *http.Request) { ...@@ -109,8 +109,8 @@ func (l *loggingResponseWriter) Log(r *http.Request) {
duration := time.Since(l.started) duration := time.Since(l.started)
responseLogger.Printf("%s %s - - [%s] %q %d %d %q %q %f\n", responseLogger.Printf("%s %s - - [%s] %q %d %d %q %q %f\n",
r.Host, r.RemoteAddr, l.started, r.Host, r.RemoteAddr, l.started,
fmt.Sprintf("%s %s %s", r.Method, r.RequestURI, r.Proto), fmt.Sprintf("%s %s %s", r.Method, ScrubURLParams(r.RequestURI), r.Proto),
l.status, l.written, r.Referer(), r.UserAgent(), duration.Seconds(), l.status, l.written, ScrubURLParams(r.Referer()), r.UserAgent(), duration.Seconds(),
) )
sessionsActive.Dec() sessionsActive.Dec()
......
...@@ -104,7 +104,7 @@ func (s *sendFileResponseWriter) WriteHeader(status int) { ...@@ -104,7 +104,7 @@ func (s *sendFileResponseWriter) WriteHeader(status int) {
} }
func sendFileFromDisk(w http.ResponseWriter, r *http.Request, file string) { func sendFileFromDisk(w http.ResponseWriter, r *http.Request, file string) {
log.Printf("Send file %q for %s %q", file, r.Method, r.RequestURI) log.Printf("Send file %q for %s %q", file, r.Method, helper.ScrubURLParams(r.RequestURI))
content, fi, err := helper.OpenFile(file) content, fi, err := helper.OpenFile(file)
if err != nil { if err != nil {
http.NotFound(w, r) http.NotFound(w, r)
......
...@@ -70,7 +70,7 @@ func (s *Static) ServeExisting(prefix urlprefix.Prefix, cache CacheMode, notFoun ...@@ -70,7 +70,7 @@ func (s *Static) ServeExisting(prefix urlprefix.Prefix, cache CacheMode, notFoun
w.Header().Set("Expires", cacheUntil) w.Header().Set("Expires", cacheUntil)
} }
log.Printf("Send static file %q (%q) for %s %q", file, w.Header().Get("Content-Encoding"), r.Method, r.RequestURI) log.Printf("Send static file %q (%q) for %s %q", file, w.Header().Get("Content-Encoding"), r.Method, helper.ScrubURLParams(r.RequestURI))
http.ServeContent(w, r, filepath.Base(file), fi.ModTime(), content) http.ServeContent(w, r, filepath.Base(file), fi.ModTime(), content)
}) })
} }
...@@ -468,6 +468,67 @@ func TestAPIFalsePositivesAreProxied(t *testing.T) { ...@@ -468,6 +468,67 @@ func TestAPIFalsePositivesAreProxied(t *testing.T) {
} }
} }
func TestQueryStringLogFiltering(t *testing.T) {
// capture the log output
buf := bytes.NewBuffer(nil)
log.SetOutput(buf)
helper.SetCustomResponseLogger(buf)
defer log.SetOutput(os.Stderr)
defer helper.SetCustomResponseLogger(os.Stderr)
ts := testhelper.TestServerWithHandler(regexp.MustCompile(`.`), func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(200)
})
defer ts.Close()
ws := startWorkhorseServer(ts.URL)
defer ws.Close()
for _, path := range []string{
"",
"/",
} {
for _, queryString := range []string{
"private-token=should_be_filtered",
"authenticity-token=should_be_filtered",
"rss-token=should_be_filtered",
"private_token=should_be_filtered",
"authenticity_token=should_be_filtered",
"rss-token=should_be_filtered",
"private-token=should_be_filtered&authenticity-token=should_be_filtered",
"private_token=should_be_filtered&authenticity_token=should_be_filtered",
} {
resource := path + "?" + queryString
// Ensure the Referer is scrubbed too
req, err := http.NewRequest("GET", ws.URL+resource, nil)
if !assert.NoError(t, err, "GET %q: %v", resource, err) {
continue
}
req.Header.Set("Referer", "http://referer.example.com"+resource)
resp, err := http.DefaultClient.Do(req)
if !assert.NoError(t, err, "GET %q: %v", resource, err) {
continue
}
resp.Body.Close()
assert.Equal(t, 200, resp.StatusCode, "GET %q: status code", resource)
logged := buf.String()
buf.Reset()
assert.NotEqual(t, 0, len(logged), "GET %q: log is empty", resource)
assert.Contains(t, logged, path, "GET %q: path not logged", resource)
assert.Contains(t, logged, "referer", "GET %q: referer not logged", resource)
assert.NotContains(t, logged, "should_be_filtered", "GET %q: log not filtered correctly", resource)
}
}
}
func setupStaticFile(fpath, content string) error { func setupStaticFile(fpath, content string) error {
cwd, err := os.Getwd() cwd, err := os.Getwd()
if err != nil { if err != nil {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment