-
Notifications
You must be signed in to change notification settings - Fork 836
PoC: global shim for logger #4085
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
base: master
Are you sure you want to change the base?
Conversation
I think we want to add something about the compile time usage of this feature to the README. Mention the default, and how to compile the alternate logger in. |
@bsardo mentioned that a similar thing is done with the time package - will take a look |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@zhongshixi This is very similar to an idea you wanted to implement. Could you please review this PR instead and share your views?
.semgrep/adapter/package-import.go
Outdated
@@ -6,7 +6,7 @@ import ( | |||
// ruleid: package-import-check | |||
"github.com/mitchellh/copystructure" | |||
// ruleid: package-import-check | |||
"github.com/golang/glog" | |||
"github.com/prebid/prebid-server/v3/di" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This code tests the semgrep rule. Please review the rule to check if any changes to the semgrep definition is required,
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
the semgrep rule seems to be checking that either of glog
or copystructure
packages is not used in the adapters, so I reverted this change to the package-import.go
.
di/di.go
Outdated
@@ -0,0 +1,8 @@ | |||
package di |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I prefer if this is called the "logger" package, which is more intuitive. I don't know if we'd want to put all global state items in one package and currently there is only one. For simplicity, I'd like to see the interfaces and providers packages collapsed up to this level under the same "logger" package.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
renamed
di/interfaces/log.go
Outdated
@@ -0,0 +1,18 @@ | |||
package interfaces | |||
|
|||
type ILogger interface { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nitpick: The Java / C# naming convention does not apply to Go. It is most appropriate to name this "Logger".
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
renamed
di/providers/log/default.go
Outdated
"github.com/prebid/prebid-server/v3/di/interfaces" | ||
) | ||
|
||
type GlogWrapper struct { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nitpick: GlogLogger would be more direct name.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
renamed
di/providers/log/alternative.go
Outdated
@@ -0,0 +1,74 @@ | |||
//go:build custom_logger |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This project does not currently use build directives to choose features. Instead, we offer a configuration system.
I like the idea of having a global log variable to override. I've seen the same in other Go projects, and it provides support for #3961. I propose to keep this ability, while also providing a config option to switch to slog from glog.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This build tag is actually not required, it's just one potential mechanism that could be used to swap a dependency in compile time, so can probably removed. Configuration would require shipping both implementations and then have them swapped in runtime depending on the configuration, while compile time would only ship a single dependency. Just to be clear, by configuration - do you mean a host-level config file pbs.yaml / pbs.json right?
@justadreamer we'll try to revisit this in a few weeks. Sorry for the delay. |
This was discussed at the last engineering subcommittee meeting. The suggestion was to move from a compile time config to a runtime config. |
…tructure of the logger: encapsulate the logger object, call only external functions
# Conflicts: # modules/fiftyonedegrees/devicedetection/device_info_extractor.go
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Consider to use build flags to include only one logging lib instead of bringing up more libs to the project codebase
logger/alternative.go
Outdated
} | ||
|
||
func (logger *SlogWrapper) Info(args ...any) { | ||
msg := fmt.Sprint(args...) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The issue with this logger that glog or fmt.Sprintf use sync.Pool with buffer reuse but this logger always allocates a string to store message and pass it to the underlying function. At least this package should use sync.Pool to store formatted msg
to bypass GC
buf := new(bytes.Buffer) // get it from sync.Pool
msg := fmt.Fprintf(buf, args...) //it takes io.Writer
slog.Info(buf.String()) // better to pass io.Reader instead of the string
// put buf back to pool
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
this file will be removed as @bsardo mentioned on the call. build tags were used originally and were discarded by the committee in favor of runtime configuration.
config/config.go
Outdated
@@ -724,8 +732,10 @@ func New(v *viper.Viper, bidderInfos BidderInfos, normalizeBidderName openrtb_ex | |||
return nil, err | |||
} | |||
|
|||
logger.New(c.Logger.Type, c.Logger.Depth) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We should validate Type
is a valid string value
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Type validation added
README.md
Outdated
This can be done compile-time in the `logger` package. | ||
It contains `Logger` interface definition and `default` and `alternative` implementation. | ||
The `default` logger implementation based on `github.com/golang/glog` package. | ||
The `alternative` logger implementation based on `log/slog` package. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Delete line since we are proposing removing the alternative
logger implementation for now.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
type Logger struct { | ||
// the type of logger: default or alternative | ||
Type string `mapstructure:"type"` | ||
Depth *int `mapstructure:"depth"` |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm curious why this is a pointer? I imagine you want to detect presence for some reason. Is it because you want to know whether to apply some default depth if depth
is not specified? What should the default be? Do you think it will dependent on the implementation?
I see you're detecting presence via a nil check and have declared a default depth of 1 in logger.go
.
Should we verify that depth
is > 0 or >= 0? What happens if depth
is some large number? Perhaps validation is needed for the upper bound as well?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Should we verify that depth is > 0 or >= 0? What happens if depth is some large number? Perhaps validation is needed for the upper bound as well?
Fun fact: glog has no depth validation within itself:
https://github.com/golang/glog/blob/master/glog.go#L432
Re-check source code will show the same.
// If Depth is present, this function calls log from a different depth in the call stack.
// This enables a callee to emit logs that use the callsite information of its caller
// or any other callers in the stack. When depth == 0, the original callee's line
// information is emitted. When depth > 0, depth frames are skipped in the call stack
// and the final frame is treated like the original callee to Info.
I've tested with different values.
What I've got:
- -1000
glog.ErrorDepth(-1000, "Hello World")
Log:
extern.go:304] Hello World
- 0
glog.ErrorDepth(0, "Hello World")
Log:
main.go:8] Hello World
- 1000
glog.ErrorDepth(0, "Hello World")
Log:
???:1] Hello World
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't know in what range to validate the value, because glog doesn't have such validation, and the current implementation doesn't have any alternatives for it now.
logger/default.go
Outdated
glog.FatalDepthf(logger.depth, format, args...) | ||
} | ||
|
||
func ProvideDefaultLogger(depth int) Logger { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nitpick: maybe call this NewDefaultLogger
to follow patterns throughout the code base?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
logger/interface.go
Outdated
Warning(args ...any) | ||
Warningf(format string, args ...any) | ||
Warningln(args ...any) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Do we need Warningln
? The default implementation is the same as Warning
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Removed
logger/alternative.go
Outdated
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Let's delete this file. We can add an slog implementation in the future. For now, simply defining the logger interface and the glog implementation suffices.
In the future we will expand the interface to include functions that are more suitable for structured logging .
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Removed
# Conflicts: # stored_requests/backends/http_fetcher/fetcher.go # stored_requests/config/config.go
…with thread-safe operations; introduced extensive unit tests for the new logger structure.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The code itself looks good. Not all that happy about the global state of the logger, but it is not supposed to change while actually running. A proper dependency injection framework would make this PR much larger.
@hhhjort, may I ask you to re-review? |
… custom logger handling
Added StructuredLogger interface.
# Conflicts: # exchange/bidder.go
…GlogLogger, and included helper methods with comprehensive tests
…proved message handling; reduced logger imports where possible
…lated logic and tests
Logger ImprovementsPR: https://github.com/prebid/prebid-server/pull/4085/commits New Simplified Interfacetype Logger interface {
// Debug level logging
Debug(msg any, args ...any)
DebugContext(ctx context.Context, msg any, args ...any)
// Info level logging
Info(msg any, args ...any)
InfoContext(ctx context.Context, msg any, args ...any)
// Warn level logging
Warn(msg any, args ...any)
WarnContext(ctx context.Context, msg any, args ...any)
// Error level logging
Error(msg any, args ...any)
ErrorContext(ctx context.Context, msg any, args ...any)
} Logger Initialization and BehaviorSupported Logger TypesYou can choose one of the supported logger types during initialization: const (
LoggerTypeSlog LoggerType = "slog"
LoggerTypeGlog LoggerType = "glog"
LoggerTypeCustom LoggerType = "custom"
) Slog and Glog work out of the box for both print-style and structured logging. You can also provide your own implementation (LoggerTypeCustom) if you need custom behavior. Common Method Signature Both loggers share the same method signature: Where: msg — the main log message Argument Processing Differences Glog — concatenates all arguments into a single string, separated by ,. Ensuring Correct Output FormattingSlog
To ensure consistent output and avoid unexpected substitutions, the original log messages are wrapped in: fmt.Sprintf("%s", data) This ensures that the message is passed to the logger as a complete string, with no unresolved %s placeholders.
Correct usage logger.Info(fmt.Sprintf("%s server starting on: %s", name, server.Addr)) Result
Structured logging example logger.Info(
fmt.Sprintf("%s server starting on: %s", name, server.Addr),
"key1", "value1",
"key2", "value2",
) Result
Conclusion: By wrapping the message in fmt.Sprintf(...), we keep the original formatting and at the same time allow the use of structured arguments when needed. GlogGlog does not support structured logging. It only accepts a preformatted message and simply outputs it as a flat string. If you try to provide additional key/value style parameters (as you would in structured logging), they will be concatenated directly into the message: Example
Result
To preserve backward compatibility and ensure that both formatted and pseudo-structured messages work correctly, the wrapper for glog concatenates all parameters using " ," as a separator and passes the resulting string to glog. This provides consistent behavior (formatted string output) while still allowing additional parameters to be included in the output. Result
Fatal Error Handling In the current logger interface implementation, there is no Fatal method.
This ensures the error is logged properly before the application shuts down. Logger Initialization at Server StartupWhen the server starts, logger parameters are selected from the host configuration. Example Configuration"logger": {
"type": "slog",
} type — logger type (slog, glog, or custom). Default Values If parameters are not explicitly set, the following defaults are applied:
|
# Conflicts: # floors/fetcher.go
This PR introduces a
logger
shim and was meant to accompany a more global proposal: #4084. With this different loggers can be swapped in compile-time, however leaving the possibility to also swap a global instance in runtime (during tests f.e.)The global object is instantiated in logger/logger.go, the interface is defined in
logger/interface.go
, while implementations of loggers are inlogger/default.go
andlogger/alternative.go
.