From ee63dd1ae6967d064647db890ae0d0e0178a0228 Mon Sep 17 00:00:00 2001 From: Ryan Leung Date: Mon, 3 Aug 2020 19:54:02 +0800 Subject: [PATCH] cherry pick #2707 to release-4.0 Signed-off-by: ti-srebot --- pkg/dashboard/adapter/manager.go | 11 +++- pkg/errs/errs.go | 51 ++++++++++++++++++ pkg/errs/errs_test.go | 91 ++++++++++++++++++++++++++++++++ server/member/leader.go | 23 +++++--- server/tso/tso.go | 15 ++++-- 5 files changed, 178 insertions(+), 13 deletions(-) create mode 100644 pkg/errs/errs.go create mode 100644 pkg/errs/errs_test.go diff --git a/pkg/dashboard/adapter/manager.go b/pkg/dashboard/adapter/manager.go index 98cc38878a2..4f3a76562ab 100644 --- a/pkg/dashboard/adapter/manager.go +++ b/pkg/dashboard/adapter/manager.go @@ -24,9 +24,16 @@ import ( "go.uber.org/zap" "github.com/pingcap/log" +<<<<<<< HEAD "github.com/tikv/pd/pkg/logutil" "github.com/tikv/pd/server" "github.com/tikv/pd/server/cluster" +======= + "github.com/pingcap/pd/v4/pkg/errs" + "github.com/pingcap/pd/v4/pkg/logutil" + "github.com/pingcap/pd/v4/server" + "github.com/pingcap/pd/v4/server/cluster" +>>>>>>> 52772d8... *: refine member/tso/adapter logs (#2707) ) var ( @@ -195,7 +202,7 @@ func (m *Manager) startService() { return } if err := m.service.Start(m.ctx); err != nil { - log.Error("Can not start dashboard server", zap.Error(err)) + log.Error("Can not start dashboard server", zap.Error(errs.ErrStartDashboard.FastGenByArgs()), zap.NamedError("cause", err)) } else { log.Info("Dashboard server is started") } @@ -206,7 +213,7 @@ func (m *Manager) stopService() { return } if err := m.service.Stop(context.Background()); err != nil { - log.Error("Stop dashboard server error", zap.Error(err)) + log.Error("Stop dashboard server error", zap.Error(errs.ErrStopDashboard.FastGenByArgs()), zap.NamedError("cause", err)) } else { log.Info("Dashboard server is stopped") } diff --git a/pkg/errs/errs.go b/pkg/errs/errs.go new file mode 100644 index 00000000000..06b9d7e4f45 --- /dev/null +++ b/pkg/errs/errs.go @@ -0,0 +1,51 @@ +// Copyright 2020 PingCAP, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// See the License for the specific language governing permissions and +// limitations under the License. + +package errs + +import "github.com/pingcap/errors" + +var ( + reg = errors.NewRegistry("PD") + // ClassTSO defines tso error class + ClassTSO = reg.RegisterErrorClass(1, "tso") + // ClassAdaptor defines adapter error class + ClassAdaptor = reg.RegisterErrorClass(2, "adapter") + // ClassMember defines member error class + ClassMember = reg.RegisterErrorClass(3, "member") +) + +// tso errors +var ( + ErrInvalidTimestamp = ClassTSO.DefineError().TextualCode("ErrInvalidTimestamp").MessageTemplate("invalid timestamp").Build() + ErrLogicOverflow = ClassTSO.DefineError().TextualCode("ErrLogicOverflow").MessageTemplate("logic part overflow").Build() + ErrIncorrectSystemTime = ClassTSO.DefineError().TextualCode("ErrIncorrectSystemTime").MessageTemplate("incorrect system time").Build() +) + +// adapter errors +var ( + ErrStartDashboard = ClassAdaptor.DefineError().TextualCode("ErrStartDashboard").MessageTemplate("fail to start dashboard").Build() + ErrStopDashboard = ClassAdaptor.DefineError().TextualCode("ErrStopDashboard").MessageTemplate("fail to stop dashboard").Build() +) + +// member errors +var ( + ErretcdLeaderNotFound = ClassMember.DefineError().TextualCode("ErretcdLeaderNotFound").MessageTemplate("etcd leader not found").Build() + ErrGetLeader = ClassMember.DefineError().TextualCode("ErrGetLeader").MessageTemplate("fail to get leader").Build() + ErrDeleteLeaderKey = ClassMember.DefineError().TextualCode("ErrDeleteLeaderKey").MessageTemplate("fail to delete leader key").Build() + ErrLoadLeaderPriority = ClassMember.DefineError().TextualCode("ErrLoadLeaderPriority").MessageTemplate("fail to load leader priority").Build() + ErrLoadetcdLeaderPriority = ClassMember.DefineError().TextualCode("ErrLoadetcdLeaderPriority").MessageTemplate("fail to load etcd leader priority").Build() + ErrTransferetcdLeader = ClassMember.DefineError().TextualCode("ErrTransferetcdLeader").MessageTemplate("fail to transfer etcd leader").Build() + ErrWatcherCancel = ClassMember.DefineError().TextualCode("ErrWatcherCancel").MessageTemplate("watcher canceled").Build() + ErrMarshalLeader = ClassMember.DefineError().TextualCode("ErrMarshalLeader").MessageTemplate("fail to marshal leader").Build() +) diff --git a/pkg/errs/errs_test.go b/pkg/errs/errs_test.go new file mode 100644 index 00000000000..e4e0b120379 --- /dev/null +++ b/pkg/errs/errs_test.go @@ -0,0 +1,91 @@ +// Copyright 2020 PingCAP, Inc. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// See the License for the specific language governing permissions and +// limitations under the License. + +package errs + +import ( + "bytes" + "errors" + "fmt" + "strings" + "testing" + + "github.com/pingcap/log" + "go.uber.org/zap" +) + +// testingWriter is a WriteSyncer that writes to the the messages. +type testingWriter struct { + messages []string +} + +func newTestingWriter() *testingWriter { + return &testingWriter{} +} + +func (w *testingWriter) Write(p []byte) (n int, err error) { + n = len(p) + p = bytes.TrimRight(p, "\n") + m := fmt.Sprintf("%s", p) + w.messages = append(w.messages, m) + return n, nil +} + +func (w *testingWriter) Sync() error { + return nil +} + +type verifyLogger struct { + *zap.Logger + w *testingWriter +} + +func (logger *verifyLogger) Contain(t *testing.T, s string) { + if logger.w.messages == nil { + t.Error() + } + msg := logger.w.messages[len(logger.w.messages)-1] + IsContain(t, msg, s) +} + +func newZapTestLogger(cfg *log.Config, opts ...zap.Option) verifyLogger { + // TestingWriter is used to write to memory. + // Used in the verify logger. + writer := newTestingWriter() + lg, _, _ := log.InitLoggerWithWriteSyncer(cfg, writer, opts...) + + return verifyLogger{ + Logger: lg, + w: writer, + } +} + +func IsContain(t *testing.T, s1 string, s2 string) { + if !strings.Contains(s1, s2) { + t.Error() + } +} + +func TestError(t *testing.T) { + conf := &log.Config{Level: "debug", File: log.FileLogConfig{}, DisableTimestamp: true} + lg := newZapTestLogger(conf) + log.ReplaceGlobals(lg.Logger, nil) + + rfc := `[error="[PD:tso:ErrInvalidTimestamp] invalid timestamp"]` + log.Error("test", zap.Error(ErrInvalidTimestamp.FastGenByArgs())) + lg.Contain(t, rfc) + cause := `[cause="test err"]` + log.Error("test", zap.Error(ErrInvalidTimestamp.FastGenByArgs()), zap.NamedError("cause", errors.New("test err"))) + lg.Contain(t, rfc) + lg.Contain(t, cause) +} diff --git a/server/member/leader.go b/server/member/leader.go index c0c47bde83b..ba7a745e2c7 100644 --- a/server/member/leader.go +++ b/server/member/leader.go @@ -28,6 +28,13 @@ import ( "github.com/pingcap/failpoint" "github.com/pingcap/kvproto/pkg/pdpb" "github.com/pingcap/log" +<<<<<<< HEAD +======= + "github.com/pingcap/pd/v4/pkg/errs" + "github.com/pingcap/pd/v4/pkg/etcdutil" + "github.com/pingcap/pd/v4/server/config" + "github.com/pingcap/pd/v4/server/kv" +>>>>>>> 52772d8... *: refine member/tso/adapter logs (#2707) "github.com/pkg/errors" "github.com/tikv/pd/pkg/etcdutil" "github.com/tikv/pd/server/config" @@ -131,14 +138,14 @@ func (m *Member) GetLeaderPath() string { // CheckLeader checks returns true if it is needed to check later. func (m *Member) CheckLeader(name string) (*pdpb.Member, int64, bool) { if m.GetEtcdLeader() == 0 { - log.Error("no etcd leader, check leader later") + log.Error("no etcd leader, check leader later", zap.Error(errs.ErretcdLeaderNotFound.FastGenByArgs())) time.Sleep(200 * time.Millisecond) return nil, 0, true } leader, rev, err := getLeader(m.client, m.GetLeaderPath()) if err != nil { - log.Error("get leader meet error", zap.Error(err)) + log.Error("get leader meet error", zap.Error(errs.ErrGetLeader.FastGenByArgs()), zap.NamedError("cause", err)) time.Sleep(200 * time.Millisecond) return nil, 0, true } @@ -148,7 +155,7 @@ func (m *Member) CheckLeader(name string) (*pdpb.Member, int64, bool) { // in previous CampaignLeader. we can delete and campaign again. log.Warn("the leader has not changed, delete and campaign again", zap.Stringer("old-leader", leader)) if err = m.deleteLeaderKey(); err != nil { - log.Error("delete leader key meet error", zap.Error(err)) + log.Error("delete leader key meet error", zap.Error(errs.ErrDeleteLeaderKey.FastGenByArgs()), zap.NamedError("cause", err)) time.Sleep(200 * time.Millisecond) return nil, 0, true } @@ -165,18 +172,18 @@ func (m *Member) CheckPriority(ctx context.Context) { } myPriority, err := m.GetMemberLeaderPriority(m.ID()) if err != nil { - log.Error("failed to load leader priority", zap.Error(err)) + log.Error("failed to load leader priority", zap.Error(errs.ErrLoadLeaderPriority.FastGenByArgs()), zap.NamedError("cause", err)) return } leaderPriority, err := m.GetMemberLeaderPriority(etcdLeader) if err != nil { - log.Error("failed to load etcd leader priority", zap.Error(err)) + log.Error("failed to load etcd leader priority", zap.Error(errs.ErrLoadetcdLeaderPriority.FastGenByArgs()), zap.NamedError("cause", err)) return } if myPriority > leaderPriority { err := m.MoveEtcdLeader(ctx, etcdLeader, m.ID()) if err != nil { - log.Error("failed to transfer etcd leader", zap.Error(err)) + log.Error("failed to transfer etcd leader", zap.Error(errs.ErrTransferetcdLeader.FastGenByArgs()), zap.NamedError("cause", err)) } else { log.Info("transfer etcd leader", zap.Uint64("from", etcdLeader), @@ -227,7 +234,7 @@ func (m *Member) MemberInfo(cfg *config.Config, name string, rootPath string) { data, err := leader.Marshal() if err != nil { // can't fail, so panic here. - log.Fatal("marshal leader meet error", zap.Stringer("leader", leader), zap.Error(err)) + log.Fatal("marshal leader meet error", zap.Stringer("leader", leader), zap.Error(errs.ErrMarshalLeader.FastGenByArgs()), zap.NamedError("cause", err)) } m.member = leader m.memberValue = string(data) @@ -475,7 +482,7 @@ func (m *Member) WatchLeader(serverCtx context.Context, leader *pdpb.Member, rev break } if wresp.Canceled { - log.Error("leader watcher is canceled with", zap.Int64("revision", revision), zap.Error(wresp.Err())) + log.Error("leader watcher is canceled with", zap.Int64("revision", revision), zap.Error(errs.ErrWatcherCancel.FastGenByArgs()), zap.NamedError("cause", wresp.Err())) return } diff --git a/server/tso/tso.go b/server/tso/tso.go index bc3a5f82fbf..04838cf38da 100644 --- a/server/tso/tso.go +++ b/server/tso/tso.go @@ -23,6 +23,15 @@ import ( "github.com/pingcap/failpoint" "github.com/pingcap/kvproto/pkg/pdpb" "github.com/pingcap/log" +<<<<<<< HEAD +======= + "github.com/pingcap/pd/v4/pkg/errs" + "github.com/pingcap/pd/v4/pkg/etcdutil" + "github.com/pingcap/pd/v4/pkg/tsoutil" + "github.com/pingcap/pd/v4/pkg/typeutil" + "github.com/pingcap/pd/v4/server/kv" + "github.com/pingcap/pd/v4/server/member" +>>>>>>> 52772d8... *: refine member/tso/adapter logs (#2707) "github.com/pkg/errors" "github.com/tikv/pd/pkg/etcdutil" "github.com/tikv/pd/pkg/tsoutil" @@ -144,7 +153,7 @@ func (t *TimestampOracle) SyncTimestamp(lease *member.LeaderLease) error { // If the current system time minus the saved etcd timestamp is less than `updateTimestampGuard`, // the timestamp allocation will start from the saved etcd timestamp temporarily. if typeutil.SubTimeByWallClock(next, last) < updateTimestampGuard { - log.Error("system time may be incorrect", zap.Time("last", last), zap.Time("next", next)) + log.Error("system time may be incorrect", zap.Time("last", last), zap.Time("next", next), zap.Error(errs.ErrIncorrectSystemTime.FastGenByArgs())) next = last.Add(updateTimestampGuard) } @@ -299,7 +308,7 @@ func (t *TimestampOracle) GetRespTS(count uint32) (pdpb.Timestamp, error) { time.Sleep(200 * time.Millisecond) continue } - log.Error("invalid timestamp", zap.Any("timestamp", current)) + log.Error("invalid timestamp", zap.Any("timestamp", current), zap.Error(errs.ErrInvalidTimestamp.FastGenByArgs())) return pdpb.Timestamp{}, errors.New("can not get timestamp, may be not leader") } @@ -308,7 +317,7 @@ func (t *TimestampOracle) GetRespTS(count uint32) (pdpb.Timestamp, error) { if resp.Logical >= maxLogical { log.Error("logical part outside of max logical interval, please check ntp time", zap.Reflect("response", resp), - zap.Int("retry-count", i)) + zap.Int("retry-count", i), zap.Error(errs.ErrLogicOverflow.FastGenByArgs())) tsoCounter.WithLabelValues("logical_overflow").Inc() time.Sleep(UpdateTimestampStep) continue