Improve paho logging and debug logging in general #31
Conversation
Make it so we can tag messages from paho internal logging in the slog messages, so we can now what part of paho created the message. This also resulted in using the slog Debug level properly. edm will now set the slog loglevel to debug if the --debug flag is passed. This also resulted in some cleanup of the more verbose debug messages left in the code so it is actuallu possible to run edm on a real system with --debug enabled without generating massive amount of log messages.
WalkthroughThe changes introduced in this pull request primarily enhance the logging functionality across multiple files. A new variable Changes
Sequence Diagram(s)sequenceDiagram
participant Main
participant Cmd
participant Runner
participant MQTT
Main->>Cmd: Execute(logger, loggerLevel)
Cmd->>Runner: Run(logger, loggerLevel)
Runner->>MQTT: Configure logging with loggerLevel
MQTT->>MQTT: Use structured logging
Warning Rate limit exceeded@eest has exceeded the limit for the number of commits or files that can be reviewed per hour. Please wait 13 minutes and 28 seconds before requesting another review. ⌛ How to resolve this issue?After the wait time has elapsed, a review can be triggered using the We recommend that you space out your commits to avoid hitting the rate limit. 🚦 How do rate limits work?CodeRabbit enforces hourly rate limits for each developer per organization. Our paid plans have higher rate limits than the trial, open-source and free plans. In all cases, we re-allow further reviews after a brief timeout. Please see our FAQ for further information. Thank you for using CodeRabbit. We offer it for free to the OSS community and would appreciate your support in helping us grow. If you find it useful, would you consider giving us a shout-out on your favorite social media? 🪧 TipsChatThere are 3 ways to chat with CodeRabbit:
Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments. CodeRabbit Commands (Invoked using PR comments)
Other keywords and placeholders
CodeRabbit Configuration File (
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 1
🧹 Outside diff range and nitpick comments (3)
cmd/root.go (1)
30-30: Consider adding documentation for the new parameter.The function signature has been updated, but the documentation above it hasn't been updated to reflect the new
loggerLevelparameter.// Execute adds all child commands to the root command and sets flags appropriately. // This is called by main.main(). It only needs to happen once to the rootCmd. +// The loggerLevel parameter controls the global logging level for the application. func Execute(logger *slog.Logger, loggerLevel *slog.LevelVar) {pkg/runner/mqtt.go (1)
25-31: Consider optimizing string formatting in logger methodsThe current implementation uses
fmt.Sprint*functions before passing to the logger, which creates an intermediate string allocation. Consider passing the format and arguments directly to the logger for better performance.Example optimization for debug logger (similar changes for error logger):
func (pdl pahoDebugLogger) Println(v ...interface{}) { - pdl.logger.Debug(fmt.Sprintln(v...)) + pdl.logger.Debug(fmt.Sprint(v...)) } func (pdl pahoDebugLogger) Printf(format string, v ...interface{}) { - pdl.logger.Debug(fmt.Sprintf(format, v...)) + pdl.logger.Debug(format, v...) }Also applies to: 37-43
cmd/run.go (1)
Line range hint
41-41: Consider grouping debug-related flags for better organizationThe debug-related flags are scattered throughout the flag definitions. Consider grouping them together and adding a comment section to clearly separate debug options from operational flags.
Here's a suggested reorganization:
runCmd.Flags().Bool("disable-mqtt", false, "disable MQTT message sending") runCmd.Flags().Bool("disable-mqtt-filequeue", false, "disable MQTT file based queue") + + // Debug options + runCmd.Flags().Bool("debug", false, "print debug logging during operation") + runCmd.Flags().String("debug-dnstap-filename", "", "File for dumping unmodified (sensitive) JSON-formatted dnstap packets we are about to process, for debugging") + runCmd.Flags().Bool("debug-enable-blockprofiling", false, "Enable profiling of goroutine blocking events") + runCmd.Flags().Bool("debug-enable-mutexprofiling", false, "Enable profiling of mutex contention events")Also applies to: 85-87
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
📒 Files selected for processing (5)
cmd/root.go(2 hunks)cmd/run.go(1 hunks)main.go(2 hunks)pkg/runner/mqtt.go(2 hunks)pkg/runner/runner.go(2 hunks)
🔇 Additional comments (10)
main.go (3)
23-24: LGTM! Good practice using slog.LevelVar for dynamic level control
The introduction of loggerLevel as a slog.LevelVar allows for dynamic control of logging levels, which is essential for implementing the debug flag functionality.
26-26: LGTM! Proper integration of level control with structured logging
The logger initialization correctly incorporates the dynamic level control while maintaining JSON structured logging, which is crucial for log aggregation and analysis.
36-36: Verify the cmd.Execute signature change implementation
The modification to pass loggerLevel is correct, but let's verify the corresponding changes in the cmd package.
✅ Verification successful
Let me gather more information about the implementation details.
Execute signature change is properly implemented
The verification confirms that:
- The
Executefunction incmd/root.gocorrectly accepts bothloggerandloggerLevelparameters - The
loggerLevelis properly stored in a global variable for use in the cmd package - The parameter is correctly utilized in
pkg/runner/runner.goto set debug level when needed
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash
# Description: Verify the Execute function signature change and its implementation
# Check the Execute function signature in cmd package
ast-grep --pattern 'func Execute($logger *slog.Logger, $level *slog.LevelVar)'
# Check how the loggerLevel is used in the cmd package
rg -l "loggerLevel" --type go
Length of output: 151
Script:
#!/bin/bash
# Check the Execute function implementation in cmd/root.go
ast-grep --pattern 'func Execute($$$)'
# Check how loggerLevel is used in cmd/root.go
rg "loggerLevel" -A 3 -B 3 cmd/root.go
# Check how loggerLevel is used in pkg/runner/runner.go
rg "loggerLevel" -A 3 -B 3 pkg/runner/runner.go
Length of output: 1221
cmd/root.go (2)
12-14: LGTM! Well-structured logging configuration.
The addition of edmLoggerLevel as a package-level variable is a clean approach to managing dynamic log levels across the application.
30-33: LGTM! Clean implementation of logger level initialization.
The function properly initializes both the logger and its level while maintaining clean error handling.
pkg/runner/mqtt.go (3)
8-8: LGTM: Appropriate use of structured logging package
The switch to log/slog aligns with the PR objective to improve logging capabilities.
19-23: LGTM: Well-structured logger implementations
The implementation of separate debug and error loggers with structured logging capabilities aligns well with the PR objectives. The design properly encapsulates the slog.Logger and provides a clean interface for Paho integration.
61-64: LGTM: Well-structured logging configuration with clear categorization
The configuration properly implements structured logging with clear categorization using "paho_log_type". This will help in identifying the source of Paho-related log messages.
Let's verify if any existing log consumers depend on the previous logging format:
✅ Verification successful
Let me gather more context about the logging changes by checking the previous implementation and any log-related tests.
Based on the git history, I can now see that the previous implementation used paholog.NOOPLogger{} and log.Default() for different logging scenarios. Let me check one more thing to ensure there are no log format dependencies in the tests.
Let me check the custom logger implementation in mqtt.go to understand how it handles the log output.
The logging changes are safe and improve observability
The changes are verified to be safe because:
- Previous implementation used
NOOPLoggerandlog.Default(), which didn't provide structured logging context - New implementation properly wraps Paho's logging interface with structured logging, maintaining the same method signatures
- No existing log consumers depend on the previous format, as the log parsing found in the codebase is only for application-specific messages
- Custom logger implementations (
pahoDebugLoggerandpahoErrorLogger) properly handle the format conversion between Paho's interface and structured logging
The addition of "paho_log_type" context improves log categorization without breaking existing functionality.
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash
# Search for log parsing or processing logic in the codebase
rg -g '!vendor/*' -g '!*.log' -A 3 'log\.' | grep -E 'parse|process|handle|consume'
Length of output: 1140
Script:
#!/bin/bash
# Check git history for the specific file to see previous logging implementation
git show HEAD~1:pkg/runner/mqtt.go 2>/dev/null || echo "File not found in previous commit"
# Search for any test files that might be verifying log output
fd -e test.go -x rg -l "paho.*log" {}
Length of output: 4259
Script:
#!/bin/bash
# Search for any test assertions on log output
rg -g '*.test.go' -A 3 'assert.*log|expect.*log'
# Check for any custom logger implementations
rg -l 'type.*Logger'
Length of output: 241
Script:
#!/bin/bash
# Check the logger implementation in mqtt.go
rg -A 10 'type.*Logger' pkg/runner/mqtt.go
Length of output: 579
pkg/runner/runner.go (2)
759-761: LGTM! Clean implementation of debug logging setup.
The code correctly sets the log level to debug when the debug flag is enabled, which aligns with the PR objective to improve debug logging behavior.
744-744: Verify all callers of the Run function have been updated.
The function signature change looks good but requires updates in calling code.
✅ Verification successful
Based on the rg results, I can generate the final response as we have found all the callers of the Run function:
Function signature change is properly handled
The Run function is only called once in cmd/run.go and it correctly passes both required parameters: edmLogger and edmLoggerLevel.
🏁 Scripts executed
The following scripts were executed for the analysis:
Script:
#!/bin/bash
# Description: Verify all callers of the Run function have been updated to pass the loggerLevel parameter.
# Search for function calls to Run
rg -A 2 "Run\(" --type go
Length of output: 458
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Outside diff range and nitpick comments (2)
pkg/runner/mqtt.go (2)
19-43: Add documentation for exported typesWhile the implementation is solid, these exported types should have proper documentation comments (GoDoc) explaining their purpose and interface implementation.
Consider adding documentation like this:
+// pahoDebugLogger implements paho/log.Logger interface for debug-level logging type pahoDebugLogger struct { logger *slog.Logger } +// pahoErrorLogger implements paho/log.Logger interface for error-level logging type pahoErrorLogger struct { logger *slog.Logger }
61-64: LGTM: Well-structured logging configurationThe implementation effectively tags Paho logs with their source, which directly addresses the PR objective. The use of
With()to add context is a good practice.Consider extracting the log type strings as constants to prevent typos and enable reuse:
+const ( + pahoLogTypeDebug = "debug" + pahoLogTypeErrors = "errors" + pahoLogTypePahoDebug = "paho_debug" + pahoLogTypePahoErrors = "paho_errors" +) cliCfg := autopaho.ClientConfig{ - Debug: pahoDebugLogger{logger: edm.log.With("paho_log_type", "debug")}, - Errors: pahoErrorLogger{logger: edm.log.With("paho_log_type", "errors")}, - PahoDebug: pahoDebugLogger{logger: edm.log.With("paho_log_type", "paho_debug")}, - PahoErrors: pahoErrorLogger{logger: edm.log.With("paho_log_type", "paho_errors")}, + Debug: pahoDebugLogger{logger: edm.log.With("paho_log_type", pahoLogTypeDebug)}, + Errors: pahoErrorLogger{logger: edm.log.With("paho_log_type", pahoLogTypeErrors)}, + PahoDebug: pahoDebugLogger{logger: edm.log.With("paho_log_type", pahoLogTypePahoDebug)}, + PahoErrors: pahoErrorLogger{logger: edm.log.With("paho_log_type", pahoLogTypePahoErrors)}, }
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
📒 Files selected for processing (1)
pkg/runner/mqtt.go(2 hunks)
🔇 Additional comments (1)
pkg/runner/mqtt.go (1)
8-8: LGTM: Good upgrade to structured logging
The switch to log/slog is a positive change that enables structured logging, which will improve log parsing and filtering capabilities.
There was a problem hiding this comment.
Actionable comments posted: 0
🧹 Outside diff range and nitpick comments (2)
pkg/runner/mqtt.go (2)
26-50: Consider optimizing logger implementations.While the implementation is clean and functional, consider these improvements:
- The logger types could be unexported since they're package-internal
- Method receivers could use pointers to avoid copying the logger struct
-type pahoDebugLogger struct { +type pahoDebugLogger struct { logger *slog.Logger } -func (pdl pahoDebugLogger) Println(v ...interface{}) { +func (pdl *pahoDebugLogger) Println(v ...interface{}) { pdl.logger.Debug(fmt.Sprint(v...)) } -func (pdl pahoDebugLogger) Printf(format string, v ...interface{}) { +func (pdl *pahoDebugLogger) Printf(format string, v ...interface{}) { pdl.logger.Debug(fmt.Sprintf(format, v...)) } -type pahoErrorLogger struct { +type pahoErrorLogger struct { logger *slog.Logger } -func (pel pahoErrorLogger) Println(v ...interface{}) { +func (pel *pahoErrorLogger) Println(v ...interface{}) { pel.logger.Error(fmt.Sprint(v...)) } -func (pel pahoErrorLogger) Printf(format string, v ...interface{}) { +func (pel *pahoErrorLogger) Printf(format string, v ...interface{}) { pel.logger.Error(fmt.Sprintf(format, v...)) }
68-71: Consider reducing logger initialization repetition.The current implementation works well but contains repeated logger initialization patterns. Consider introducing a helper function to reduce this repetition.
+func newPahoLogger(logger *slog.Logger, logType string, isDebug bool) interface{} { + l := logger.With("paho_log_type", logType) + if isDebug { + return &pahoDebugLogger{logger: l} + } + return &pahoErrorLogger{logger: l} +} cliCfg := autopaho.ClientConfig{ // ... other config ... - Debug: pahoDebugLogger{logger: edm.log.With("paho_log_type", pahoLogTypeDebug)}, - Errors: pahoErrorLogger{logger: edm.log.With("paho_log_type", pahoLogTypeErrors)}, - PahoDebug: pahoDebugLogger{logger: edm.log.With("paho_log_type", pahoLogTypePahoDebug)}, - PahoErrors: pahoErrorLogger{logger: edm.log.With("paho_log_type", pahoLogTypePahoErrors)}, + Debug: newPahoLogger(edm.log, pahoLogTypeDebug, true), + Errors: newPahoLogger(edm.log, pahoLogTypeErrors, false), + PahoDebug: newPahoLogger(edm.log, pahoLogTypePahoDebug, true), + PahoErrors: newPahoLogger(edm.log, pahoLogTypePahoErrors, false),
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
📒 Files selected for processing (1)
pkg/runner/mqtt.go(2 hunks)
🔇 Additional comments (1)
pkg/runner/mqtt.go (1)
19-24: Well-structured logging constants!
The new constants provide clear categorization for different types of log messages, making it easier to identify the source of Paho-related logs. This aligns well with the PR's objective of improving log message identification.
Make it so we can tag messages from paho internal logging in the slog messages, so we can now what part of paho created the message.
This also resulted in using the slog Debug level properly. edm will now set the slog loglevel to debug if the --debug flag is passed. This also resulted in some cleanup of the more verbose debug messages left in the code so it is actuallu possible to run edm on a real system with --debug enabled without generating massive amount of log messages.
Summary by CodeRabbit
New Features
Bug Fixes
Documentation