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.

Sign up for GitHub

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

infoschema/slow_query: fix token too long #10328

Merged
merged 18 commits into from
May 9, 2019
Merged

infoschema/slow_query: fix token too long #10328

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
18 commits
Select commit Hold shift + click to select a range
1664104
infoschema/slow_query: fix token too long
crazycs520 Apr 30, 2019
c9f0daf
fix ci
crazycs520 Apr 30, 2019
13919dc
use reader.ReadLine
crazycs520 Apr 30, 2019
c68b4da
use MaxOfMaxAllowedPacket to check single line limit
crazycs520 May 5, 2019
b4e610e
Merge branch 'master' of https://github.com/pingcap/tidb into fix-slo…
crazycs520 May 5, 2019
775be13
refine code
crazycs520 May 5, 2019
be791f4
fix bug
crazycs520 May 5, 2019
c0a67fa
fix ci
crazycs520 May 5, 2019
214a046
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 5, 2019
690d5dc
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 5, 2019
b5e905f
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 7, 2019
b6a6b6b
refine code
crazycs520 May 8, 2019
0f827ba
remove useless code
crazycs520 May 8, 2019
3481e69
Merge branch 'master' into fix-slow-log-token-too-long
eurekaka May 8, 2019
7b0528f
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 8, 2019
b44fafd
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 9, 2019
ef8efe7
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 9, 2019
077daf3
Merge branch 'master' into fix-slow-log-token-too-long
crazycs520 May 9, 2019
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
2 changes: 2 additions & 0 deletions config/config.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,8 @@ var (
CheckTableBeforeDrop = false
// checkBeforeDropLDFlag is a go build flag.
checkBeforeDropLDFlag = "None"
// QueryLogMaxLenRecord use to record the max value of QueryLogMaxLen.
QueryLogMaxLenRecord = uint64(logutil.DefaultQueryLogMaxLen)
)

// Config contains configuration options.
Expand Down
9 changes: 9 additions & 0 deletions executor/set_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,15 @@ package executor_test

import (
"context"
"fmt"
"sync/atomic"

. "github.com/pingcap/check"
"github.com/pingcap/parser/terror"
"github.com/pingcap/tidb/config"
"github.com/pingcap/tidb/sessionctx"
"github.com/pingcap/tidb/sessionctx/variable"
"github.com/pingcap/tidb/util/logutil"
"github.com/pingcap/tidb/util/testkit"
"github.com/pingcap/tidb/util/testutil"
)
Expand Down Expand Up @@ -272,8 +275,14 @@ func (s *testSuite2) TestSetVar(c *C) {

tk.MustExec("set tidb_query_log_max_len = 0")
tk.MustQuery("select @@session.tidb_query_log_max_len;").Check(testkit.Rows("0"))
c.Assert(atomic.LoadUint64(&config.QueryLogMaxLenRecord), Equals, uint64(logutil.DefaultQueryLogMaxLen))
tk.MustExec(fmt.Sprintf("set tidb_query_log_max_len = %v", logutil.DefaultQueryLogMaxLen+1))
tk.MustQuery("select @@session.tidb_query_log_max_len;").Check(testkit.Rows(fmt.Sprintf("%v", logutil.DefaultQueryLogMaxLen+1)))
c.Assert(atomic.LoadUint64(&config.QueryLogMaxLenRecord), Equals, uint64(logutil.DefaultQueryLogMaxLen+1))
tk.MustExec("set tidb_query_log_max_len = 20")
tk.MustQuery("select @@session.tidb_query_log_max_len;").Check(testkit.Rows("20"))
// QueryLogMaxLenRecord record the max len.
c.Assert(atomic.LoadUint64(&config.QueryLogMaxLenRecord), Equals, uint64(logutil.DefaultQueryLogMaxLen+1))
_, err = tk.Exec("set global tidb_query_log_max_len = 20")
c.Assert(err, NotNil)

Expand Down
12 changes: 11 additions & 1 deletion infoschema/slow_log.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,10 +19,13 @@ import (
"os"
"strconv"
"strings"
"sync/atomic"
"time"

"github.com/pingcap/errors"
"github.com/pingcap/parser/mysql"
"github.com/pingcap/parser/terror"
"github.com/pingcap/tidb/config"
"github.com/pingcap/tidb/sessionctx"
"github.com/pingcap/tidb/sessionctx/variable"
"github.com/pingcap/tidb/types"
Expand Down Expand Up @@ -77,7 +80,6 @@ func parseSlowLogFile(tz *time.Location, filePath string) ([][]types.Datum, erro
logutil.Logger(context.Background()).Error("close slow log file failed.", zap.String("file", filePath), zap.Error(err))
}
}()

return ParseSlowLog(tz, bufio.NewScanner(file))
}

Expand All @@ -88,6 +90,11 @@ func ParseSlowLog(tz *time.Location, scanner *bufio.Scanner) ([][]types.Datum, e
startFlag := false
var st *slowQueryTuple
var err error
// Adjust buffer size.
if atomic.LoadUint64(&config.QueryLogMaxLenRecord) > (bufio.MaxScanTokenSize - 100) {
maxBuf := int(atomic.LoadUint64(&config.QueryLogMaxLenRecord) + 100)
scanner.Buffer([]byte{}, maxBuf)
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use bufio.Reader.ReadLine to completely avoid this error?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can use ReadLine to implement a new scanner

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great idea. Other question, should we add a max-single-line-length-limit? If user executes a long query.

At first, I think if we don't limit the max-single-line-length, then parse slow log may consume a lot of memory and then may make TiDB-server killed by the system.

But after careful consideration, I think no need to add max-single-line-length, the first reason is we have log rotate, the other reason is executing the long query may make tidb-server killed in executing. 😂 What do you think? @eurekaka @winkyao

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

https://dev.mysql.com/doc/refman/5.7/en/server-system-variables.html#sysvar_max_allowed_packet should limit the input query size?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

done. PTAL @eurekaka @winkyao

for scanner.Scan() {
line := scanner.Text()
// Check slow log entry start flag.
Expand Down Expand Up @@ -128,6 +135,9 @@ func ParseSlowLog(tz *time.Location, scanner *bufio.Scanner) ([][]types.Datum, e
}
}
if err := scanner.Err(); err != nil {
if terror.ErrorEqual(err, bufio.ErrTooLong) {
err = errors.Errorf("read file buffer overflow, please try to enlarge the variable 'tidb_query_log_max_len'")
}
return nil, errors.AddStack(err)
}
return rows, nil
Expand Down
21 changes: 21 additions & 0 deletions infoschema/slow_log_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,9 +16,12 @@ package infoschema_test
import (
"bufio"
"bytes"
"strings"
"sync/atomic"
"time"

. "github.com/pingcap/check"
"github.com/pingcap/tidb/config"
"github.com/pingcap/tidb/infoschema"
"github.com/pingcap/tidb/util/logutil"
)
Expand Down Expand Up @@ -88,6 +91,24 @@ select * from t;
t1Str, err := rows[1][0].ToString()
c.Assert(err, IsNil)
c.Assert(t1Str, Equals, "2019-04-24 19:41:21.716221")

// test for bufio.Scanner: token too long.
slowLog = bytes.NewBufferString(
`# Time: 2019-04-28T15:24:04.309074+08:00
select * from t;
# Time: 2019-04-24-19:41:21.716221 +0800
`)
sql := strings.Repeat("x", bufio.MaxScanTokenSize)
slowLog.WriteString(sql)
scanner = bufio.NewScanner(slowLog)
_, err = infoschema.ParseSlowLog(loc, scanner)
c.Assert(err, NotNil)
c.Assert(err.Error(), Equals, "read file buffer overflow, please try to enlarge the variable 'tidb_query_log_max_len'")

atomic.StoreUint64(&config.QueryLogMaxLenRecord, bufio.MaxScanTokenSize)
scanner = bufio.NewScanner(slowLog)
_, err = infoschema.ParseSlowLog(loc, scanner)
c.Assert(err, IsNil)
}

func (s *testSuite) TestSlowLogParseTime(c *C) {
Expand Down
3 changes: 3 additions & 0 deletions sessionctx/variable/session.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -739,6 +739,9 @@ func (s *SessionVars) SetSystemVar(name string, val string) error {
atomic.StoreUint32(&DDLSlowOprThreshold, uint32(tidbOptPositiveInt32(val, DefTiDBDDLSlowOprThreshold)))
case TiDBQueryLogMaxLen:
atomic.StoreUint64(&config.GetGlobalConfig().Log.QueryLogMaxLen, uint64(tidbOptInt64(val, logutil.DefaultQueryLogMaxLen)))
if atomic.LoadUint64(&config.GetGlobalConfig().Log.QueryLogMaxLen) > atomic.LoadUint64(&config.QueryLogMaxLenRecord) {
atomic.StoreUint64(&config.QueryLogMaxLenRecord, atomic.LoadUint64(&config.GetGlobalConfig().Log.QueryLogMaxLen))
}
case TiDBRetryLimit:
s.RetryLimit = tidbOptInt64(val, DefTiDBRetryLimit)
case TiDBDisableTxnAutoRetry:
Expand Down