Use ptutil for safelog and prometheus rounded metrics

* Related: #40354
This commit is contained in:
meskio 2024-05-09 11:42:56 +02:00
parent 7bd3e31d7e
commit a9df5dd71a
No known key found for this signature in database
GPG key ID: 52B8F5AC97A2DA86
12 changed files with 35 additions and 380 deletions

View file

@ -5,7 +5,7 @@ import (
"time"
"github.com/pion/webrtc/v3"
"gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/v2/common/safelog"
"gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/ptutil/safelog"
)
type SnowflakeEvent interface {

View file

@ -1,83 +0,0 @@
//Package for a safer logging wrapper around the standard logging package
// import "gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/v2/common/safelog"
package safelog
import (
"bytes"
"io"
"regexp"
"sync"
)
const ipv4Address = `\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}`
// %3A and %3a are for matching : in URL-encoded IPv6 addresses
const colon = `(:|%3a|%3A)`
const ipv6Address = `([0-9a-fA-F]{0,4}` + colon + `){5,7}([0-9a-fA-F]{0,4})?`
const ipv6Compressed = `([0-9a-fA-F]{0,4}` + colon + `){0,5}([0-9a-fA-F]{0,4})?(` + colon + `){2}([0-9a-fA-F]{0,4}` + colon + `){0,5}([0-9a-fA-F]{0,4})?`
const ipv6Full = `(` + ipv6Address + `(` + ipv4Address + `))` +
`|(` + ipv6Compressed + `(` + ipv4Address + `))` +
`|(` + ipv6Address + `)` + `|(` + ipv6Compressed + `)`
const optionalPort = `(:\d{1,5})?`
const addressPattern = `((` + ipv4Address + `)|(\[(` + ipv6Full + `)\])|(` + ipv6Full + `))` + optionalPort
const fullAddrPattern = `(?:^|\s|[^\w:])(` + addressPattern + `)(?:\s|(:\s)|[^\w:]|$)`
var scrubberPatterns = []*regexp.Regexp{
regexp.MustCompile(fullAddrPattern),
}
var addressRegexp = regexp.MustCompile(addressPattern)
// An io.Writer that can be used as the output for a logger that first
// sanitizes logs and then writes to the provided io.Writer
type LogScrubber struct {
Output io.Writer
buffer []byte
lock sync.Mutex
}
func (ls *LogScrubber) Lock() { (*ls).lock.Lock() }
func (ls *LogScrubber) Unlock() { (*ls).lock.Unlock() }
func Scrub(b []byte) []byte {
scrubbedBytes := b
for _, pattern := range scrubberPatterns {
// this is a workaround since go does not yet support look ahead or look
// behind for regular expressions.
var newBytes []byte
index := 0
for {
loc := pattern.FindSubmatchIndex(scrubbedBytes[index:])
if loc == nil {
break
}
newBytes = append(newBytes, scrubbedBytes[index:index+loc[2]]...)
newBytes = append(newBytes, []byte("[scrubbed]")...)
index = index + loc[3]
}
scrubbedBytes = append(newBytes, scrubbedBytes[index:]...)
}
return scrubbedBytes
}
func (ls *LogScrubber) Write(b []byte) (n int, err error) {
ls.Lock()
defer ls.Unlock()
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:]
}
}

View file

@ -1,183 +0,0 @@
package safelog
import (
"bytes"
"log"
"testing"
)
// 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]: 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)
}
}
// Test the log scrubber on known problematic log messages
func TestLogScrubberMessages(t *testing.T) {
for _, test := range []struct {
input, expected string
}{
{
"http: TLS handshake error from 129.97.208.23:38310: ",
"http: TLS handshake error from [scrubbed]: \n",
},
{
"http2: panic serving [2620:101:f000:780:9097:75b1:519f:dbb8]:58344: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack",
"http2: panic serving [scrubbed]: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack\n",
},
{
//Make sure it doesn't scrub fingerprint
"a=fingerprint:sha-256 33:B6:FA:F6:94:CA:74:61:45:4A:D2:1F:2C:2F:75:8A:D9:EB:23:34:B2:30:E9:1B:2A:A6:A9:E0:44:72:CC:74",
"a=fingerprint:sha-256 33:B6:FA:F6:94:CA:74:61:45:4A:D2:1F:2C:2F:75:8A:D9:EB:23:34:B2:30:E9:1B:2A:A6:A9:E0:44:72:CC:74\n",
},
{
//try with enclosing parens
"(1:2:3:4:c:d:e:f) {1:2:3:4:c:d:e:f}",
"([scrubbed]) {[scrubbed]}\n",
},
{
//Make sure it doesn't scrub timestamps
"2019/05/08 15:37:31 starting",
"2019/05/08 15:37:31 starting\n",
},
{
//Make sure ipv6 addresses where : are encoded as %3A or %3a are scrubbed
"error dialing relay: wss://snowflake.torproject.net/?client_ip=6201%3ac8%3A3004%3A%3A1234",
"error dialing relay: wss://snowflake.torproject.net/?client_ip=[scrubbed]\n",
},
{
// make sure url encoded IPv6 IPs get scrubbed (%3a)
"http2: panic serving [fd00%3a111%3af000%3a777%3a9999%3abbbb%3affff%3adddd]:58344: xxx",
"http2: panic serving [scrubbed]: xxx\n",
},
{
// make sure url encoded IPv6 IPs get scrubbed (%3A)
"http2: panic serving [fd00%3a111%3af000%3a777%3a9999%3abbbb%3affff%3adddd]:58344: xxx",
"http2: panic serving [scrubbed]: xxx\n",
},
{
// make sure url encoded IPv6 IPs get scrubbed, different URL (%3A)
"error dialing relay: wss://snowflake.torproject.net/?client_ip=fd00%3A8888%3Abbbb%3Acccc%3Adddd%3Aeeee%3A2222%3A123 = dial tcp xxx",
"error dialing relay: wss://snowflake.torproject.net/?client_ip=[scrubbed] = dial tcp xxx\n",
},
{
// make sure url encoded IPv6 IPs get scrubbed (%3A), compressed
"http2: panic serving [1%3A2%3A3%3A%3Ad%3Ae%3Af]:55: xxx",
"http2: panic serving [scrubbed]: xxx\n",
},
{
// make sure url encoded IPv6 IPs get scrubbed (%3A), compressed
"error dialing relay: wss://snowflake.torproject.net/?client_ip=1%3A2%3A3%3A%3Ad%3Ae%3Af = dial tcp xxx",
"error dialing relay: wss://snowflake.torproject.net/?client_ip=[scrubbed] = dial tcp xxx\n",
},
{
// multiple space-separated IP addresses
"Allowed stations: [10.0.1.1 10.0.1.2 10.0.1.3 10.0.1.4]\n",
"Allowed stations: [[scrubbed] [scrubbed] [scrubbed] [scrubbed]]\n",
},
} {
var buff bytes.Buffer
log.SetFlags(0) //remove all extra log output for test comparisons
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)
}
}
}
func TestLogScrubberGoodFormats(t *testing.T) {
for _, addr := range []string{
// IPv4
"1.2.3.4",
"255.255.255.255",
// IPv4 with port
"1.2.3.4:55",
"255.255.255.255:65535",
// IPv6
"1:2:3:4:c:d:e:f",
"1111:2222:3333:4444:CCCC:DDDD:EEEE:FFFF",
// IPv6 with brackets
"[1:2:3:4:c:d:e:f]",
"[1111:2222:3333:4444:CCCC:DDDD:EEEE:FFFF]",
// IPv6 with brackets and port
"[1:2:3:4:c:d:e:f]:55",
"[1111:2222:3333:4444:CCCC:DDDD:EEEE:FFFF]:65535",
// compressed IPv6
"::f",
"::d:e:f",
"1:2:3::",
"1:2:3::d:e:f",
"1:2:3:d:e:f::",
"::1:2:3:d:e:f",
"1111:2222:3333::DDDD:EEEE:FFFF",
// compressed IPv6 with brackets
"[::d:e:f]",
"[1:2:3::]",
"[1:2:3::d:e:f]",
"[1111:2222:3333::DDDD:EEEE:FFFF]",
"[1:2:3:4:5:6::8]",
"[1::7:8]",
// compressed IPv6 with brackets and port
"[1::]:58344",
"[::d:e:f]:55",
"[1:2:3::]:55",
"[1:2:3::d:e:f]:55",
"[1111:2222:3333::DDDD:EEEE:FFFF]:65535",
// IPv4-compatible and IPv4-mapped
"::255.255.255.255",
"::ffff:255.255.255.255",
"[::255.255.255.255]",
"[::ffff:255.255.255.255]",
"[::255.255.255.255]:65535",
"[::ffff:255.255.255.255]:65535",
"[::ffff:0:255.255.255.255]",
"[2001:db8:3:4::192.0.2.33]",
} {
var buff bytes.Buffer
log.SetFlags(0) //remove all extra log output for test comparisons
log.SetOutput(&LogScrubber{Output: &buff})
log.Print(addr)
if buff.String() != "[scrubbed]\n" {
t.Errorf("%q: Got %q, expected %q", addr, buff.String(), "[scrubbed]\n")
}
}
}