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

executor: make the format of user and host fields in slow logs be compatible with MySQL #18162

Merged
merged 9 commits into from
Jul 6, 2020
Merged
Show file tree
Hide file tree
Changes from 2 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
24 changes: 19 additions & 5 deletions executor/slow_query.go
Original file line number Diff line number Diff line change
Expand Up @@ -231,6 +231,17 @@ func (e *slowQueryRetriever) parseSlowLog(ctx sessionctx.Context, reader *bufio.
line = line[len(variable.SlowLogRowPrefixStr):]
if strings.HasPrefix(line, variable.SlowLogPrevStmtPrefix) {
st.prevStmt = line[len(variable.SlowLogPrevStmtPrefix):]
} else if strings.HasPrefix(line, variable.SlowLogUserAndHostStr+variable.SlowLogSpaceMarkStr) {
// the user and hostname field has a special format, for example, # User@Host: root[root] @ localhost [127.0.0.1]
value := line[len(variable.SlowLogUserAndHostStr+variable.SlowLogSpaceMarkStr):]
valid, err := st.setFieldValue(tz, variable.SlowLogUserAndHostStr, value, e.fileLine, e.checker)
if err != nil {
ctx.GetSessionVars().StmtCtx.AppendWarning(err)
continue
}
if !valid {
startFlag = false
}
} else {
fieldValues := strings.Split(line, " ")
for i := 0; i < len(fieldValues)-1; i += 2 {
Expand Down Expand Up @@ -373,13 +384,16 @@ func (st *slowQueryTuple) setFieldValue(tz *time.Location, field, value string,
}
case variable.SlowLogTxnStartTSStr:
st.txnStartTs, err = strconv.ParseUint(value, 10, 64)
case variable.SlowLogUserStr:
qw4990 marked this conversation as resolved.
Show resolved Hide resolved
case variable.SlowLogUserAndHostStr:
// root[root] @ localhost [127.0.0.1]
fields := strings.SplitN(value, "@", 2)
if len(field) > 0 {
st.user = fields[0]
if len(fields) > 0 {
tmp := strings.Split(fields[0], "[")
st.user = strings.TrimSpace(tmp[0])
}
if len(field) > 1 {
st.host = fields[1]
if len(fields) > 1 {
tmp := strings.Split(fields[1], "[")
st.host = strings.TrimSpace(tmp[0])
}
if checker != nil {
valid = checker.hasPrivilege(st.user)
Expand Down
3 changes: 2 additions & 1 deletion executor/slow_query_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,7 @@ func (s *testExecSuite) TestParseSlowLogFile(c *C) {
slowLogStr :=
`# Time: 2019-04-28T15:24:04.309074+08:00
# Txn_start_ts: 405888132465033227
# User@Host: root[root] @ localhost [127.0.0.1]
# Query_time: 0.216905
# Cop_time: 0.38 Process_time: 0.021 Request_count: 1 Total_keys: 637 Processed_keys: 436
# Is_internal: true
Expand Down Expand Up @@ -77,7 +78,7 @@ select * from t;`
}
recordString += str
}
expectRecordString := "2019-04-28 15:24:04.309074,405888132465033227,,,0,0.216905,0,0,0,0,0,0,0,0,0,0,0,0,,0,0,0,0,0,0,0.38,0.021,0,0,0,1,637,0,,,1,42a1c8aae6f133e934d4bf0147491709a8812ea05ff8819ec522780fe657b772,t1:1,t2:2,0.1,0.2,0.03,127.0.0.1:20160,0.05,0.6,0.8,0.0.0.0:20160,70724,65536,0,1,,60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4,update t set i = 1;,select * from t;"
expectRecordString := "2019-04-28 15:24:04.309074,405888132465033227,root,localhost,0,0.216905,0,0,0,0,0,0,0,0,0,0,0,0,,0,0,0,0,0,0,0.38,0.021,0,0,0,1,637,0,,,1,42a1c8aae6f133e934d4bf0147491709a8812ea05ff8819ec522780fe657b772,t1:1,t2:2,0.1,0.2,0.03,127.0.0.1:20160,0.05,0.6,0.8,0.0.0.0:20160,70724,65536,0,1,,60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4,update t set i = 1;,select * from t;"
c.Assert(expectRecordString, Equals, recordString)

// fix sql contain '# ' bug
Expand Down
6 changes: 2 additions & 4 deletions server/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -365,8 +365,8 @@ func (s *Server) Close() {
func (s *Server) onConn(conn *clientConn) {
ctx := logutil.WithConnID(context.Background(), conn.connectionID)
if err := conn.handshake(ctx); err != nil {
conn.ctx.GetSessionVars().ConnectionInfo = conn.connectInfo()
if plugin.IsEnable(plugin.Audit) && conn.ctx != nil {
conn.ctx.GetSessionVars().ConnectionInfo = conn.connectInfo()
err = plugin.ForeachPlugin(plugin.Audit, func(p *plugin.Plugin) error {
authPlugin := plugin.DeclareAuditManifest(p.Manifest)
if authPlugin.OnConnectionEvent != nil {
Expand Down Expand Up @@ -397,9 +397,7 @@ func (s *Server) onConn(conn *clientConn) {
metrics.ConnGauge.Set(float64(connections))

sessionVars := conn.ctx.GetSessionVars()
if plugin.IsEnable(plugin.Audit) {
sessionVars.ConnectionInfo = conn.connectInfo()
}
sessionVars.ConnectionInfo = conn.connectInfo()
err := plugin.ForeachPlugin(plugin.Audit, func(p *plugin.Plugin) error {
authPlugin := plugin.DeclareAuditManifest(p.Manifest)
if authPlugin.OnConnectionEvent != nil {
Expand Down
10 changes: 8 additions & 2 deletions sessionctx/variable/session.go
Original file line number Diff line number Diff line change
Expand Up @@ -1525,6 +1525,8 @@ const (
SlowLogStartPrefixStr = SlowLogRowPrefixStr + SlowLogTimeStr + SlowLogSpaceMarkStr
// SlowLogTxnStartTSStr is slow log field name.
SlowLogTxnStartTSStr = "Txn_start_ts"
// SlowLogUserAndHostStr is the user and host field name, which is compatible with MySQL.
SlowLogUserAndHostStr = "User@Host"
// SlowLogUserStr is slow log field name.
SlowLogUserStr = "User"
// SlowLogHostStr only for slow_query table usage.
Expand Down Expand Up @@ -1648,7 +1650,7 @@ type SlowQueryLogItems struct {
// The slow log output is like below:
// # Time: 2019-04-28T15:24:04.309074+08:00
// # Txn_start_ts: 406315658548871171
// # User: root@127.0.0.1
// # User@Host: root[root] @ localhost [127.0.0.1]
// # Conn_ID: 6
// # Query_time: 4.895492
// # Process_time: 0.161 Request_count: 1 Total_keys: 100001 Processed_keys: 100000
Expand All @@ -1670,7 +1672,11 @@ func (s *SessionVars) SlowLogFormat(logItems *SlowQueryLogItems) string {

writeSlowLogItem(&buf, SlowLogTxnStartTSStr, strconv.FormatUint(logItems.TxnTS, 10))
if s.User != nil {
writeSlowLogItem(&buf, SlowLogUserStr, s.User.String())
hostAddress := s.User.Hostname
if s.ConnectionInfo != nil {
hostAddress = s.ConnectionInfo.ClientIP
}
writeSlowLogItem(&buf, SlowLogUserAndHostStr, fmt.Sprintf("%s[%s] @ %s [%s]", s.User.Username, s.User.Username, s.User.Hostname, hostAddress))
}
if s.ConnectionID != 0 {
writeSlowLogItem(&buf, SlowLogConnIDStr, strconv.FormatUint(s.ConnectionID, 10))
Expand Down
3 changes: 2 additions & 1 deletion sessionctx/variable/session_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,7 @@ func (*testSessionSuite) TestSlowLogFormat(c *C) {
c.Assert(seVar, NotNil)

seVar.User = &auth.UserIdentity{Username: "root", Hostname: "192.168.0.1"}
seVar.ConnectionInfo = &variable.ConnectionInfo{ClientIP: "192.168.0.1"}
seVar.ConnectionID = 1
seVar.CurrentDB = "test"
seVar.InRestrictedSQL = true
Expand Down Expand Up @@ -175,7 +176,7 @@ func (*testSessionSuite) TestSlowLogFormat(c *C) {
var memMax int64 = 2333
var diskMax int64 = 6666
resultString := `# Txn_start_ts: 406649736972468225
# User: root@192.168.0.1
# User@Host: root[root] @ 192.168.0.1 [192.168.0.1]
# Conn_ID: 1
# Query_time: 1
# Parse_time: 0.00000001
Expand Down