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

Jump to bottom

ddl: add conn and session_alias entry in ddl worker log #46443

Merged
merged 2 commits into from
Aug 29, 2023
Merged

ddl: add conn and session_alias entry in ddl worker log #46443

merged 2 commits into from
Aug 29, 2023

Conversation

lcwangchao
Copy link
Collaborator

What problem does this PR solve?

Issue Number: close #46441, ref #46071

What is changed and how it works?

After this PR, we can trace the ddl worker logs by conn or session_alias field to figure out where this ddl job come from, for example:

TiDB root@127.0.0.1:test> set @@session.tidb_session_alias="alias123";
Query OK, 0 rows affected
Time: 0.002s
TiDB root@127.0.0.1:test> create table t1(a int);
Query OK, 0 rows affected
Time: 0.040s

log:

[2023/08/28 14:47:58.899 +08:00] [INFO] [ddl_worker.go:615] ["finish DDL job"] [worker="worker 1, tp general"] [category=ddl] [jobID=217] [conn=2097154] [session_alias=alias123] [job="ID:217, Type:create table, State:synced, SchemaState:public, SchemaID:2, TableID:216, RowCount:0, ArgLen:0, start time: 2023-08-28 14:47:58.883 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0"]

Check List

Tests

  • Unit test
  • Integration test
  • Manual test (add detailed scripts or steps below)
  • No code

Side effects

  • Performance regression: Consumes more CPU
  • Performance regression: Consumes more Memory
  • Breaking backward compatibility

Documentation

  • Affects user behaviors
  • Contains syntax changes
  • Contains variable changes
  • Contains experimental features
  • Changes MySQL compatibility

Release note

Please refer to Release Notes Language Style Guide to write a quality release note.

Add some trace info in ddl worker log

@lcwangchao lcwangchao requested a review from a team as a code owner August 28, 2023 06:49
@ti-chi-bot ti-chi-bot bot added release-note Denotes a PR that will be considered when it comes time to generate release notes. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Aug 28, 2023
@lcwangchao lcwangchao removed the request for review from a team August 28, 2023 06:53
@codecov
Copy link

codecov bot commented Aug 28, 2023 •
edited
Loading

Codecov Report

Merging #46443 (2752e01) into master (c11a999) will decrease coverage by 0.6894%.
Report is 10 commits behind head on master.
The diff coverage is 82.0000%.

Additional details and impacted files 
@@               Coverage Diff                @@
##             master     #46443        +/-   ##
================================================
- Coverage   73.4208%   72.7314%   -0.6894%     
================================================
  Files          1295       1320        +25     
  Lines        393759     400924      +7165     
================================================
+ Hits         289101     291598      +2497     
- Misses        86294      90848      +4554     
- Partials      18364      18478       +114
Flag Coverage Δ
integration 25.8068% <44.8979%> (?)
unit 73.4211% <82.0000%> (+0.0003%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Components Coverage Δ
dumpling 54.0444% <ø> (ø)
parser 85.0638% <100.0000%> (-0.0103%) ⬇️
br 48.0046% <ø> (-4.3005%) ⬇️

@lcwangchao
Copy link
Collaborator Author

/retest

@ti-chi-bot ti-chi-bot bot added approved needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Aug 28, 2023
zimulala
zimulala reviewed Aug 29, 2023
View reviewed changes
ddl/ddl_worker.go
@@ -167,7 +178,7 @@ func (w *worker) Close() {
w.sessPool.Put(w.sess.Session())
}
w.wg.Wait()
logutil.Logger(w.logCtx).Info("DDL worker closed", zap.String("category", "ddl"), zap.Duration("take time", time.Since(startTime)))
logutil.Logger(w.logCtx).Info("DDL worker closed", zap.Duration("take time", time.Since(startTime)))
Copy link
Contributor

Choose a reason for hiding this comment

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

Missing w.jobLogger(job) here?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

There is no job ref here because the stop method is not related to any job. I removed zap.String("category", "ddl") because the logger in w.logCtx contains this field already: https://github.com/pingcap/tidb/pull/46443/files#diff-dfc42c5764e7e4ff9122a1db728ff1cb0dee56e72dbccefdb211018ccd444c73R143

Copy link
Contributor

Choose a reason for hiding this comment

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

Ok, but I see that your function(jobLogger ) actually has a check to determine if the job is empty. So I'm asking.

zimulala
zimulala reviewed Aug 29, 2023
View reviewed changes
ddl/ddl_worker.go Outdated
traceInfo = job.TraceInfo
}
return logutil.LoggerWithTraceInfo(
logutil.Logger(w.logCtx).With(zap.Int64("jobID", job.ID)),
Copy link
Contributor

Choose a reason for hiding this comment

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

We check job != nil in line149 before getting traceInfo, how about job.ID?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

done

okJiang
okJiang approved these changes Aug 29, 2023
View reviewed changes
Copy link
Member

@okJiang okJiang left a comment

Choose a reason for hiding this comment

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

lgtm except existed conversation

@ti-chi-bot ti-chi-bot bot added lgtm and removed needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Aug 29, 2023
@ti-chi-bot
Copy link

ti-chi-bot bot commented Aug 29, 2023

[LGTM Timeline notifier]

Timeline:

  • 2023-08-28 08:44:46.697090888 +0000 UTC m=+1743851.246106860: ☑️ agreed by tangenta.
  • 2023-08-29 02:50:34.676516121 +0000 UTC m=+1808999.225532093: ☑️ agreed by okJiang.

@lcwangchao
Copy link
Collaborator Author

/hold

@ti-chi-bot ti-chi-bot bot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Aug 29, 2023
@lcwangchao
Copy link
Collaborator Author

/unhold

@ti-chi-bot ti-chi-bot bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Aug 29, 2023
@ti-chi-bot
Copy link

ti-chi-bot bot commented Aug 29, 2023

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: okJiang, tangenta, zimulala

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:
  • OWNERS [okJiang,tangenta,zimulala]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@hawkingrei
Copy link
Member

/retest

@ti-chi-bot ti-chi-bot bot merged commit 2fa680d into pingcap:master Aug 29, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@zimulala zimulala zimulala approved these changes

@okJiang okJiang okJiang approved these changes

@tangenta tangenta tangenta approved these changes

Assignees
No one assigned
Labels
approved lgtm release-note Denotes a PR that will be considered when it comes time to generate release notes. size/L Denotes a PR that changes 100-499 lines, ignoring generated files.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

add conn and session_alias entry in ddl worker log
5 participants
@lcwangchao @hawkingrei @zimulala @okJiang @tangenta