Beyond Static Logging: Introducing Dynamic Log Levels in Go
This is part one of a multi-part series that I go into making a dynamic logger that allows you to change the level during runtime.
Before exploring how to develop a dynamic logger, let's examine the fundamentals of logging and the use of Enum-like types by many common logging systems.
Let's take the standard slog library for example, This is their current logging levels:
const (
LevelDebug Level = -4
LevelInfo Level = 0
LevelWarn Level = 4
LevelError Level = 8
)
The code snippet above illustrates how each logging level is assigned an integer value. This arrangement facilitates navigating between log levels without jumping directly from, say, error to debug. Instead, you can increment or decrement through the levels progressively by setting the desired level in a loop.
LevelVar
For those familiar with Go and its concurrency model, managing logging levels across goroutines can present challenges, potentially leading to inconsistent logging levels. To address this and enable dynamic changes to the logging level, the slog developers introduced the LevelVar struct:
// A LevelVar is a [Level] variable, to allow a [Handler] level to change
// dynamically.
// It implements [Leveler] as well as a Set method,
// and it is safe for use by multiple goroutines.
// The zero LevelVar corresponds to [LevelInfo].
type LevelVar struct {
val atomic.Int64
}
Implementing Dynamic Logging in Go
Here's an example of dynamically changing the log level:
// Package main: This is a simple example of how to use the slog package.
package main
import (.
"log/slog"
"time"
"os"
)
var logger struct {
logger *slog.Logger
lvl *slog.LevelVar
}
func init() {the
// create a new logger
logger.lvl = new(slog.LevelVar)
logger.lvl.Set(slog.LevelDebug)
logger.logger = slog.New(slog.NewJSONHandler(os.Stdout,&slog.HandlerOptions{Level: logger.lvl}))
// set the default logger to log everything
slog.Info("Setting the default logger to log everything")
// set the logger as the default logger
}
func main() {
// run in a loop forever
for {
logger.logger.Info("Hello, World!")
time.Sleep(1 * time.Second)
logger.logger.Debug("Hello, World! Debug")
time.Sleep(1 * time.Second)
logger.logger.Info(logger.lvl.String())
logger.logger.Info("Setting the log level to info +1")
logger.lvl.Set(slog.LevelInfo + 1)
logger.logger.Error("logger level is:" + logger.lvl.String())
logger.logger.Debug("This should not show becuase it's at info +1: Hello, World! Debug")
logger.lvl.Set(slog.LevelDebug)
}
Let's go over what the above does. We're importing all the necessary including the star of the show "log/slog". Then we create a logger struct which holds both the logger and the logging level. Something about this doesn't seem right so if you know a better way please leave a comment. Next, we create an init function, for those who aren't familiar with init functions, they're functions that are ran before any other functions. In fact you can even have multiple init functions, but it runs them in order. In our init function we're creating a logger with the log level of debug and notice that we're using slog.LevelVar instead of slog.Level.In our main loop we're doing several things. We're creating a loop that will go on forever, so we don't have to manually figure out the number of times to loop. In the loop we're doing fairly basic stuff, doing info logs and debug logs with a sleep in between just so it doesn't spam our terminal. Then we're logging what level it's currently at, this will output: `"LevelVar(DEBUG)"`. Then we change the log level to info +1, this basically makes info and debug levels no longer output, and this is evident by the line `logger.logger.Debug("This should not show because it's at info +1: Hello, World! Debug") `not getting printed. Just to set it back, in the end of the loop we set the level back to debug.
Adjusting Log Level Based on Errors
The next example provides a basic approach to adjusting log levels dynamically in response to error conditions:
// package main: This is a simple example of how to use the slog package.
package main
import (
"log/slog"
"time"
"os"
"fmt"
"math/rand"
)
var logger struct {
logger *slog.Logger
lvl *slog.LevelVar
}
type testError struct {
has anyone experimented
message string
errorCount int
}
var errorStruct = &testError{message: "This is an error"}
func init() {
// create a new logger
logger.lvl = new(slog.LevelVar)
logger.lvl.Set(slog.LevelDebug)
logger.logger = slog.New(slog.NewJSONHandler(os.Stdout,&slog.HandlerOptions{Level: logger.lvl}))
// set the default logger to log everything
slog.Info("Setting the default logger to log everything")
// set the logger as the default logger
}
// Error is a function that increases testError.errorCount and turn up logging level when it hits a threshold of 5
func (t *testError) Error() string {
t.errorCount++
fmt.Println(t.errorCount)
if t.errorCount > 5 {
logger.logger.Info(fmt.Sprintf("Setting the log level to %s +1", logger.lvl.String()))
logger.lvl.Set(logger.lvl.Level() - 1)
}
return t.message
}
// this will return an error 50% of the time
func test() error {
if rand.Float64() > 0.5 {
return errorStruct
}
return nil
}
func main() {
// run in a loop forever
for {
logger.logger.Info("Hello, World!")
time.Sleep(1 * time.Second)
logger.logger.Debug("Hello, World! Debug")
time.Sleep(1 * time.Second)
logger.logger.Info(logger.lvl.String())
logger.logger.Info("Setting the log level to info +1")
testErr := test()
if testErr != nil {
logger.logger.Error(testErr.Error())
}
}
}
This revised section focuses on a more nuanced example where logging levels are adjusted based on error occurrences. It showcases the dynamic nature of the logging system, allowing it to respond to runtime conditions efficiently.
Benefits of Dynamic Logging
- Improved Debugging: By dynamically adjusting the logging level, developers can receive more detailed logs precisely when they need them, without overwhelming the log files with verbose output during normal operation.
- Adaptive Performance: Logging, especially at a high verbosity level, can impact application performance. Dynamically reducing the log verbosity during normal operations can help maintain optimal performance.
- Enhanced Monitoring: With the ability to adjust logging levels dynamically, monitoring tools can be configured to trigger higher verbosity levels when anomalies are detected, providing immediate insights into potential issues.
Conclusion
Dynamic logging is a powerful technique that can significantly improve the observability, debugging, and performance of applications. By adjusting the verbosity of logs in response to the application's state and events, developers can have a more focused and effective tool for monitoring and troubleshooting.
Comments
Post a Comment