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

session: let handleAssertionFailure work for partitioned table #40630

Merged
merged 5 commits into from
Feb 24, 2023
Merged

session: let handleAssertionFailure work for partitioned table #40630

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
a2cedc5
let handleAssertionFailure work for partitioned table
ekexium Jan 16, 2023
32be4f5
test: make logHook a public utility and use it in TestHandleAssertion…
ekexium Jan 16, 2023
5638294
comments for pub functions
ekexium Jan 17, 2023
55d7c0e
update bazel
ekexium Jan 17, 2023
9ff247e
Merge branch 'master' of github.com:pingcap/tidb into handle-assertio…
ekexium Feb 22, 2023
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
203 changes: 57 additions & 146 deletions executor/admin_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,14 +17,10 @@ package executor_test
import (
"context"
"fmt"
"os"
"strings"
"testing"
"time"

"github.com/pingcap/errors"
"github.com/pingcap/log"
"github.com/pingcap/tidb/config"
"github.com/pingcap/tidb/domain"
mysql "github.com/pingcap/tidb/errno"
"github.com/pingcap/tidb/kv"
Expand All @@ -39,12 +35,10 @@ import (
"github.com/pingcap/tidb/testkit/testutil"
"github.com/pingcap/tidb/types"
"github.com/pingcap/tidb/util/codec"
"github.com/pingcap/tidb/util/logutil"
"github.com/pingcap/tidb/util/logutil/consistency"
"github.com/pingcap/tidb/util/mock"
"github.com/stretchr/testify/require"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)

func TestAdminCheckIndexRange(t *testing.T) {
Expand Down Expand Up @@ -1181,89 +1175,6 @@ func (tk *inconsistencyTestKit) rebuild() {
tk.plainIndex = tables.NewIndex(tbl.Meta().ID, tbl.Meta(), tbl.Meta().Indices[1])
}

type logEntry struct {
entry zapcore.Entry
fields []zapcore.Field
}

func (l *logEntry) checkMsg(t *testing.T, msg string) {
require.Equal(t, msg, l.entry.Message)
}

func (l *logEntry) checkField(t *testing.T, requireFields ...zapcore.Field) {
for _, rf := range requireFields {
var f *zapcore.Field
for i, field := range l.fields {
if field.Equals(rf) {
f = &l.fields[i]
break
}
}
require.NotNilf(t, f, "matched log fields %s:%s not found in log", rf.Key, rf)
}
}

func (l *logEntry) checkFieldNotEmpty(t *testing.T, fieldName string) {
var f *zapcore.Field
for i, field := range l.fields {
if field.Key == fieldName {
f = &l.fields[i]
break
}
}
require.NotNilf(t, f, "log field %s not found in log", fieldName)
require.NotEmpty(t, f.String)
}

type logHook struct {
zapcore.Core
logs []logEntry
enc zapcore.Encoder
messageFilter string
}

func (h *logHook) Write(entry zapcore.Entry, fields []zapcore.Field) error {
h.logs = append(h.logs, logEntry{entry: entry, fields: fields})
return nil
}

func (h *logHook) Check(entry zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
if len(h.messageFilter) > 0 && !strings.Contains(entry.Message, h.messageFilter) {
return nil
}
return ce.AddCore(entry, h)
}

func (h *logHook) encode(entry *logEntry) (string, error) {
buffer, err := h.enc.EncodeEntry(entry.entry, entry.fields)
if err != nil {
return "", err
}
return buffer.String(), nil
}

func (h *logHook) checkLogCount(t *testing.T, expected int) {
logsStr := make([]string, len(h.logs))
for i, item := range h.logs {
var err error
logsStr[i], err = h.encode(&item)
require.NoError(t, err)
}
// Check the length of strings, so that in case the test fails, the error message will be printed.
require.Len(t, logsStr, expected)
}

func withLogHook(ctx context.Context, t *testing.T, msgFilter string) (newCtx context.Context, hook *logHook) {
conf := &log.Config{Level: os.Getenv("log_level"), File: log.FileLogConfig{}}
_, r, _ := log.InitLogger(conf)
enc, err := log.NewTextEncoder(&config.GetGlobalConfig().Log.ToLogConfig().Config)
require.NoError(t, err)
hook = &logHook{r.Core, nil, enc, msgFilter}
logger := zap.New(hook)
newCtx = context.WithValue(ctx, logutil.CtxLogKey, logger)
return
}

func TestCheckFailReport(t *testing.T) {
store := testkit.CreateMockStore(t)
tk := newInconsistencyKit(t, testkit.NewAsyncTestKit(t, store), newDefaultOpt())
Expand All @@ -1278,16 +1189,16 @@ func TestCheckFailReport(t *testing.T) {
require.NoError(t, tk.uniqueIndex.Delete(tk.sctx, txn, types.MakeDatums(1), kv.IntHandle(1)))
require.NoError(t, txn.Commit(tk.ctx))

ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test", "[admin:8223]data inconsistency in table: admin_test, index: uk1, handle: 1, index-values:\"\" != record-values:\"handle: 1, values: [KindInt64 1]\"")
hook.checkLogCount(t, 1)
hook.logs[0].checkMsg(t, "admin check found data inconsistency")
hook.logs[0].checkField(t,
hook.CheckLogCount(t, 1)
hook.Logs[0].CheckMsg(t, "admin check found data inconsistency")
hook.Logs[0].CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "uk1"),
zap.Stringer("row_id", kv.IntHandle(1)),
)
hook.logs[0].checkFieldNotEmpty(t, "row_mvcc")
hook.Logs[0].CheckFieldNotEmpty(t, "row_mvcc")
}()

// row more than plain index
Expand All @@ -1300,16 +1211,16 @@ func TestCheckFailReport(t *testing.T) {
require.NoError(t, tk.plainIndex.Delete(tk.sctx, txn, []types.Datum{types.NewStringDatum("10")}, kv.IntHandle(1)))
require.NoError(t, txn.Commit(tk.ctx))

ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test", "[admin:8223]data inconsistency in table: admin_test, index: k2, handle: 1, index-values:\"\" != record-values:\"handle: 1, values: [KindString 10]\"")
hook.checkLogCount(t, 1)
hook.logs[0].checkMsg(t, "admin check found data inconsistency")
hook.logs[0].checkField(t,
hook.CheckLogCount(t, 1)
hook.Logs[0].CheckMsg(t, "admin check found data inconsistency")
hook.Logs[0].CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "k2"),
zap.Stringer("row_id", kv.IntHandle(1)),
)
hook.logs[0].checkFieldNotEmpty(t, "row_mvcc")
hook.Logs[0].CheckFieldNotEmpty(t, "row_mvcc")
}()

// row is missed for plain key
Expand All @@ -1322,38 +1233,38 @@ func TestCheckFailReport(t *testing.T) {
require.NoError(t, err)
require.NoError(t, txn.Commit(tk.ctx))

ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test",
"[admin:8223]data inconsistency in table: admin_test, index: k2, handle: 1, index-values:\"handle: 1, values: [KindString 100 KindInt64 1]\" != record-values:\"\"")
hook.checkLogCount(t, 1)
logEntry := hook.logs[0]
logEntry.checkMsg(t, "admin check found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry := hook.Logs[0]
logEntry.CheckMsg(t, "admin check found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "k2"),
zap.Stringer("row_id", kv.IntHandle(1)),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc")
logEntry.checkFieldNotEmpty(t, "index_mvcc")
logEntry.CheckFieldNotEmpty(t, "row_mvcc")
logEntry.CheckFieldNotEmpty(t, "index_mvcc")

// test inconsistency check in index lookup
ctx, hook = withLogHook(tk.ctx, t, "")
ctx, hook = testutil.WithLogHook(tk.ctx, t, "")
rs, err := tk.Exec(ctx, "select * from admin_test use index(k2) where c3 = '100'")
require.NoError(t, err)
_, err = session.GetRows4Test(ctx, testkit.TryRetrieveSession(ctx), rs)
require.Error(t, err)
require.Equal(t, "[executor:8133]data inconsistency in table: admin_test, index: k2, index-count:1 != record-count:0", err.Error())
hook.checkLogCount(t, 1)
logEntry = hook.logs[0]
logEntry.checkMsg(t, "indexLookup found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry = hook.Logs[0]
logEntry.CheckMsg(t, "indexLookup found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "k2"),
zap.Int64("table_cnt", 0),
zap.Int64("index_cnt", 1),
zap.String("missing_handles", `[1]`),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc_0")
logEntry.CheckFieldNotEmpty(t, "row_mvcc_0")
}()

// row is missed for unique key
Expand All @@ -1366,37 +1277,37 @@ func TestCheckFailReport(t *testing.T) {
require.NoError(t, err)
require.NoError(t, txn.Commit(tk.ctx))

ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test",
"[admin:8223]data inconsistency in table: admin_test, index: uk1, handle: 1, index-values:\"handle: 1, values: [KindInt64 10 KindInt64 1]\" != record-values:\"\"")
hook.checkLogCount(t, 1)
logEntry := hook.logs[0]
logEntry.checkMsg(t, "admin check found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry := hook.Logs[0]
logEntry.CheckMsg(t, "admin check found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "uk1"),
zap.Stringer("row_id", kv.IntHandle(1)),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc")
logEntry.checkFieldNotEmpty(t, "index_mvcc")
logEntry.CheckFieldNotEmpty(t, "row_mvcc")
logEntry.CheckFieldNotEmpty(t, "index_mvcc")

// test inconsistency check in point-get
ctx, hook = withLogHook(tk.ctx, t, "")
ctx, hook = testutil.WithLogHook(tk.ctx, t, "")
rs, err := tk.Exec(ctx, "select * from admin_test use index(uk1) where c2 = 10")
require.NoError(t, err)
_, err = session.GetRows4Test(ctx, testkit.TryRetrieveSession(ctx), rs)
require.Error(t, err)
hook.checkLogCount(t, 1)
logEntry = hook.logs[0]
logEntry.checkMsg(t, "indexLookup found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry = hook.Logs[0]
logEntry.CheckMsg(t, "indexLookup found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "uk1"),
zap.Int64("table_cnt", 0),
zap.Int64("index_cnt", 1),
zap.String("missing_handles", `[1]`),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc_0")
logEntry.CheckFieldNotEmpty(t, "row_mvcc_0")
}()

// handle match but value is different for uk
Expand All @@ -1410,20 +1321,20 @@ func TestCheckFailReport(t *testing.T) {
_, err = tk.uniqueIndex.Create(mock.NewContext(), txn, []types.Datum{types.NewIntDatum(20)}, kv.IntHandle(1), nil)
require.NoError(t, err)
require.NoError(t, txn.Commit(tk.ctx))
ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test",
"[executor:8134]data inconsistency in table: admin_test, index: uk1, col: c2, handle: \"1\", index-values:\"KindInt64 20\" != record-values:\"KindInt64 10\", compare err:<nil>")
hook.checkLogCount(t, 1)
logEntry := hook.logs[0]
logEntry.checkMsg(t, "admin check found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry := hook.Logs[0]
logEntry.CheckMsg(t, "admin check found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "uk1"),
zap.Stringer("row_id", kv.IntHandle(1)),
zap.String("col", "c2"),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc")
logEntry.checkFieldNotEmpty(t, "index_mvcc")
logEntry.CheckFieldNotEmpty(t, "row_mvcc")
logEntry.CheckFieldNotEmpty(t, "index_mvcc")
}()

// handle match but value is different for plain key
Expand All @@ -1437,20 +1348,20 @@ func TestCheckFailReport(t *testing.T) {
_, err = tk.plainIndex.Create(mock.NewContext(), txn, []types.Datum{types.NewStringDatum("200")}, kv.IntHandle(1), nil)
require.NoError(t, err)
require.NoError(t, txn.Commit(tk.ctx))
ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")
tk.MustGetErrMsg(ctx, "admin check table admin_test",
"[executor:8134]data inconsistency in table: admin_test, index: k2, col: c3, handle: \"1\", index-values:\"KindString 200\" != record-values:\"KindString 100\", compare err:<nil>")
hook.checkLogCount(t, 1)
logEntry := hook.logs[0]
logEntry.checkMsg(t, "admin check found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry := hook.Logs[0]
logEntry.CheckMsg(t, "admin check found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "k2"),
zap.Stringer("row_id", kv.IntHandle(1)),
zap.String("col", "c3"),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc")
logEntry.checkFieldNotEmpty(t, "index_mvcc")
logEntry.CheckFieldNotEmpty(t, "row_mvcc")
logEntry.CheckFieldNotEmpty(t, "index_mvcc")
}()

// test binary column.
Expand All @@ -1473,24 +1384,24 @@ func TestCheckFailReport(t *testing.T) {
require.NoError(t, err)
require.NoError(t, txn.Commit(tk.ctx))

ctx, hook := withLogHook(tk.ctx, t, "inconsistency")
ctx, hook := testutil.WithLogHook(tk.ctx, t, "inconsistency")

// TODO(tiancaiamao): admin check doesn't support the chunk protocol.
// Remove this after https://github.com/pingcap/tidb/issues/35156
tk.MustExec(ctx, "set @@tidb_enable_chunk_rpc = off")

tk.MustGetErrMsg(ctx, "admin check table admin_test",
`[admin:8223]data inconsistency in table: admin_test, index: uk1, handle: 282574488403969, index-values:"handle: 282574488403969, values: [KindInt64 282578800083201 KindInt64 282574488403969]" != record-values:""`)
hook.checkLogCount(t, 1)
logEntry := hook.logs[0]
logEntry.checkMsg(t, "admin check found data inconsistency")
logEntry.checkField(t,
hook.CheckLogCount(t, 1)
logEntry := hook.Logs[0]
logEntry.CheckMsg(t, "admin check found data inconsistency")
logEntry.CheckField(t,
zap.String("table_name", "admin_test"),
zap.String("index_name", "uk1"),
zap.Stringer("row_id", kv.IntHandle(282574488403969)),
)
logEntry.checkFieldNotEmpty(t, "row_mvcc")
logEntry.checkFieldNotEmpty(t, "index_mvcc")
logEntry.CheckFieldNotEmpty(t, "row_mvcc")
logEntry.CheckFieldNotEmpty(t, "index_mvcc")
}()
}

Expand Down
Loading