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.

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

[log] better trace log #3914

Merged
merged 11 commits into from
Nov 3, 2023
Merged

[log] better trace log #3914

merged 11 commits into from
Nov 3, 2023

Conversation

millken
Copy link
Contributor

@millken millken commented Aug 3, 2023

Description

Due to the requirement of structured JSON logs for Signoz log collection, the current format of console logs cannot be parsed by Signoz. Additionally, the logs do not contain a trace_id, making it difficult to combine tracing and logs effectively.

This PR addresses these issues by implementing the following changes:

  1. Disable logging in automaxprocs that is not in JSON format.

  2. Wrap the zap.Logger to print the trace_id when there is a api trace log. This requires using log.Ctx(ctx), these logs can be sent to signoz by configuring whether.

image
  1. Fix the issue where JSON encoded logs would still forcefully output console logs.

Fixes #(issue)

Type of change

Please delete options that are not relevant.

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Code refactor or improvement
  • [] Breaking change (fix or feature that would cause a new or changed behavior of existing functionality)
  • [] This change requires a documentation update

How Has This Been Tested?

Please describe the tests that you ran to verify your changes. Provide instructions so we can reproduce. Please also list any relevant details for your test configuration

  • [] make test
  • [] fullsync
  • [] Other test (please specify)

Test Configuration:

  • Firmware version:
  • Hardware:
  • Toolchain:
  • SDK:

Checklist:

  • [] My code follows the style guidelines of this project
  • [] I have performed a self-review of my code
  • [] I have commented my code, particularly in hard-to-understand areas
  • [] I have made corresponding changes to the documentation
  • [] My changes generate no new warnings
  • [] I have added tests that prove my fix is effective or that my feature works
  • [] New and existing unit tests pass locally with my changes
  • [] Any dependent changes have been merged and published in downstream modules

@millken millken requested review from CoderZhi, dustinxie, Liuhaai and a team as code owners August 3, 2023 05:48
@millken millken requested a review from xianhuawei as a code owner August 3, 2023 08:43
@codecov
Copy link

codecov bot commented Aug 3, 2023

Codecov Report

Merging #3914 (2571d1c) into master (e1f0636) will increase coverage by 0.78%.
Report is 93 commits behind head on master.
The diff coverage is 77.14%.

❗ Current head 2571d1c differs from pull request most recent head 8aae37f. Consider uploading reports for the commit 8aae37f to get more accurate results

@@            Coverage Diff             @@
##           master    #3914      +/-   ##
==========================================
+ Coverage   75.38%   76.16%   +0.78%     
==========================================
  Files         303      328      +25     
  Lines       25923    27971    +2048     
==========================================
+ Hits        19541    21303    +1762     
- Misses       5360     5573     +213     
- Partials     1022     1095      +73     
Files Coverage Δ
action/candidate_register.go 90.00% <100.00%> (ø)
action/candidate_update.go 89.01% <100.00%> (+0.12%) ⬆️
action/claimreward.go 90.62% <100.00%> (-0.42%) ⬇️
action/depositreward.go 87.50% <100.00%> (-0.56%) ⬇️
action/protocol/context.go 67.91% <100.00%> (+0.73%) ⬆️
action/protocol/execution/evm/evmstatedbadapter.go 66.77% <ø> (ø)
action/protocol/execution/protocol.go 42.10% <100.00%> (ø)
action/protocol/rewarding/reward.go 90.07% <100.00%> (+0.60%) ⬆️
...tion/protocol/staking/candidate_buckets_indexer.go 89.31% <100.00%> (-0.47%) ⬇️
...col/staking/ethabi/stake_composite_bucketscount.go 100.00% <100.00%> (ø)
... and 67 more

... and 3 files with indirect coverage changes

📣 Codecov offers a browser extension for seamless coverage viewing on GitHub. Try it in Chrome or Firefox today!

@@ -25,7 +25,7 @@ jobs:
- name: Set up Go
uses: actions/setup-go@v3
with:
go-version: 1.18.5
Copy link
Member

Choose a reason for hiding this comment

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

revert if this is not required

Copy link
Contributor Author

Choose a reason for hiding this comment

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

after updating go.mod, need to upgrade to go.1.19

# go.uber.org/multierr
Error: ../../../go/pkg/mod/go.uber.org/[email protected]/error.go:209:20: undefined: atomic.Bool
note: module requires Go 1.19
# go.opentelemetry.io/otel/sdk/trace
Error: ../../../go/pkg/mod/go.opentelemetry.io/otel/[email protected]/trace/provider.go:78:24: undefined: atomic.Pointer
Error: ../../../go/pkg/mod/go.opentelemetry.io/otel/[email protected]/trace/provider.go:80:20: undefined: atomic.Bool
note: module requires Go 1.19
Error: Process completed with exit code 2.

@@ -28,7 +28,7 @@ jobs:
- name: Set up Go
uses: actions/setup-go@v2
with:
go-version: 1.18.5
Copy link
Member

Choose a reason for hiding this comment

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

revert if this is not required

@@ -64,14 +63,12 @@ func newHTTPHandler(web3Handler Web3Handler) *hTTPHandler {
}

func (handler *hTTPHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {
ctx, span := tracer.NewSpan(req.Context(), "handler.ServeHTTP")
defer span.End()
Copy link
Member

Choose a reason for hiding this comment

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

there are other places calling tracer.NewSpan(), should same changes be applied there as well?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes, can remove this later and use log.Ctx instead. But it can be used when there are special needs (such as funcs spent time)

actually log.Ctxis an event in the span

)

// Ctx is a wrapper of otelzap.Ctx, returns a logger with context.
func Ctx(ctx context.Context) otelzap.LoggerWithCtx {
Copy link
Member

Choose a reason for hiding this comment

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

The name Ctx may be misleading. Using T(ctx) may be a better alternative as it denotes tracing, and is consistent with the L() and S() methods in log pkg.

@sonarqubecloud
Copy link

sonarqubecloud bot commented Aug 7, 2023

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

No Coverage information No Coverage information
0.0% 0.0% Duplication

@@ -115,6 +126,9 @@ func InitLoggers(globalCfg GlobalConfig, subCfgs map[string]GlobalConfig, opts .
zap.RedirectStdLog(logger)
}
zap.ReplaceGlobals(logger)
if err := initTraceLogger(logger, cfg.Trace); err != nil {
Copy link
Member

Choose a reason for hiding this comment

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

why is it initiated here?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

trace logger needs to wrap a global zap logger, here is global zap logger initiated

)

// T is a wrapper of otelzap.Ctx, returns a logger with context.
func T(ctx context.Context) otelzap.LoggerWithCtx {
Copy link
Member

@Liuhaai Liuhaai Aug 10, 2023

Choose a reason for hiding this comment

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

listen logs from L(), etc.

Copy link
Contributor Author

@millken millken Aug 10, 2023

Choose a reason for hiding this comment

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

after initTraceLogger, T(ctx) and L() use the same zap logger.

In different , T(ctx) will additionally attach some trace fields and send them to the trace provider(jaeger/signoz)

Copy link
Member

Choose a reason for hiding this comment

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

ok. Does the tracer work as before with this pr?

server/main.go Outdated
@@ -73,6 +73,8 @@ func init() {
}

func main() {
// set max number of CPUs, disable log printing
maxprocs.Set(maxprocs.Logger(nil))
Copy link
Member

@Liuhaai Liuhaai Aug 10, 2023

Choose a reason for hiding this comment

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

only for json format?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

yes, Its log is not controlled by zap and will break the format of zap json log

Copy link
Member

Choose a reason for hiding this comment

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

this line will be executed even if for console format

@sonarqubecloud
Copy link

sonarqubecloud bot commented Sep 8, 2023

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

No Coverage information No Coverage information
0.0% 0.0% Duplication

Copy link

sonarqubecloud bot commented Nov 3, 2023

Kudos, SonarCloud Quality Gate passed!    Quality Gate passed

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

No Coverage information No Coverage information
0.0% 0.0% Duplication

@millken millken merged commit 32cbd3c into iotexproject:master Nov 3, 2023
3 checks passed
@dustinxie dustinxie mentioned this pull request Nov 16, 2023
10 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants