Skip to content

Conversation

kenkalang
Copy link

@kenkalang kenkalang commented Jul 4, 2025

See #503

Changes:

  • Introduced clientLogger to encapsulate loggers per client.
  • Added ClientOptions methods to allow setting loggers for each level (Error, Critical, Warn, Debug), all scoped to the ClientID.
  • Replaced global logging calls with client-bound clientLogger usage.
  • Injected clientLogger into relevant functions and structs to maintain client-level context in logs.

Before:

mqtt.ERROR = log.New(os.Stdout, "[ERROR] ", 0)
mqtt.CRITICAL = log.New(os.Stdout, "[CRITICAL] ", 0)
mqtt.WARN = log.New(os.Stdout, "[WARN]  ", 0)
mqtt.DEBUG = log.New(os.Stdout, "[DEBUG] ", 0)

After:

errorLogger := log.New(os.Stdout, "[ERROR]", 0)
criticalLogger := log.New(os.Stdout, "[CRITICAL]", 0)
warnLogger := log.New(os.Stdout, "[WARN]", 0)
debugLogger := log.New(os.Stdout, "[DEBUG]", 0)

opts = mqtt.NewClientOptions().
	SetClientID(clientID).
	SetDebugLogger(debugLogger).
	SetErrorLogger(errorLogger).
	SetCriticalLogger(criticalLogger).
	SetWarnLogger(warnLogger)

Example output:
Screenshot 2025-07-04 at 18 35 21

Note:

This log usage and output is no longer relevant. I changed the client log to use sLog, as for now there will be 2 log, global and client. See latest commit for more details

@MattBrittan
Copy link
Contributor

MattBrittan commented Jul 6, 2025

Thanks very much for all of your effort on this. But please consider in commenting on the issue before putting too much effort into changes (can be difficult to get much of a response, but it's worth trying).

Note: I do not personally use this library any more (have moved everything to V5) so will make a comment on the original issue asking for input from others (this also limits the amount of time I spend on this library). This also means that these comments are based on a fairly quick look (but with the extent of these changes a quick look is not all that quick!).

As I noted in issue #503 "My preference would be that the client defaults to the global logger because this would avoid breaking existing changes". Go has a bit of a focus on stability (see the Go 1 compatibility guarantee) and this applies to libraries (more so than a lot of other languages). Because of this (and experiences with other languages!) I've tried very hard to avoid breaking changes in this library (this is why the V5 client is completly seperate). As your PR containa breaking changes, we need to either:

  1. Move to a new major version ("V2") because users would expect a minor version change to be non-breaking; or
  2. Remove the breaking changes

My preference would be option 2 as I don't think this would be all that difficult and removes the need for end users to make changes. Based on a quick look:

  • NewClientOptions() - Default to logger that utilises the global loggers defined in trace.go (meaning as long as users set the loggers before calling NewClientOptions() logs will operate as they have previously)
  • MQTT.NewFileStore function definition changed (also with other stores) - change this to use default loggers and add a new NewFileStoreEx, or similar, to take the new logger.
  • ConnectionLostHandler signature change - users can get the logger from the Client (already passed).

A few other general thoughts:

  • func NewClientLogger(clientID string, errorLogger, criticalLogger, warnLogger, debugLogger Logger) *clientLogger , this may be difficult to use because clientLogger is not exported (so a user cannot do var *clientLogger paho.clientLogger). I also wonder whether using an interface for SetErrorLogger etc would be better (means a user can implement their own logger (something you can currently do but would no longer be possible with this PR).
  • Consider removing all direct calls to the old trace.go functions - there are still calls in options.go and store.go.
  • If making a change this big is it worth consideting moving to sLog. I believe the main benefit from would be that the log could more easily augmented, filtered etc. This might be too big of a change. Note this may also address Logging of message payloads #716 because the packet could be passed to a logger (would probably want to ignore it by default).

@kenkalang
Copy link
Author

kenkalang commented Jul 8, 2025

Hi Matt, thanks a lot for your feedback, I really appreciate the time you've taken, especially since you're no longer actively using this library.
You're right that I should have opened a discussion first before jumping into the code. I’ll make sure to do that in the future to avoid unnecessary work and ensure alignment before making larger changes.

  • I’ve adjusted the code to remove all breaking changes, as suggested.
  • For DefaultConnectionLostHandler, I reverted to using the global DEBUG logger directly. Since Client is an interface, introducing a new method like Logger() would have been a breaking change, so I avoided that.
  • Also in options.go, there’s still a direct call to the global logger (AddBroker), unfortunately this occurs before a client instance is created, so client-based logging isn’t possible at that stage.

Do you have any suggestions regarding my last 2 points?

Lastly, can you elaborate more on how adding sLog could address logging of message payload issues?

Thanks again for your feedback

@kenkalang
Copy link
Author

There are some changes:

  • Client log uses sLog
  • Add back global log

There are 2 logs for now, client and global, just to avoid any breaking changes. Will remove the global log soon

@kenkalang kenkalang force-pushed the feat/add-clientlogger branch from 3e0e0ca to ad5e07c Compare July 14, 2025 06:12
@kenkalang kenkalang force-pushed the feat/add-clientlogger branch from 7daea6f to cc49c16 Compare July 16, 2025 08:46
@MattBrittan
Copy link
Contributor

Sorry - had planned on looking at this before the end of the week but thats not going to happen. Will aim for next week (this is quite a big change now so takes time to review).

Copy link
Contributor

@MattBrittan MattBrittan left a comment

Choose a reason for hiding this comment

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

Confirmed that pre PR CMD files all build OK and pre PR tests (with changes to private fn sigs only) pass (there is one dodgy test that fails intermittently prior to this PR). This reassures me that there should not be breaking changes.

Thanks very much for your work on this. I think it will be a worthy change but would prefer that we don't end up with two logging engines if thats possible (have made some suggestions as to how this could be accomplished). Note: my comments are suggestions - please feel free to push back!

As this is a big change so have created issue #722 to try and involve more people. Think I'l also do a dependency update/release this weekend so we can add this PR into Master and let it sit a while before it gets into a release.

Please consider updating the logging section of the Readme to use the new logger.

client.go Outdated
// because queued messages may be delivered immediately post connection
func (c *client) Connect() Token {
t := newToken(packets.Connect).(*ConnectToken)
DEBUG.Println(CLI, "Connect()")
Copy link
Contributor

Choose a reason for hiding this comment

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

Assume that calls to ERROR, CRITICAL, WARN, DEBUG, are for backwards compatability? If so these should probably be marked as depreciated (perhaps not in this PR but within a couple of months). I'm not a massive fan of having both calls.

Thinking about this I don't believe that we need to retain consistancy in the logged messages themselves (users should not assume that message text is constant) so wonder if a tidier solution might be to wrap the default handler. Something like (this is just a thought experiment at this stage!):

type Wrapper struct {
	handler slog.Handler

        // Below will be created as slog a custom handler moddled on https://cs.opensource.google/go/go/+/refs/tags/go1.24.5:src/log/slog/text_handler.go;l=28
       // and writing to the relevant global output (ERROR.Println etc).
        ERROR    slog.Handler
	CRITICAL slog.Handler
	WARN     slog.Handler
	DEBUG    slog.Handler
}

func (w *Wrapper) Handle(ctx context.Context, record slog.Record) error {
	switch {
	case record.Level == slog.LevelError:
		w.ERROR.Handle(ctx, record)
	case record.Level == slog.LevelWarn:
		w.CRITICALHandle(ctx, record)
	case record.Level == slog.LevelInfo:
		w.WARN.Handle(ctx, record)
       case record.Level == slog.LevelDebug:
		w.DEBUG.Handle(ctx, record)
	}
	return w.handler.Handle(ctx, record) // Invoke child slog handler
}

This would mean we would only need a single call to c.logger.X and the old loggers would still be called (albeit passed a slightly different message).

My concerns with things the way they are is that we have two seperate logging systems and this makes the code more confusing (and complicates future changes).

Thoughts?

Copy link
Author

Choose a reason for hiding this comment

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

Hi @MattBrittan, sorry for replying this late. I've been working on other things.

Yes, I see what you mean. Wrapping the handler like that makes sense and definitely feels cleaner than keeping two parallel systems. Just to confirm, are you suggesting something along the lines of:

type debugWriter struct{}

func (w debugWriter) Write(p []byte) (n int, err error) {
	DEBUG.Printf("%s", string(p))
	return len(p), nil
}

and pass it as writer on slog.NewTextHandler? I believe this way we can remove the old calls and just use c.logger.X, while still maintaining backward compatibility when users set mqtt.DEBUG = log.New(...).

If that’s what you meant, I can start putting it together.

Copy link
Contributor

Choose a reason for hiding this comment

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

No worries - I'd expect changes this big to take a while. Thanks for taking another look!

are you suggesting something along the lines of:

I had not got quite that far (just wanted to see if this was possible as it seems a lot tidier). What you are suggesting makes sense, I guess it could be generalised to (but I'm happy with either):

type debugWriter struct{
   l Logger
}

func (w debugWriter) Write(p []byte) (n int, err error) {
	w.l.Printf("%s", string(p))
	return len(p), nil
}

My feeling is that the output is going to be failrly close to the existing system (close enough that most users will not notice the change) and it will reduce duplication considerably. Hopefully users will move over to using slog fairly quickly (I think it will be easier for users to understand/use).

client.go Outdated
c.options.ProtocolVersion = 4
c.options.protocolVersionExplicit = false
}
if o.LogVerbosity == LogLevelDefault {
Copy link
Contributor

Choose a reason for hiding this comment

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

See comment in Logger.go

trace.go Outdated

var noopSLogger = slog.New(slog.NewTextHandler(io.Discard, &slog.HandlerOptions{}))

type LogLevel int
Copy link
Contributor

Choose a reason for hiding this comment

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

See comment in client.go and options.go

client.go Outdated
if o.LogVerbosity == LogLevelDefault {
c.logger = noopSLogger
} else {
c.logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Copy link
Contributor

Choose a reason for hiding this comment

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

Would it be better for the user to pass in an Slog.Logger as an option? This would allow them to use a different output type and set the output level themselves (could also change the output level dynamically if they need).

Copy link
Author

Choose a reason for hiding this comment

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

Sure, this is in line with your approach. We can let users provide their own logger like before, instead of limiting them to just setting the log level.

options.go Outdated
}

// SetLogLevel sets the log level for the client. This will be used to control the verbosity of the logs
func (o *ClientOptions) SetLogLevel(logVerbosity LogLevel) *ClientOptions {
Copy link
Contributor

Choose a reason for hiding this comment

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

As commented elsewhere I think SetLogger(l *slog.Logger) *ClientOptions might be more flexible?

A few reasons:

  • One of the main belefits of using slog is that it's part of the standard library and there are heaps of adaptors (for example I use zerolog in quite a few apps and could use https://github.com/samber/slog-zerolog to get an slog.Logger to pass into such a function).
  • Users can use whatever output type they want

client.go Outdated
ERROR.Println(CLI, err.Error())
c.logger.Error("Failed to connect to broker", slog.String("error", err.Error()), componentAttr(CLI))
WARN.Println(CLI, "failed to connect to broker, trying next")
c.logger.Warn("failed to connect to broker, trying next", componentAttr(CLI))
Copy link
Contributor

Choose a reason for hiding this comment

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

Is this needed when there is an Error for the same thing? (think we want one or the other, not both)

Copy link
Author

Choose a reason for hiding this comment

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

Oh yeah, this should only be an error log. I'll remove the warn one

@kenkalang
Copy link
Author

Hi @MattBrittan, I’ve committed a change reflecting your suggestion, please do take a look and give it a review. One thing to note is that I’ve mapped the CRITICAL log to Warn rather than creating a separate custom handler. Keeping everything within slog’s model avoids us having to maintain yet another handler abstraction, and helps push us toward deprecating the older style calls cleanly in the near future.

Other than that, there are still a couple of places I haven’t resolved yet:

  • In Options.go, there’s an ERROR call in AddBroker before the client logger has been initialized. In that case, I think it might be cleaner to return an error instead of logging.
  • In DefaultConnectionLostHandler, we can likely remove the logging entirely since afaik it’s only a placeholder.

Once we agree on this, we should be able to simplify further and remove the old calls entirely. I’m open to any suggestions here, so please let me know your opinion on this.

@MattBrittan
Copy link
Contributor

As mentioned above I was keen to make a release before looking at this further (as thie is a large change), I have now done that with 1.5.1 (apologies - this introduced a few conflicts). I aim to have a look at the logging over the next couple of weeks (sorry have put quite a bit of time into the releases and need to catch up on other stuff!).

@kenkalang kenkalang force-pushed the feat/add-clientlogger branch from 991ab43 to 0242a07 Compare October 11, 2025 18:59
@kenkalang kenkalang force-pushed the feat/add-clientlogger branch from 0242a07 to 8ef835d Compare October 12, 2025 09:36
@kenkalang
Copy link
Author

Hi @MattBrittan, I’ve rebased the branch. Please take your time reviewing and let me know if you want me to follow up on anything.

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.

3 participants