Skip to content

Commit

Permalink
executor: make the format of user and host fields ... (#18162) (#18379)
Browse files Browse the repository at this point in the history
  • Loading branch information
ti-srebot authored Sep 2, 2020
1 parent 177c323 commit 1782af3
Show file tree
Hide file tree
Showing 5 changed files with 44 additions and 10 deletions.
26 changes: 26 additions & 0 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 @@ -369,6 +380,7 @@ func (st *slowQueryTuple) setFieldValue(tz *time.Location, field, value string,
case variable.SlowLogTxnStartTSStr:
st.txnStartTs, err = strconv.ParseUint(value, 10, 64)
case variable.SlowLogUserStr:
// the old User format is kept for compatibility
fields := strings.SplitN(value, "@", 2)
if len(field) > 0 {
st.user = fields[0]
Expand All @@ -379,6 +391,20 @@ func (st *slowQueryTuple) setFieldValue(tz *time.Location, field, value string,
if checker != nil {
valid = checker.hasPrivilege(st.user)
}
case variable.SlowLogUserAndHostStr:
// the new User&Host format: root[root] @ localhost [127.0.0.1]
fields := strings.SplitN(value, "@", 2)
if len(fields) > 0 {
tmp := strings.Split(fields[0], "[")
st.user = strings.TrimSpace(tmp[0])
}
if len(fields) > 1 {
tmp := strings.Split(fields[1], "[")
st.host = strings.TrimSpace(tmp[0])
}
if checker != nil {
valid = checker.hasPrivilege(st.user)
}
case variable.SlowLogConnIDStr:
st.connID, err = strconv.ParseUint(value, 10, 64)
case variable.SlowLogQueryTimeStr:
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.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.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
12 changes: 6 additions & 6 deletions infoschema/tables_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -531,7 +531,7 @@ func prepareSlowLogfile(c *C, slowLogFileName string) {
c.Assert(err, IsNil)
_, err = f.Write([]byte(`# Time: 2019-02-12T19:33:56.571953+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
# Parse_time: 0.4
Expand Down Expand Up @@ -620,10 +620,10 @@ func (s *testTableSuite) TestSlowQuery(c *C) {
tk.MustExec("set time_zone = '+08:00';")
re := tk.MustQuery("select * from information_schema.slow_query")
re.Check(testutil.RowsWithSep("|",
"2019-02-12 19:33:56.571953|406315658548871171|root|127.0.0.1|6|4.895492|0.4|0.2|0.19|0.21|0.01|0|0.18|[txnLock]|0.03|0|15|480|1|8|0.3824278|0.161|0.101|0.092|1.71|1|100001|100000|test||0|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|1|1|abcd|60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4|update t set i = 2;|select * from t_slim;"))
"2019-02-12 19:33:56.571953|406315658548871171|root|localhost|6|4.895492|0.4|0.2|0.19|0.21|0.01|0|0.18|[txnLock]|0.03|0|15|480|1|8|0.3824278|0.161|0.101|0.092|1.71|1|100001|100000|test||0|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|1|1|abcd|60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4|update t set i = 2;|select * from t_slim;"))
tk.MustExec("set time_zone = '+00:00';")
re = tk.MustQuery("select * from information_schema.slow_query")
re.Check(testutil.RowsWithSep("|", "2019-02-12 11:33:56.571953|406315658548871171|root|127.0.0.1|6|4.895492|0.4|0.2|0.19|0.21|0.01|0|0.18|[txnLock]|0.03|0|15|480|1|8|0.3824278|0.161|0.101|0.092|1.71|1|100001|100000|test||0|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|1|1|abcd|60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4|update t set i = 2;|select * from t_slim;"))
re.Check(testutil.RowsWithSep("|", "2019-02-12 11:33:56.571953|406315658548871171|root|localhost|6|4.895492|0.4|0.2|0.19|0.21|0.01|0|0.18|[txnLock]|0.03|0|15|480|1|8|0.3824278|0.161|0.101|0.092|1.71|1|100001|100000|test||0|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|1|1|abcd|60e9378c746d9a2be1c791047e008967cf252eb6de9167ad3aa6098fa2d523f4|update t set i = 2;|select * from t_slim;"))

// Test for long query.
f, err := os.OpenFile(slowLogFileName, os.O_CREATE|os.O_WRONLY, 0644)
Expand Down Expand Up @@ -811,13 +811,13 @@ func (s *testClusterTableSuite) TestSelectClusterTablePrivelege(c *C) {
c.Assert(err, IsNil)
_, err = f.Write([]byte(
`# Time: 2019-02-12T19:33:57.571953+08:00
# User: user2@127.0.0.1
# User@Host: user2 [user2] @ 127.0.0.1 [127.0.0.1]
select * from t2;
# Time: 2019-02-12T19:33:56.571953+08:00
# User: user1@127.0.0.1
# User@Host: user1 [user1] @ 127.0.0.1 [127.0.0.1]
select * from t1;
# Time: 2019-02-12T19:33:58.571953+08:00
# User: user2@127.0.0.1
# User@Host: user2 [user2] @ 127.0.0.1 [127.0.0.1]
select * from t3;
# Time: 2019-02-12T19:33:59.571953+08:00
select * from t3;
Expand Down
10 changes: 8 additions & 2 deletions sessionctx/variable/session.go
Original file line number Diff line number Diff line change
Expand Up @@ -1492,6 +1492,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 @@ -1602,7 +1604,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 @@ -1624,7 +1626,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

0 comments on commit 1782af3

Please sign in to comment.