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

ddl: using pingcap/log and unify the log format( #9659) #9955

Merged
merged 3 commits into from
Apr 3, 2019
Merged

ddl: using pingcap/log and unify the log format( #9659) #9955

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
c69c9fc
ddl: using pingcap/log and unify the log format( #9659)
crazycs520 Mar 29, 2019
d36dd73
fix ci
crazycs520 Mar 29, 2019
c22eb0f
Merge branch 'release-2.1' of https://github.com/pingcap/tidb into 96…
crazycs520 Apr 3, 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
7 changes: 4 additions & 3 deletions ddl/callback_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,11 @@ package ddl

import (
. "github.com/pingcap/check"
"github.com/pingcap/log"
"github.com/pingcap/parser/model"
"github.com/pingcap/tidb/infoschema"
"github.com/pingcap/tidb/sessionctx"
log "github.com/sirupsen/logrus"
"go.uber.org/zap"
"golang.org/x/net/context"
)

Expand Down Expand Up @@ -47,7 +48,7 @@ type TestDDLCallback struct {
}

func (tc *TestDDLCallback) OnJobRunBefore(job *model.Job) {
log.Infof("on job run before, job %v", job)
log.Info("on job run before", zap.String("job", job.String()))
if tc.OnJobRunBeforeExported != nil {
tc.OnJobRunBeforeExported(job)
return
Expand All @@ -61,7 +62,7 @@ func (tc *TestDDLCallback) OnJobRunBefore(job *model.Job) {
}

func (tc *TestDDLCallback) OnJobUpdated(job *model.Job) {
log.Infof("on job updated, job %v", job)
log.Info("on job updated", zap.String("job", job.String()))
if tc.OnJobUpdatedExported != nil {
tc.OnJobUpdatedExported(job)
return
Expand Down
5 changes: 3 additions & 2 deletions ddl/column.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,8 @@ import (
"github.com/pingcap/tidb/meta"
"github.com/pingcap/tidb/table"
"github.com/pingcap/tidb/types"
log "github.com/sirupsen/logrus"
"github.com/pingcap/tidb/util/logutil"
"go.uber.org/zap"
)

// adjustColumnInfoInAddColumn is used to set the correct position of column info when adding column.
Expand Down Expand Up @@ -162,7 +163,7 @@ func onAddColumn(d *ddlCtx, t *meta.Meta, job *model.Job) (ver int64, err error)
job.State = model.JobStateCancelled
return ver, errors.Trace(err)
}
log.Infof("[ddl] add column, run DDL job %s, column info %#v, offset %d", job, columnInfo, offset)
logutil.Logger(ddlLogCtx).Info("[ddl] run add column job", zap.String("job", job.String()), zap.Reflect("columnInfo", *columnInfo), zap.Int("offset", offset))
// Set offset arg to job.
if offset != 0 {
job.Args = []interface{}{columnInfo, pos, offset}
Expand Down
28 changes: 16 additions & 12 deletions ddl/ddl.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,8 +41,9 @@ import (
"github.com/pingcap/tidb/sessionctx/variable"
"github.com/pingcap/tidb/table"
tidbutil "github.com/pingcap/tidb/util"
log "github.com/sirupsen/logrus"
"github.com/pingcap/tidb/util/logutil"
"github.com/twinj/uuid"
"go.uber.org/zap"
"golang.org/x/net/context"
)

Expand All @@ -69,6 +70,9 @@ var (
// Mysql maximum number of partitions is 8192, our maximum number of partitions is 1024.
// Reference linking https://dev.mysql.com/doc/refman/5.7/en/partitioning-limitations.html.
PartitionCountLimit = 1024

// ddlLogCtx uses for log.
ddlLogCtx = context.Background()
)

var (
Expand Down Expand Up @@ -265,7 +269,7 @@ type ddlCtx struct {

func (dc *ddlCtx) isOwner() bool {
isOwner := dc.ownerManager.IsOwner()
log.Debugf("[ddl] it's the DDL owner %v, self ID %s", isOwner, dc.uuid)
logutil.Logger(ddlLogCtx).Debug("[ddl] check whether is the DDL owner", zap.Bool("isOwner", isOwner), zap.String("selfID", dc.uuid))
if isOwner {
metrics.DDLCounter.WithLabelValues(metrics.IsDDLOwner).Inc()
}
Expand Down Expand Up @@ -294,7 +298,7 @@ func asyncNotifyEvent(d *ddlCtx, e *util.Event) {
case d.ddlEventCh <- e:
return
default:
log.Warnf("Fail to notify event %s.", e)
logutil.Logger(ddlLogCtx).Warn("[ddl] fail to notify DDL event", zap.String("event", e.String()))
time.Sleep(time.Microsecond * 10)
}
}
Expand Down Expand Up @@ -355,14 +359,14 @@ func (d *ddl) Stop() error {
defer d.m.Unlock()

d.close()
log.Infof("[ddl] stop DDL:%s", d.uuid)
logutil.Logger(ddlLogCtx).Info("[ddl] stop DDL", zap.String("ID", d.uuid))
return nil
}

// start campaigns the owner and starts workers.
// ctxPool is used for the worker's delRangeManager and creates sessions.
func (d *ddl) start(ctx context.Context, ctxPool *pools.ResourcePool) {
log.Infof("[ddl] start DDL:%s, run worker %v", d.uuid, RunWorker)
logutil.Logger(ddlLogCtx).Info("[ddl] start DDL", zap.String("ID", d.uuid), zap.Bool("runWorker", RunWorker))
d.quitCh = make(chan struct{})

// If RunWorker is true, we need campaign owner and do DDL job.
Expand All @@ -381,7 +385,7 @@ func (d *ddl) start(ctx context.Context, ctxPool *pools.ResourcePool) {
func() { w.start(d.ddlCtx) },
func(r interface{}) {
if r != nil {
log.Errorf("[ddl-%s] ddl %s meet panic", w, d.uuid)
logutil.Logger(w.logCtx).Error("[ddl] DDL worker meet panic", zap.String("ID", d.uuid))
metrics.PanicCounter.WithLabelValues(metrics.LabelDDL).Inc()
}
})
Expand All @@ -404,13 +408,13 @@ func (d *ddl) close() {
d.ownerManager.Cancel()
err := d.schemaSyncer.RemoveSelfVersionPath()
if err != nil {
log.Errorf("[ddl] remove self version path failed %v", err)
logutil.Logger(ddlLogCtx).Error("[ddl] remove self version path failed", zap.Error(err))
}

for _, worker := range d.workers {
worker.close()
}
log.Infof("[ddl] closing DDL:%s takes time %v", d.uuid, time.Since(startTime))
logutil.Logger(ddlLogCtx).Info("[ddl] closing DDL", zap.String("ID", d.uuid), zap.Duration("takeTime", time.Since(startTime)))
}

// GetLease implements DDL.GetLease interface.
Expand Down Expand Up @@ -491,7 +495,7 @@ func (d *ddl) doDDLJob(ctx sessionctx.Context, job *model.Job) error {

// Notice worker that we push a new job and wait the job done.
d.asyncNotifyWorker(job.Type)
log.Infof("[ddl] start DDL job %s, Query:%s", job, job.Query)
logutil.Logger(ddlLogCtx).Info("[ddl] start to do DDL job", zap.String("job", job.String()), zap.String("query", job.Query))

var historyJob *model.Job
jobID := job.ID
Expand All @@ -514,16 +518,16 @@ func (d *ddl) doDDLJob(ctx sessionctx.Context, job *model.Job) error {

historyJob, err = d.getHistoryDDLJob(jobID)
if err != nil {
log.Errorf("[ddl] get history DDL job err %v, check again", err)
logutil.Logger(ddlLogCtx).Error("[ddl] get history DDL job failed, check again", zap.Error(err))
continue
} else if historyJob == nil {
log.Debugf("[ddl] DDL job ID:%d is not in history, maybe not run", jobID)
logutil.Logger(ddlLogCtx).Debug("[ddl] DDL job is not in history, maybe not run", zap.Int64("jobID", jobID))
continue
}

// If a job is a history job, the state must be JobSynced or JobCancel.
if historyJob.IsSynced() {
log.Infof("[ddl] DDL job ID:%d is finished", jobID)
logutil.Logger(ddlLogCtx).Info("[ddl] DDL job is finished", zap.Int64("jobID", jobID))
return nil
}

Expand Down
7 changes: 4 additions & 3 deletions ddl/ddl_api.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -36,8 +36,9 @@ import (
"github.com/pingcap/tidb/sessionctx/variable"
"github.com/pingcap/tidb/table"
"github.com/pingcap/tidb/types"
"github.com/pingcap/tidb/util/logutil"
"github.com/pingcap/tidb/util/schemautil"
log "github.com/sirupsen/logrus"
"go.uber.org/zap"
)

func (d *ddl) CreateSchema(ctx sessionctx.Context, schema model.CIStr, charsetInfo *ast.CharsetOpt) (err error) {
Expand Down Expand Up @@ -540,11 +541,11 @@ func setTimestampDefaultValue(c *table.Column, hasDefaultValue bool, setOnUpdate
if mysql.HasTimestampFlag(c.Flag) && mysql.HasNotNullFlag(c.Flag) {
if setOnUpdateNow {
if err := c.SetDefaultValue(types.ZeroDatetimeStr); err != nil {
log.Error(errors.ErrorStack(err))
logutil.Logger(ddlLogCtx).Error("set default value failed", zap.Error(err))
}
} else {
if err := c.SetDefaultValue(strings.ToUpper(ast.CurrentTimestamp)); err != nil {
log.Error(errors.ErrorStack(err))
logutil.Logger(ddlLogCtx).Error("set default value failed", zap.Error(err))
}

}
Expand Down
5 changes: 3 additions & 2 deletions ddl/ddl_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import (

"github.com/coreos/etcd/clientv3"
. "github.com/pingcap/check"
"github.com/pingcap/log"
"github.com/pingcap/parser/ast"
"github.com/pingcap/parser/model"
"github.com/pingcap/parser/terror"
Expand All @@ -32,7 +33,7 @@ import (
"github.com/pingcap/tidb/util"
"github.com/pingcap/tidb/util/logutil"
"github.com/pingcap/tidb/util/mock"
log "github.com/sirupsen/logrus"
"go.uber.org/zap"
"golang.org/x/net/context"
)

Expand Down Expand Up @@ -91,7 +92,7 @@ func (d *ddl) restartWorkers(ctx context.Context) {
go util.WithRecovery(func() { w.start(d.ddlCtx) },
func(r interface{}) {
if r != nil {
log.Errorf("[ddl-%s] ddl %s meet panic", w, d.uuid)
log.Error("[ddl] restart DDL worker meet panic", zap.String("worker", w.String()), zap.String("ID", d.uuid))
}
})
asyncNotify(worker.ddlJobCh)
Expand Down
Loading