Skip to content

Commit 8438bad

Browse files
authored
*: make the set system variable log shorter (#7031)
1 parent cef80ce commit 8438bad

File tree

11 files changed

+45
-45
lines changed

11 files changed

+45
-45
lines changed

executor/adapter.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -280,10 +280,10 @@ func (a *ExecStmt) buildExecutor(ctx sessionctx.Context) (Executor, error) {
280280
var err error
281281
isPointGet := IsPointGetWithPKOrUniqueKeyByAutoCommit(ctx, a.Plan)
282282
if isPointGet {
283-
log.Debugf("[con:%d][InitTxnWithStartTS] %s", ctx.GetSessionVars().ConnectionID, a.Text)
283+
log.Debugf("con:%d InitTxnWithStartTS %s", ctx.GetSessionVars().ConnectionID, a.Text)
284284
err = ctx.InitTxnWithStartTS(math.MaxUint64)
285285
} else {
286-
log.Debugf("[con:%d][ActivePendingTxn] %s", ctx.GetSessionVars().ConnectionID, a.Text)
286+
log.Debugf("con:%d ActivePendingTxn %s", ctx.GetSessionVars().ConnectionID, a.Text)
287287
err = ctx.ActivePendingTxn()
288288
}
289289
if err != nil {

executor/compiler.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -195,7 +195,7 @@ func GetInfoSchema(ctx sessionctx.Context) infoschema.InfoSchema {
195195
var is infoschema.InfoSchema
196196
if snap := sessVar.SnapshotInfoschema; snap != nil {
197197
is = snap.(infoschema.InfoSchema)
198-
log.Infof("[con:%d] use snapshot schema %d", sessVar.ConnectionID, is.SchemaMetaVersion())
198+
log.Infof("con:%d use snapshot schema %d", sessVar.ConnectionID, is.SchemaMetaVersion())
199199
} else {
200200
is = sessVar.TxnCtx.InfoSchema.(infoschema.InfoSchema)
201201
}

executor/set.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -178,7 +178,7 @@ func (e *SetExecutor) setSysVariable(name string, v *expression.VarAssignment) e
178178
valStr, err = value.ToString()
179179
terror.Log(errors.Trace(err))
180180
}
181-
log.Infof("[con:%d] set system variable %s = %s", sessionVars.ConnectionID, name, valStr)
181+
log.Infof("con:%d %s=%s", sessionVars.ConnectionID, name, valStr)
182182
}
183183

184184
if name == variable.TxnIsolation {
@@ -259,7 +259,7 @@ func (e *SetExecutor) loadSnapshotInfoSchemaIfNeeded(name string) error {
259259
vars.SnapshotInfoschema = nil
260260
return nil
261261
}
262-
log.Infof("[con:%d] loadSnapshotInfoSchema, SnapshotTS:%d", vars.ConnectionID, vars.SnapshotTS)
262+
log.Infof("con:%d loadSnapshotInfoSchema, SnapshotTS:%d", vars.ConnectionID, vars.SnapshotTS)
263263
dom := domain.GetDomain(e.ctx)
264264
snapInfo, err := dom.GetSnapshotInfoSchema(vars.SnapshotTS)
265265
if err != nil {

executor/simple.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -122,7 +122,7 @@ func (e *SimpleExec) executeCommit(s *ast.CommitStmt) {
122122

123123
func (e *SimpleExec) executeRollback(s *ast.RollbackStmt) error {
124124
sessVars := e.ctx.GetSessionVars()
125-
log.Debugf("[con:%d] execute rollback statement", sessVars.ConnectionID)
125+
log.Debugf("con:%d execute rollback statement", sessVars.ConnectionID)
126126
sessVars.SetStatusFlag(mysql.ServerStatusInTrans, false)
127127
if e.ctx.Txn().Valid() {
128128
e.ctx.GetSessionVars().TxnCtx.ClearDelta()

server/conn.go

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -451,7 +451,7 @@ func (cc *clientConn) Run() {
451451
if terror.ErrorNotEqual(err, io.EOF) {
452452
errStack := errors.ErrorStack(err)
453453
if !strings.Contains(errStack, "use of closed network connection") {
454-
log.Errorf("[con:%d] read packet error, close this connection %s",
454+
log.Errorf("con:%d read packet error, close this connection %s",
455455
cc.connectionID, errStack)
456456
}
457457
}
@@ -471,11 +471,11 @@ func (cc *clientConn) Run() {
471471
cc.addMetrics(data[0], startTime, nil)
472472
return
473473
} else if terror.ErrResultUndetermined.Equal(err) {
474-
log.Errorf("[con:%d] result undetermined error, close this connection %s",
474+
log.Errorf("con:%d result undetermined error, close this connection %s",
475475
cc.connectionID, errors.ErrorStack(err))
476476
return
477477
} else if terror.ErrCritical.Equal(err) {
478-
log.Errorf("[con:%d] critical error, stop the server listener %s",
478+
log.Errorf("con:%d critical error, stop the server listener %s",
479479
cc.connectionID, errors.ErrorStack(err))
480480
metrics.CriticalErrorCounter.Add(1)
481481
select {
@@ -484,7 +484,7 @@ func (cc *clientConn) Run() {
484484
}
485485
return
486486
}
487-
log.Warnf("[con:%d] dispatch error:\n%s\n%q\n%s",
487+
log.Warnf("con:%d dispatch error:\n%s\n%q\n%s",
488488
cc.connectionID, cc, queryStrForLog(string(data[1:])), errStrForLog(err))
489489
err1 := cc.writeError(err)
490490
terror.Log(errors.Trace(err1))

server/server.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -300,9 +300,9 @@ func (s *Server) onConn(c net.Conn) {
300300
terror.Log(errors.Trace(err))
301301
return
302302
}
303-
log.Infof("[con:%d] new connection %s", conn.connectionID, c.RemoteAddr().String())
303+
log.Infof("con:%d new connection %s", conn.connectionID, c.RemoteAddr().String())
304304
defer func() {
305-
log.Infof("[con:%d] close connection", conn.connectionID)
305+
log.Infof("con:%d close connection", conn.connectionID)
306306
}()
307307
s.rwlock.Lock()
308308
s.clients[conn.connectionID] = conn

session/session.go

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -347,7 +347,7 @@ func (s *session) doCommitWithRetry(ctx context.Context) error {
347347
// BatchInsert already commit the first batch 1000 rows, then it commit 1000-2000 and retry the statement,
348348
// Finally t1 will have more data than t2, with no errors return to user!
349349
if s.isRetryableError(err) && !s.sessionVars.BatchInsert && commitRetryLimit > 0 {
350-
log.Warnf("[con:%d] retryable error: %v, txn: %v", s.sessionVars.ConnectionID, err, s.txn)
350+
log.Warnf("con:%d retryable error: %v, txn: %v", s.sessionVars.ConnectionID, err, s.txn)
351351
// Transactions will retry 2 ~ commitRetryLimit times.
352352
// We make larger transactions retry less times to prevent cluster resource outage.
353353
txnSizeRate := float64(txnSize) / float64(kv.TxnTotalSizeLimit)
@@ -372,7 +372,7 @@ func (s *session) doCommitWithRetry(ctx context.Context) error {
372372
}
373373

374374
if err != nil {
375-
log.Warnf("[con:%d] finished txn:%v, %v", s.sessionVars.ConnectionID, s.txn, err)
375+
log.Warnf("con:%d finished txn:%v, %v", s.sessionVars.ConnectionID, s.txn, err)
376376
return errors.Trace(err)
377377
}
378378
mapper := s.GetSessionVars().TxnCtx.TableDeltaMap
@@ -519,17 +519,17 @@ func (s *session) retry(ctx context.Context, maxCnt uint) error {
519519
}
520520
}
521521
if !s.isRetryableError(err) {
522-
log.Warnf("[con:%d] session:%v, err:%v in retry", connID, s, err)
522+
log.Warnf("con:%d session:%v, err:%v in retry", connID, s, err)
523523
metrics.SessionRetryErrorCounter.WithLabelValues(metrics.LblUnretryable)
524524
return errors.Trace(err)
525525
}
526526
retryCnt++
527527
if retryCnt >= maxCnt {
528-
log.Warnf("[con:%d] Retry reached max count %d", connID, retryCnt)
528+
log.Warnf("con:%d Retry reached max count %d", connID, retryCnt)
529529
metrics.SessionRetryErrorCounter.WithLabelValues(metrics.LblReachMax)
530530
return errors.Trace(err)
531531
}
532-
log.Warnf("[con:%d] retryable error: %v, txn: %v", connID, err, s.txn)
532+
log.Warnf("con:%d retryable error: %v, txn: %v", connID, err, s.txn)
533533
kv.BackOff(retryCnt)
534534
s.txn.changeToInvalid()
535535
s.sessionVars.SetStatusFlag(mysql.ServerStatusInTrans, false)
@@ -750,7 +750,7 @@ func (s *session) executeStatement(ctx context.Context, connID uint64, stmtNode
750750
recordSet, err := runStmt(ctx, s, stmt)
751751
if err != nil {
752752
if !kv.ErrKeyExists.Equal(err) {
753-
log.Warnf("[%d] session error:\n%v\n%s", connID, errors.ErrorStack(err), s)
753+
log.Warnf("con:%d session error:\n%v\n%s", connID, errors.ErrorStack(err), s)
754754
}
755755
return nil, errors.Trace(err)
756756
}
@@ -815,7 +815,7 @@ func (s *session) Execute(ctx context.Context, sql string) (recordSets []ast.Rec
815815
stmtNodes, err := s.ParseSQL(ctx, sql, charsetInfo, collation)
816816
if err != nil {
817817
s.rollbackOnError(ctx)
818-
log.Warnf("[con:%d] parse error:\n%v\n%s", connID, err, sql)
818+
log.Warnf("con:%d parse error:\n%v\n%s", connID, err, sql)
819819
return nil, errors.Trace(err)
820820
}
821821
metrics.SessionExecuteParseDuration.Observe(time.Since(startTS).Seconds())
@@ -831,7 +831,7 @@ func (s *session) Execute(ctx context.Context, sql string) (recordSets []ast.Rec
831831
stmt, err := compiler.Compile(ctx, stmtNode)
832832
if err != nil {
833833
s.rollbackOnError(ctx)
834-
log.Warnf("[con:%d] compile error:\n%v\n%s", connID, err, sql)
834+
log.Warnf("con:%d compile error:\n%v\n%s", connID, err, sql)
835835
return nil, errors.Trace(err)
836836
}
837837
metrics.SessionExecuteCompileDuration.Observe(time.Since(startTS).Seconds())
@@ -983,7 +983,7 @@ func (s *session) NewTxn() error {
983983
if err != nil {
984984
return errors.Trace(err)
985985
}
986-
log.Infof("[con:%d] NewTxn() inside a transaction auto commit: %d", s.GetSessionVars().ConnectionID, txnID)
986+
log.Infof("con:%d NewTxn() inside a transaction auto commit: %d", s.GetSessionVars().ConnectionID, txnID)
987987
}
988988

989989
txn, err := s.store.Begin()

store/tikv/2pc.go

Lines changed: 17 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -140,7 +140,7 @@ func newTwoPhaseCommitter(txn *tikvTxn, connID uint64) (*twoPhaseCommitter, erro
140140
const logSize = 4 * 1024 * 1024 // 4MB
141141
if len(keys) > logEntryCount || size > logSize {
142142
tableID := tablecodec.DecodeTableID(keys[0])
143-
log.Infof("[BIG_TXN] [con:%d] table id:%d size:%d, keys:%d, puts:%d, dels:%d, locks:%d, startTS:%d",
143+
log.Infof("[BIG_TXN] con:%d table id:%d size:%d, keys:%d, puts:%d, dels:%d, locks:%d, startTS:%d",
144144
connID, tableID, size, len(keys), putCnt, delCnt, lockCnt, txn.startTS)
145145
}
146146

@@ -229,7 +229,7 @@ func (c *twoPhaseCommitter) doActionOnKeys(bo *Backoffer, action twoPhaseCommitA
229229
twoPhaseCommitGP.Go(func() {
230230
e := c.doActionOnBatches(bo, action, batches)
231231
if e != nil {
232-
log.Debugf("[con:%d] 2PC async doActionOnBatches %s err: %v", c.connID, action, e)
232+
log.Debugf("con:%d 2PC async doActionOnBatches %s err: %v", c.connID, action, e)
233233
metrics.TiKVSecondaryLockCleanupFailureCounter.WithLabelValues("commit").Inc()
234234
}
235235
})
@@ -256,7 +256,7 @@ func (c *twoPhaseCommitter) doActionOnBatches(bo *Backoffer, action twoPhaseComm
256256
if len(batches) == 1 {
257257
e := singleBatchActionFunc(bo, batches[0])
258258
if e != nil {
259-
log.Debugf("[con:%d] 2PC doActionOnBatches %s failed: %v, tid: %d", c.connID, action, e, c.startTS)
259+
log.Debugf("con:%d 2PC doActionOnBatches %s failed: %v, tid: %d", c.connID, action, e, c.startTS)
260260
}
261261
return errors.Trace(e)
262262
}
@@ -294,10 +294,10 @@ func (c *twoPhaseCommitter) doActionOnBatches(bo *Backoffer, action twoPhaseComm
294294
var err error
295295
for i := 0; i < len(batches); i++ {
296296
if e := <-ch; e != nil {
297-
log.Debugf("[con:%d] 2PC doActionOnBatches %s failed: %v, tid: %d", c.connID, action, e, c.startTS)
297+
log.Debugf("con:%d 2PC doActionOnBatches %s failed: %v, tid: %d", c.connID, action, e, c.startTS)
298298
// Cancel other requests and return the first error.
299299
if cancel != nil {
300-
log.Debugf("[con:%d] 2PC doActionOnBatches %s to cancel other actions, tid: %d", c.connID, action, c.startTS)
300+
log.Debugf("con:%d 2PC doActionOnBatches %s to cancel other actions, tid: %d", c.connID, action, c.startTS)
301301
cancel()
302302
}
303303
if err == nil {
@@ -370,7 +370,7 @@ func (c *twoPhaseCommitter) prewriteSingleBatch(bo *Backoffer, batch batchKeys)
370370
if err1 != nil {
371371
return errors.Trace(err1)
372372
}
373-
log.Debugf("[con:%d] 2PC prewrite encounters lock: %v", c.connID, lock)
373+
log.Debugf("con:%d 2PC prewrite encounters lock: %v", c.connID, lock)
374374
locks = append(locks, lock)
375375
}
376376
ok, err := c.store.lockResolver.ResolveLocks(bo, locks)
@@ -478,7 +478,7 @@ func (c *twoPhaseCommitter) commitSingleBatch(bo *Backoffer, batch batchKeys) er
478478
if keyErr := commitResp.GetError(); keyErr != nil {
479479
c.mu.RLock()
480480
defer c.mu.RUnlock()
481-
err = errors.Errorf("[con:%d] 2PC commit failed: %v", c.connID, keyErr.String())
481+
err = errors.Errorf("con:%d 2PC commit failed: %v", c.connID, keyErr.String())
482482
if c.mu.committed {
483483
// No secondary key could be rolled back after it's primary key is committed.
484484
// There must be a serious bug somewhere.
@@ -527,7 +527,7 @@ func (c *twoPhaseCommitter) cleanupSingleBatch(bo *Backoffer, batch batchKeys) e
527527
return errors.Trace(err)
528528
}
529529
if keyErr := resp.BatchRollback.GetError(); keyErr != nil {
530-
err = errors.Errorf("[con:%d] 2PC cleanup failed: %s", c.connID, keyErr)
530+
err = errors.Errorf("con:%d 2PC cleanup failed: %s", c.connID, keyErr)
531531
log.Debugf("2PC failed cleanup key: %v, tid: %d", err, c.startTS)
532532
return errors.Trace(err)
533533
}
@@ -565,9 +565,9 @@ func (c *twoPhaseCommitter) execute(ctx context.Context) error {
565565
err := c.cleanupKeys(NewBackoffer(context.Background(), cleanupMaxBackoff), c.keys)
566566
if err != nil {
567567
metrics.TiKVSecondaryLockCleanupFailureCounter.WithLabelValues("rollback").Inc()
568-
log.Infof("[con:%d] 2PC cleanup err: %v, tid: %d", c.connID, err, c.startTS)
568+
log.Infof("con:%d 2PC cleanup err: %v, tid: %d", c.connID, err, c.startTS)
569569
} else {
570-
log.Infof("[con:%d] 2PC clean up done, tid: %d", c.connID, c.startTS)
570+
log.Infof("con:%d 2PC clean up done, tid: %d", c.connID, c.startTS)
571571
}
572572
c.cleanWg.Done()
573573
})
@@ -597,19 +597,19 @@ func (c *twoPhaseCommitter) execute(ctx context.Context) error {
597597
}
598598
}
599599
if err != nil {
600-
log.Debugf("[con:%d] 2PC failed on prewrite: %v, tid: %d", c.connID, err, c.startTS)
600+
log.Debugf("con:%d 2PC failed on prewrite: %v, tid: %d", c.connID, err, c.startTS)
601601
return errors.Trace(err)
602602
}
603603

604604
commitTS, err := c.store.getTimestampWithRetry(NewBackoffer(ctx, tsoMaxBackoff))
605605
if err != nil {
606-
log.Warnf("[con:%d] 2PC get commitTS failed: %v, tid: %d", c.connID, err, c.startTS)
606+
log.Warnf("con:%d 2PC get commitTS failed: %v, tid: %d", c.connID, err, c.startTS)
607607
return errors.Trace(err)
608608
}
609609

610610
// check commitTS
611611
if commitTS <= c.startTS {
612-
err = errors.Errorf("[con:%d] Invalid transaction tso with start_ts=%v while commit_ts=%v",
612+
err = errors.Errorf("con:%d Invalid transaction tso with start_ts=%v while commit_ts=%v",
613613
c.connID, c.startTS, commitTS)
614614
log.Error(err)
615615
return errors.Trace(err)
@@ -620,21 +620,21 @@ func (c *twoPhaseCommitter) execute(ctx context.Context) error {
620620
}
621621

622622
if c.store.oracle.IsExpired(c.startTS, maxTxnTimeUse) {
623-
err = errors.Errorf("[con:%d] txn takes too much time, start: %d, commit: %d", c.connID, c.startTS, c.commitTS)
623+
err = errors.Errorf("con:%d txn takes too much time, start: %d, commit: %d", c.connID, c.startTS, c.commitTS)
624624
return errors.Annotate(err, txnRetryableMark)
625625
}
626626

627627
err = c.commitKeys(NewBackoffer(ctx, CommitMaxBackoff), c.keys)
628628
if err != nil {
629629
if undeterminedErr := c.getUndeterminedErr(); undeterminedErr != nil {
630-
log.Warnf("[con:%d] 2PC commit result undetermined, err: %v, rpcErr: %v, tid: %v", c.connID, err, undeterminedErr, c.startTS)
630+
log.Warnf("con:%d 2PC commit result undetermined, err: %v, rpcErr: %v, tid: %v", c.connID, err, undeterminedErr, c.startTS)
631631
err = errors.Wrap(err, terror.ErrResultUndetermined)
632632
}
633633
if !c.mu.committed {
634-
log.Debugf("[con:%d] 2PC failed on commit: %v, tid: %d", c.connID, err, c.startTS)
634+
log.Debugf("con:%d 2PC failed on commit: %v, tid: %d", c.connID, err, c.startTS)
635635
return errors.Trace(err)
636636
}
637-
log.Debugf("[con:%d] 2PC succeed with error: %v, tid: %d", c.connID, err, c.startTS)
637+
log.Debugf("con:%d 2PC succeed with error: %v, tid: %d", c.connID, err, c.startTS)
638638
}
639639
return nil
640640
}

table/column.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -171,7 +171,7 @@ func CastValue(ctx sessionctx.Context, val types.Datum, col *model.ColumnInfo) (
171171
continue
172172
}
173173
err = ErrTruncateWrongValue.FastGen("incorrect utf8 value %x(%s) for column %s", casted.GetBytes(), str, col.Name)
174-
log.Errorf("[con:%d] %v", ctx.GetSessionVars().ConnectionID, err)
174+
log.Errorf("con:%d %v", ctx.GetSessionVars().ConnectionID, err)
175175
// Truncate to valid utf8 string.
176176
casted = types.NewStringDatum(str[:i])
177177
err = sc.HandleTruncate(err)

x-server/conn.go

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -51,24 +51,24 @@ func (cc *clientConn) Run() {
5151
tp, payload, err := cc.readPacket()
5252
if err != nil {
5353
if terror.ErrorNotEqual(err, io.EOF) {
54-
log.Errorf("[con:%d] read packet error, close this connection %s",
54+
log.Errorf("con:%d read packet error, close this connection %s",
5555
cc.connectionID, errors.ErrorStack(err))
5656
}
5757
return
5858
}
5959
if err = cc.dispatch(tp, payload); err != nil {
6060
if terror.ErrorEqual(err, terror.ErrResultUndetermined) {
61-
log.Errorf("[con:%d] result undetermined error, close this connection %s",
61+
log.Errorf("con:%d result undetermined error, close this connection %s",
6262
cc.connectionID, errors.ErrorStack(err))
6363
} else if terror.ErrorEqual(err, terror.ErrCritical) {
64-
log.Errorf("[con:%d] critical error, stop the server listener %s",
64+
log.Errorf("con:%d critical error, stop the server listener %s",
6565
cc.connectionID, errors.ErrorStack(err))
6666
select {
6767
case cc.server.stopListenerCh <- struct{}{}:
6868
default:
6969
}
7070
}
71-
log.Warnf("[con:%d] dispatch error: %s, %s", cc.connectionID, cc, err)
71+
log.Warnf("con:%d dispatch error: %s, %s", cc.connectionID, cc, err)
7272
cc.writeError(err)
7373
return
7474
}

0 commit comments

Comments
 (0)