diff --git a/go/streamlog/streamlog.go b/go/streamlog/streamlog.go index 6b9559694be..8717898df8b 100644 --- a/go/streamlog/streamlog.go +++ b/go/streamlog/streamlog.go @@ -25,6 +25,7 @@ import ( "net/url" "os" "os/signal" + "strings" "sync" "syscall" @@ -40,6 +41,9 @@ var ( // QueryLogFormat controls the format of the query log (either text or json) QueryLogFormat = flag.String("querylog-format", "text", "format for query logs (\"text\" or \"json\")") + // QueryLogFilterTag contains an optional string that must be present in the query for it to be logged + QueryLogFilterTag = flag.String("querylog-filter-tag", "", "string that must be present in the query for it to be logged") + sendCount = stats.NewCountersWithSingleLabel("StreamlogSend", "stream log send count", "logger_names") deliveredCount = stats.NewCountersWithMultiLabels( "StreamlogDelivered", @@ -201,3 +205,12 @@ func GetFormatter(logger *StreamLogger) LogFormatter { return fmter.Logf(w, params) } } + +// ShouldEmitLog returns whether the log with the given SQL query +// should be emitted or filtered +func ShouldEmitLog(sql string) bool { + if *QueryLogFilterTag == "" { + return true + } + return strings.Contains(sql, *QueryLogFilterTag) +} diff --git a/go/vt/vtgate/logstats.go b/go/vt/vtgate/logstats.go index 84042878be8..02b4d46b5b0 100644 --- a/go/vt/vtgate/logstats.go +++ b/go/vt/vtgate/logstats.go @@ -121,6 +121,10 @@ func (stats *LogStats) RemoteAddrUsername() (string, string) { // Logf formats the log record to the given writer, either as // tab-separated list of logged fields or as JSON. func (stats *LogStats) Logf(w io.Writer, params url.Values) error { + if !streamlog.ShouldEmitLog(stats.SQL) { + return nil + } + formattedBindVars := "\"[REDACTED]\"" if !*streamlog.RedactDebugUIQueries { _, fullBindParams := params["full"] diff --git a/go/vt/vtgate/logstats_test.go b/go/vt/vtgate/logstats_test.go index 01f5430e6d8..4720d5c7cfd 100644 --- a/go/vt/vtgate/logstats_test.go +++ b/go/vt/vtgate/logstats_test.go @@ -126,6 +126,35 @@ func TestLogStatsFormat(t *testing.T) { *streamlog.QueryLogFormat = "text" } +func TestLogStatsFilter(t *testing.T) { + defer func() { *streamlog.QueryLogFilterTag = "" }() + + logStats := NewLogStats(context.Background(), "test", "sql1 /* LOG_THIS_QUERY */", map[string]*querypb.BindVariable{"intVal": sqltypes.Int64BindVariable(1)}) + logStats.StartTime = time.Date(2017, time.January, 1, 1, 2, 3, 0, time.UTC) + logStats.EndTime = time.Date(2017, time.January, 1, 1, 2, 4, 1234, time.UTC) + params := map[string][]string{"full": {}} + + got := testFormat(logStats, url.Values(params)) + want := "test\t\t\t''\t''\t2017-01-01 01:02:03.000000\t2017-01-01 01:02:04.000001\t1.000001\t0.000000\t0.000000\t0.000000\t\t\"sql1 /* LOG_THIS_QUERY */\"\tmap[intVal:type:INT64 value:\"1\" ]\t0\t0\t\"\"\t\n" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } + + *streamlog.QueryLogFilterTag = "LOG_THIS_QUERY" + got = testFormat(logStats, url.Values(params)) + want = "test\t\t\t''\t''\t2017-01-01 01:02:03.000000\t2017-01-01 01:02:04.000001\t1.000001\t0.000000\t0.000000\t0.000000\t\t\"sql1 /* LOG_THIS_QUERY */\"\tmap[intVal:type:INT64 value:\"1\" ]\t0\t0\t\"\"\t\n" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } + + *streamlog.QueryLogFilterTag = "NOT_THIS_QUERY" + got = testFormat(logStats, url.Values(params)) + want = "" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } +} + func TestLogStatsContextHTML(t *testing.T) { html := "HtmlContext" callInfo := &fakecallinfo.FakeCallInfo{ diff --git a/go/vt/vtgate/querylogz_test.go b/go/vt/vtgate/querylogz_test.go index 1f0ede98bd6..65abb9b8642 100644 --- a/go/vt/vtgate/querylogz_test.go +++ b/go/vt/vtgate/querylogz_test.go @@ -26,6 +26,7 @@ import ( "time" "golang.org/x/net/context" + "vitess.io/vitess/go/streamlog" "vitess.io/vitess/go/vt/callerid" ) @@ -142,6 +143,17 @@ func TestQuerylogzHandlerFormatting(t *testing.T) { close(ch) body, _ = ioutil.ReadAll(response.Body) checkQuerylogzHasStats(t, slowQueryPattern, logStats, body) + + // ensure querylogz is not affected by the filter tag + *streamlog.QueryLogFilterTag = "XXX_SKIP_ME" + defer func() { *streamlog.QueryLogFilterTag = "" }() + ch = make(chan interface{}, 1) + ch <- logStats + querylogzHandler(ch, response, req) + close(ch) + body, _ = ioutil.ReadAll(response.Body) + checkQuerylogzHasStats(t, slowQueryPattern, logStats, body) + } func checkQuerylogzHasStats(t *testing.T, pattern []string, logStats *LogStats, page []byte) { diff --git a/go/vt/vttablet/tabletserver/querylogz_test.go b/go/vt/vttablet/tabletserver/querylogz_test.go index 199a4c969b7..d94f355eaa3 100644 --- a/go/vt/vttablet/tabletserver/querylogz_test.go +++ b/go/vt/vttablet/tabletserver/querylogz_test.go @@ -26,6 +26,7 @@ import ( "time" "golang.org/x/net/context" + "vitess.io/vitess/go/streamlog" "vitess.io/vitess/go/vt/callerid" "vitess.io/vitess/go/vt/vttablet/tabletserver/planbuilder" "vitess.io/vitess/go/vt/vttablet/tabletserver/tabletenv" @@ -148,6 +149,16 @@ func TestQuerylogzHandler(t *testing.T) { close(ch) body, _ = ioutil.ReadAll(response.Body) checkQuerylogzHasStats(t, slowQueryPattern, logStats, body) + + // ensure querylogz is not affected by the filter tag + *streamlog.QueryLogFilterTag = "XXX_SKIP_ME" + defer func() { *streamlog.QueryLogFilterTag = "" }() + ch = make(chan interface{}, 1) + ch <- logStats + querylogzHandler(ch, response, req) + close(ch) + body, _ = ioutil.ReadAll(response.Body) + checkQuerylogzHasStats(t, slowQueryPattern, logStats, body) } func checkQuerylogzHasStats(t *testing.T, pattern []string, logStats *tabletenv.LogStats, page []byte) { diff --git a/go/vt/vttablet/tabletserver/tabletenv/logstats.go b/go/vt/vttablet/tabletserver/tabletenv/logstats.go index a117668b33b..c8967c4596c 100644 --- a/go/vt/vttablet/tabletserver/tabletenv/logstats.go +++ b/go/vt/vttablet/tabletserver/tabletenv/logstats.go @@ -180,6 +180,10 @@ func (stats *LogStats) CallInfo() (string, string) { // Logf formats the log record to the given writer, either as // tab-separated list of logged fields or as JSON. func (stats *LogStats) Logf(w io.Writer, params url.Values) error { + if !streamlog.ShouldEmitLog(stats.OriginalSQL) { + return nil + } + rewrittenSQL := "[REDACTED]" formattedBindVars := "\"[REDACTED]\"" diff --git a/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go b/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go index 2bd62184a0d..9f5dbe05047 100644 --- a/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go +++ b/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go @@ -149,6 +149,41 @@ func TestLogStatsFormat(t *testing.T) { *streamlog.QueryLogFormat = "text" } +func TestLogStatsFilter(t *testing.T) { + defer func() { *streamlog.QueryLogFilterTag = "" }() + + logStats := NewLogStats(context.Background(), "test") + logStats.StartTime = time.Date(2017, time.January, 1, 1, 2, 3, 0, time.UTC) + logStats.EndTime = time.Date(2017, time.January, 1, 1, 2, 4, 1234, time.UTC) + logStats.OriginalSQL = "sql /* LOG_THIS_QUERY */" + logStats.BindVariables = map[string]*querypb.BindVariable{"intVal": sqltypes.Int64BindVariable(1)} + logStats.AddRewrittenSQL("sql with pii", time.Now()) + logStats.MysqlResponseTime = 0 + logStats.Rows = [][]sqltypes.Value{{sqltypes.NewVarBinary("a")}} + params := map[string][]string{"full": {}} + + got := testFormat(logStats, url.Values(params)) + want := "test\t\t\t''\t''\t2017-01-01 01:02:03.000000\t2017-01-01 01:02:04.000001\t1.000001\t\t\"sql /* LOG_THIS_QUERY */\"\tmap[intVal:type:INT64 value:\"1\" ]\t1\t\"sql with pii\"\tmysql\t0.000000\t0.000000\t0\t1\t\"\"\t\n" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } + + *streamlog.QueryLogFilterTag = "LOG_THIS_QUERY" + got = testFormat(logStats, url.Values(params)) + want = "test\t\t\t''\t''\t2017-01-01 01:02:03.000000\t2017-01-01 01:02:04.000001\t1.000001\t\t\"sql /* LOG_THIS_QUERY */\"\tmap[intVal:type:INT64 value:\"1\" ]\t1\t\"sql with pii\"\tmysql\t0.000000\t0.000000\t0\t1\t\"\"\t\n" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } + + *streamlog.QueryLogFilterTag = "NOT_THIS_QUERY" + got = testFormat(logStats, url.Values(params)) + want = "" + if got != want { + t.Errorf("logstats format: got:\n%q\nwant:\n%q\n", got, want) + } + +} + func TestLogStatsFormatQuerySources(t *testing.T) { logStats := NewLogStats(context.Background(), "test") if logStats.FmtQuerySources() != "none" {