Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

replace the logstats RemoteAddr with a more inclusive CallInfo #4422

Merged
merged 1 commit into from
Dec 16, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 6 additions & 3 deletions go/vt/callinfo/fakecallinfo/fakecallinfo.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
}

Expand All @@ -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.
Expand Down
12 changes: 6 additions & 6 deletions go/vt/vttablet/tabletserver/tabletenv/logstats.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -195,22 +195,22 @@ 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
switch *streamlog.QueryLogFormat {
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(),
Expand Down
22 changes: 12 additions & 10 deletions go/vt/vttablet/tabletserver/tabletenv/logstats_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)
}
Expand All @@ -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)
}
Expand Down Expand Up @@ -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)
}
Expand Down Expand Up @@ -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")
Expand All @@ -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)
Expand Down