diff --git a/go/vt/callinfo/fakecallinfo/fakecallinfo.go b/go/vt/callinfo/fakecallinfo/fakecallinfo.go index d7eedf2fc5c..84a6df9f5d3 100644 --- a/go/vt/callinfo/fakecallinfo/fakecallinfo.go +++ b/go/vt/callinfo/fakecallinfo/fakecallinfo.go @@ -16,13 +16,16 @@ limitations under the License. package fakecallinfo -import "html/template" +import ( + "fmt" + "html/template" +) // FakeCallInfo gives a fake Callinfo usable in callinfo type FakeCallInfo struct { Remote string + Method string User string - Txt string Html string } @@ -38,7 +41,7 @@ func (fci *FakeCallInfo) Username() string { // Text returns the text. func (fci *FakeCallInfo) Text() string { - return fci.Txt + return fmt.Sprintf("%s:%s(fakeRPC)", fci.Remote, fci.Method) } // HTML returns the html. diff --git a/go/vt/vttablet/tabletserver/tabletenv/logstats.go b/go/vt/vttablet/tabletserver/tabletenv/logstats.go index d95cf046135..6e8323400c3 100644 --- a/go/vt/vttablet/tabletserver/tabletenv/logstats.go +++ b/go/vt/vttablet/tabletserver/tabletenv/logstats.go @@ -168,13 +168,13 @@ func (stats *LogStats) ErrorStr() string { return "" } -// RemoteAddrUsername returns some parts of CallInfo if set -func (stats *LogStats) RemoteAddrUsername() (string, string) { +// CallInfo returns some parts of CallInfo if set +func (stats *LogStats) CallInfo() (string, string) { ci, ok := callinfo.FromContext(stats.Ctx) if !ok { return "", "" } - return ci.RemoteAddr(), ci.Username() + return ci.Text(), ci.Username() } // Logf formats the log record to the given writer, either as @@ -195,7 +195,7 @@ func (stats *LogStats) Logf(w io.Writer, params url.Values) error { } // TODO: remove username here we fully enforce immediate caller id - remoteAddr, username := stats.RemoteAddrUsername() + callInfo, username := stats.CallInfo() // Valid options for the QueryLogFormat are text or json var fmtString string @@ -203,14 +203,14 @@ func (stats *LogStats) Logf(w io.Writer, params url.Values) error { case streamlog.QueryLogFormatText: fmtString = "%v\t%v\t%v\t'%v'\t'%v'\t%v\t%v\t%.6f\t%v\t%q\t%v\t%v\t%q\t%v\t%.6f\t%.6f\t%v\t%v\t%q\t\n" case streamlog.QueryLogFormatJSON: - fmtString = "{\"Method\": %q, \"RemoteAddr\": %q, \"Username\": %q, \"ImmediateCaller\": %q, \"Effective Caller\": %q, \"Start\": \"%v\", \"End\": \"%v\", \"TotalTime\": %.6f, \"PlanType\": %q, \"OriginalSQL\": %q, \"BindVars\": %v, \"Queries\": %v, \"RewrittenSQL\": %q, \"QuerySources\": %q, \"MysqlTime\": %.6f, \"ConnWaitTime\": %.6f, \"RowsAffected\": %v, \"ResponseSize\": %v, \"Error\": %q}\n" + fmtString = "{\"Method\": %q, \"CallInfo\": %q, \"Username\": %q, \"ImmediateCaller\": %q, \"Effective Caller\": %q, \"Start\": \"%v\", \"End\": \"%v\", \"TotalTime\": %.6f, \"PlanType\": %q, \"OriginalSQL\": %q, \"BindVars\": %v, \"Queries\": %v, \"RewrittenSQL\": %q, \"QuerySources\": %q, \"MysqlTime\": %.6f, \"ConnWaitTime\": %.6f, \"RowsAffected\": %v, \"ResponseSize\": %v, \"Error\": %q}\n" } _, err := fmt.Fprintf( w, fmtString, stats.Method, - remoteAddr, + callInfo, username, stats.ImmediateCaller(), stats.EffectiveCaller(), diff --git a/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go b/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go index 4b33f4fe424..2bd62184a0d 100644 --- a/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go +++ b/go/vt/vttablet/tabletserver/tabletenv/logstats_test.go @@ -97,7 +97,7 @@ func TestLogStatsFormat(t *testing.T) { if err != nil { t.Errorf("logstats format: error marshaling json: %v -- got:\n%v", err, got) } - want = "{\n \"BindVars\": {\n \"intVal\": {\n \"type\": \"INT64\",\n \"value\": 1\n }\n },\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"RemoteAddr\": \"\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"sql with pii\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" + want = "{\n \"BindVars\": {\n \"intVal\": {\n \"type\": \"INT64\",\n \"value\": 1\n }\n },\n \"CallInfo\": \"\",\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"sql with pii\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" if string(formatted) != want { t.Errorf("logstats format: got:\n%q\nwant:\n%v\n", string(formatted), want) } @@ -113,7 +113,7 @@ func TestLogStatsFormat(t *testing.T) { if err != nil { t.Errorf("logstats format: error marshaling json: %v -- got:\n%v", err, got) } - want = "{\n \"BindVars\": \"[REDACTED]\",\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"RemoteAddr\": \"\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"[REDACTED]\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" + want = "{\n \"BindVars\": \"[REDACTED]\",\n \"CallInfo\": \"\",\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"[REDACTED]\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" if string(formatted) != want { t.Errorf("logstats format: got:\n%q\nwant:\n%v\n", string(formatted), want) } @@ -141,7 +141,7 @@ func TestLogStatsFormat(t *testing.T) { if err != nil { t.Errorf("logstats format: error marshaling json: %v -- got:\n%v", err, got) } - want = "{\n \"BindVars\": {\n \"strVal\": {\n \"type\": \"VARCHAR\",\n \"value\": \"abc\"\n }\n },\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"RemoteAddr\": \"\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"sql with pii\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" + want = "{\n \"BindVars\": {\n \"strVal\": {\n \"type\": \"VARCHAR\",\n \"value\": \"abc\"\n }\n },\n \"CallInfo\": \"\",\n \"ConnWaitTime\": 0,\n \"Effective Caller\": \"\",\n \"End\": \"2017-01-01 01:02:04.000001\",\n \"Error\": \"\",\n \"ImmediateCaller\": \"\",\n \"Method\": \"test\",\n \"MysqlTime\": 0,\n \"OriginalSQL\": \"sql\",\n \"PlanType\": \"\",\n \"Queries\": 1,\n \"QuerySources\": \"mysql\",\n \"ResponseSize\": 1,\n \"RewrittenSQL\": \"sql with pii\",\n \"RowsAffected\": 0,\n \"Start\": \"2017-01-01 01:02:03.000000\",\n \"TotalTime\": 1.000001,\n \"Username\": \"\"\n}" if string(formatted) != want { t.Errorf("logstats format: got:\n%q\nwant:\n%v\n", string(formatted), want) } @@ -190,11 +190,11 @@ func TestLogStatsErrorStr(t *testing.T) { } } -func TestLogStatsRemoteAddrUsername(t *testing.T) { +func TestLogStatsCallInfo(t *testing.T) { logStats := NewLogStats(context.Background(), "test") - addr, user := logStats.RemoteAddrUsername() - if addr != "" { - t.Fatalf("remote addr should be empty") + caller, user := logStats.CallInfo() + if caller != "" { + t.Fatalf("caller should be empty") } if user != "" { t.Fatalf("username should be empty") @@ -204,13 +204,15 @@ func TestLogStatsRemoteAddrUsername(t *testing.T) { username := "vt" callInfo := &fakecallinfo.FakeCallInfo{ Remote: remoteAddr, + Method: "FakeExecute", User: username, } ctx := callinfo.NewContext(context.Background(), callInfo) logStats = NewLogStats(ctx, "test") - addr, user = logStats.RemoteAddrUsername() - if addr != remoteAddr { - t.Fatalf("expected to get remote addr: %s, but got: %s", remoteAddr, addr) + caller, user = logStats.CallInfo() + wantCaller := remoteAddr + ":FakeExecute(fakeRPC)" + if caller != wantCaller { + t.Fatalf("expected to get caller: %s, but got: %s", wantCaller, caller) } if user != username { t.Fatalf("expected to get username: %s, but got: %s", username, user)