commit c6a4a4191f2031abc744013d63f536612c37b512 Author: Cecylia Bocovich <cohosh@torproject.org> Date: Mon Mar 25 10:51:47 2019 -0400 Modified log scrubber to handle split lines Log scrubber now scrubs addresses even in the case where they are split across calls to the scrubber's output io.Writer. Added test cases to test that the writer behaves correctly across split lines. --- server/server.go | 24 +++++++++++++++++++++--- server/server_test.go | 47 +++++++++++++++++++++++++++++++++++++++++++++-- 2 files changed, 66 insertions(+), 5 deletions(-) diff --git a/server/server.go b/server/server.go index decfed4..539d0e1 100644 --- a/server/server.go +++ b/server/server.go @@ -3,6 +3,7 @@ package main import ( + "bytes" "crypto/tls" "errors" "flag" @@ -66,15 +67,32 @@ var scrubberPatterns = []*regexp.Regexp{ // sanitizes logs and then writes to the provided io.Writer type logScrubber struct { output io.Writer + buffer []byte } -func (ls *logScrubber) Write(b []byte) (n int, err error) { +func scrub(b []byte) []byte { scrubbedBytes := b for _, pattern := range scrubberPatterns { scrubbedBytes = pattern.ReplaceAll(scrubbedBytes, []byte("[scrubbed]")) } + return scrubbedBytes +} - return ls.output.Write(scrubbedBytes) +func (ls *logScrubber) Write(b []byte) (n int, err error) { + n = len(b) + ls.buffer = append(ls.buffer, b...) + for { + i := bytes.LastIndexByte(ls.buffer, '\n') + if i == -1 { + return + } + fullLines := ls.buffer[:i+1] + _, err = ls.output.Write(scrub(fullLines)) + if err != nil { + return + } + ls.buffer = ls.buffer[i+1:] + } } // An abstraction that makes an underlying WebSocket connection look like an @@ -308,7 +326,7 @@ func main() { logOutput = f } //We want to send the log output through our scrubber first - log.SetOutput(&logScrubber{logOutput}) + log.SetOutput(&logScrubber{output: logOutput}) if !disableTLS && acmeHostnamesCommas == "" { log.Fatal("the --acme-hostnames option is required") diff --git a/server/server_test.go b/server/server_test.go index cfe4653..846d95e 100644 --- a/server/server_test.go +++ b/server/server_test.go @@ -50,7 +50,50 @@ func TestClientAddr(t *testing.T) { } } -func TestLogScrubber(t *testing.T) { +//Check to make sure that addresses split across calls to write are still scrubbed +func TestLogScrubberSplit(t *testing.T) { + input := []byte("test\nhttp2: panic serving [2620:101:f000:780:9097:75b1:519f:dbb8]:58344: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack\n") + + expected := "test\nhttp2: panic serving [scrubbed]:58344: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack\n" + + var buff bytes.Buffer + scrubber := &logScrubber{output: &buff} + n, err := scrubber.Write(input[:12]) //test\nhttp2: + if n != 12 { + t.Errorf("wrong number of bytes %d", n) + } + if err != nil { + t.Errorf("%q", err) + } + if buff.String() != "test\n" { + t.Errorf("Got %q, expected %q", buff.String(), "test\n") + } + + n, err = scrubber.Write(input[12:30]) //panic serving [2620:101:f + if n != 18 { + t.Errorf("wrong number of bytes %d", n) + } + if err != nil { + t.Errorf("%q", err) + } + if buff.String() != "test\n" { + t.Errorf("Got %q, expected %q", buff.String(), "test\n") + } + + n, err = scrubber.Write(input[30:]) //000:780:9097:75b1:519f:dbb8]:58344: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack\n + if n != (len(input) - 30) { + t.Errorf("wrong number of bytes %d", n) + } + if err != nil { + t.Errorf("%q", err) + } + if buff.String() != expected { + t.Errorf("Got %q, expected %q", buff.String(), expected) + } + +} + +func TestLogScrubberFormats(t *testing.T) { for _, test := range []struct { input, expected string }{ @@ -98,7 +141,7 @@ func TestLogScrubber(t *testing.T) { } { var buff bytes.Buffer log.SetFlags(0) //remove all extra log output for test comparisons - log.SetOutput(&logScrubber{&buff}) + log.SetOutput(&logScrubber{output: &buff}) log.Print(test.input) if buff.String() != test.expected { t.Errorf("%q: got %q, expected %q", test.input, buff.String(), test.expected)