Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

logutil/dxf: add a error verbose logger, and use it in DXF #58185

Merged
merged 2 commits into from
Dec 12, 2024

Conversation

D3Hunter
Copy link
Contributor

@D3Hunter D3Hunter commented Dec 12, 2024

What problem does this PR solve?

Issue Number: ref #57497

Problem Summary:

What changed and how does it work?

see #56014 too

// error verbose is disabled on default, but without stack it's harder to investigate
// some issues, such as in DXF the error mostly happen in business logic, the
// error stack is very deep, we want to log the stack to help us investigate.
// Note: if stack is not that needed to investigate, use normal logger instead.

Check List

Tests

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

apply this patch

diff --git a/pkg/disttask/framework/taskexecutor/manager.go b/pkg/disttask/framework/taskexecutor/manager.go
index 43179a6ba0..bca8e50fd2 100644
--- a/pkg/disttask/framework/taskexecutor/manager.go
+++ b/pkg/disttask/framework/taskexecutor/manager.go
@@ -84,6 +84,8 @@ func NewManager(ctx context.Context, id string, taskTable TaskTable) (*Manager,
 	if intest.InTest {
 		logger = logger.With(zap.String("server-id", id))
 	}
+	logger.Error("error verbose logger", zap.Error(errors.New("some error")))
+	logutil.BgLogger().Error("normal logger", zap.Error(errors.New("some error")))
 	totalMem, err := memory.MemTotal()
 	if err != nil {
 		// should not happen normally, as in main function of tidb-server, we assert

run tidb with json fmt

{"level":"ERROR","time":"2024/12/12 10:50:21.940 +08:00","caller":"manager.go:87","message":"error verbose logger","error":"some error","errorVerbose":"some error\ngithub.heygears.com/pingcap/tidb/pkg/disttask/framework/taskexecutor.NewManager\n\t/Users/jujiajia/code/pingcap/tidb/pkg/disttask/framework/taskexecutor/manager.go:87\ngithub.heygears.com/pingcap/tidb/pkg/domain.(*Domain).InitDistTaskLoop\n\t/Users/jujiajia/code/pingcap/tidb/pkg/domain/domain.go:1758\ngithub.heygears.com/pingcap/tidb/pkg/session.bootstrapSessionImpl\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3664\ngithub.heygears.com/pingcap/tidb/pkg/session.BootstrapSession\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3406\nmain.createStoreDDLOwnerMgrAndDomain\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:418\nmain.main\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:321\nruntime.main\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/proc.go:272\nruntime.goexit\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/asm_arm64.s:1223"}
{"level":"ERROR","time":"2024/12/12 10:50:21.940 +08:00","caller":"manager.go:88","message":"normal logger","error":"some error","errorVerbose":"some error\ngithub.heygears.com/pingcap/tidb/pkg/disttask/framework/taskexecutor.NewManager\n\t/Users/jujiajia/code/pingcap/tidb/pkg/disttask/framework/taskexecutor/manager.go:88\ngithub.heygears.com/pingcap/tidb/pkg/domain.(*Domain).InitDistTaskLoop\n\t/Users/jujiajia/code/pingcap/tidb/pkg/domain/domain.go:1758\ngithub.heygears.com/pingcap/tidb/pkg/session.bootstrapSessionImpl\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3664\ngithub.heygears.com/pingcap/tidb/pkg/session.BootstrapSession\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3406\nmain.createStoreDDLOwnerMgrAndDomain\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:418\nmain.main\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:321\nruntime.main\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/proc.go:272\nruntime.goexit\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/asm_arm64.s:1223"}

run with default config

[2024/12/12 10:47:17.846 +08:00] [ERROR] [manager.go:87] ["error verbose logger"] [error="some error"] [errorVerbose="some error\ngithub.heygears.com/pingcap/tidb/pkg/disttask/framework/taskexecutor.NewManager\n\t/Users/jujiajia/code/pingcap/tidb/pkg/disttask/framework/taskexecutor/manager.go:87\ngithub.heygears.com/pingcap/tidb/pkg/domain.(*Domain).InitDistTaskLoop\n\t/Users/jujiajia/code/pingcap/tidb/pkg/domain/domain.go:1758\ngithub.heygears.com/pingcap/tidb/pkg/session.bootstrapSessionImpl\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3664\ngithub.heygears.com/pingcap/tidb/pkg/session.BootstrapSession\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3406\nmain.createStoreDDLOwnerMgrAndDomain\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:418\nmain.main\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:321\nruntime.main\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/proc.go:272\nruntime.goexit\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/asm_arm64.s:1223"]
[2024/12/12 10:47:17.846 +08:00] [ERROR] [manager.go:88] ["normal logger"] [error="some error"]

run with enable-error-stack = true

[2024/12/12 11:05:36.750 +08:00] [ERROR] [manager.go:87] ["error verbose logger"] [error="some error"] [errorVerbose="some error\ngithub.heygears.com/pingcap/tidb/pkg/disttask/framework/taskexecutor.NewManager\n\t/Users/jujiajia/code/pingcap/tidb/pkg/disttask/framework/taskexecutor/manager.go:87\ngithub.heygears.com/pingcap/tidb/pkg/domain.(*Domain).InitDistTaskLoop\n\t/Users/jujiajia/code/pingcap/tidb/pkg/domain/domain.go:1758\ngithub.heygears.com/pingcap/tidb/pkg/session.bootstrapSessionImpl\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3664\ngithub.heygears.com/pingcap/tidb/pkg/session.BootstrapSession\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3406\nmain.createStoreDDLOwnerMgrAndDomain\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:418\nmain.main\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:321\nruntime.main\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/proc.go:272\nruntime.goexit\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/asm_arm64.s:1223"]
[2024/12/12 11:05:36.750 +08:00] [ERROR] [manager.go:88] ["normal logger"] [error="some error"] [errorVerbose="some error\ngithub.heygears.com/pingcap/tidb/pkg/disttask/framework/taskexecutor.NewManager\n\t/Users/jujiajia/code/pingcap/tidb/pkg/disttask/framework/taskexecutor/manager.go:88\ngithub.heygears.com/pingcap/tidb/pkg/domain.(*Domain).InitDistTaskLoop\n\t/Users/jujiajia/code/pingcap/tidb/pkg/domain/domain.go:1758\ngithub.heygears.com/pingcap/tidb/pkg/session.bootstrapSessionImpl\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3664\ngithub.heygears.com/pingcap/tidb/pkg/session.BootstrapSession\n\t/Users/jujiajia/code/pingcap/tidb/pkg/session/session.go:3406\nmain.createStoreDDLOwnerMgrAndDomain\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:418\nmain.main\n\t/Users/jujiajia/code/pingcap/tidb/cmd/tidb-server/main.go:321\nruntime.main\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/proc.go:272\nruntime.goexit\n\t/Users/jujiajia/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.23.4.darwin-arm64/src/runtime/asm_arm64.s:1223"]
  • No need to test
    • I checked and no code files have been changed.

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.

None

@ti-chi-bot ti-chi-bot bot added release-note-none Denotes a PR that doesn't merit a release note. size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Dec 12, 2024
Copy link

tiprow bot commented Dec 12, 2024

Hi @D3Hunter. Thanks for your PR.

PRs from untrusted users cannot be marked as trusted with /ok-to-test in this repo meaning untrusted PR authors can never trigger tests themselves. Collaborators can still trigger tests on the PR using /test all.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

@D3Hunter D3Hunter requested a review from lance6716 December 12, 2024 03:22
@D3Hunter
Copy link
Contributor Author

/retest

Copy link

tiprow bot commented Dec 12, 2024

@D3Hunter: Cannot trigger testing until a trusted user reviews the PR and leaves an /ok-to-test message.

In response to this:

/retest

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

Copy link

codecov bot commented Dec 12, 2024

Codecov Report

Attention: Patch coverage is 86.36364% with 3 lines in your changes missing coverage. Please review.

Project coverage is 73.7085%. Comparing base (7e34efa) to head (7fbbfa4).
Report is 65 commits behind head on master.

Additional details and impacted files
@@               Coverage Diff                @@
##             master     #58185        +/-   ##
================================================
+ Coverage   73.2045%   73.7085%   +0.5040%     
================================================
  Files          1675       1676         +1     
  Lines        461929     463341      +1412     
================================================
+ Hits         338153     341522      +3369     
+ Misses       102987     101068      -1919     
+ Partials      20789      20751        -38     
Flag Coverage Δ
integration 43.2419% <50.0000%> (?)
unit 72.4284% <86.3636%> (+0.0878%) ⬆️

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

Components Coverage Δ
dumpling 52.6910% <ø> (ø)
parser ∅ <ø> (∅)
br 45.9728% <ø> (-0.0211%) ⬇️

@ti-chi-bot ti-chi-bot bot added approved needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Dec 12, 2024
@ti-chi-bot ti-chi-bot bot added lgtm and removed needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Dec 12, 2024
Copy link

ti-chi-bot bot commented Dec 12, 2024

[LGTM Timeline notifier]

Timeline:

  • 2024-12-12 09:03:52.594856556 +0000 UTC m=+515622.683659099: ☑️ agreed by lance6716.
  • 2024-12-12 09:35:16.888069165 +0000 UTC m=+517506.976871709: ☑️ agreed by Defined2014.

Copy link

ti-chi-bot bot commented Dec 12, 2024

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: Defined2014, lance6716, tangenta

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:

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

@ti-chi-bot ti-chi-bot bot merged commit e62963d into pingcap:master Dec 12, 2024
23 checks passed
@D3Hunter D3Hunter deleted the stack-logger branch December 12, 2024 12:20
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
approved lgtm release-note-none Denotes a PR that doesn't merit a release note. size/M Denotes a PR that changes 30-99 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants