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

proposal: log: improve the existing logger without breaking any existing functionalities #48503

Closed
burakkoken opened this issue Sep 20, 2021 · 11 comments
Labels
Projects
Milestone

Comments

@burakkoken
Copy link

@burakkoken burakkoken commented Sep 20, 2021

As you know, the current implementation of the log.Logger provides us with limited flexibility and does not meet developers' needs so most of the developers use third-party libraries for logging. Moreover, we use multiple third-party libraries in our projects and each of these libraries uses different third-party logger implementations. This is a common problem that has been addressed and faced frequently.

The problems with the existing API are:
(These problems have been already addressed in #13182 and #28412)

  • Lack of support for leveled logging. This is the most obvious reason for people to use a third-party logger instead of using the standard library.
  • The standard logger enforces a specific logging format. So it cannot be customized based on needs.
  • Since it is not context-aware, contextual fields and data cannot be added to log output.

The latest developments show that log.Logger type will be changed to an interface in Go2 (see also the discussion on #13182). However, it is not going to provide backward compatibility and will affect most of the libraries that use the standard Logger. In my opinion, it would be better to improve existing implementation without breaking any existing functionalities and affecting libraries that use the standard logger implementation such as HTTP.

Proposal

This proposes some changes to the existing logger which won't break any existing functionalities or affect any libraries. In my opinion, developer needs will be met thanks to these changes. Moreover, it will have backward compatibility.

Here are the changes proposed:

  • The standard log package does not have levels, To support this, additional methods can be added such as Warn, Error, Info, etc.

  • Any Formatter interface can be introduced, which helps developers to customize the output based on their needs. The current implementation of the log.Logger enforces a specific logging format.

  • Logger should be context-aware. So that we can add contextual values into the log output such as TraceId and CorrelationId.

  • Loggers should be able to have a Root Logger. Thanks to this, we can have multiple loggers with different prefixes which write to the same output destination.

For more detail, please check out the sections below and review PR(#48464) I have already created.

Logger Levels

In order to support logger levels, a function named OutputLevel can be added. The function might look like this:

func OutputLevel(level Level, calldepth int, s string) error {
	return std.OutputLevel(level, calldepth+1, s) // +1 for this frame.
}

There is no need to change for Output function's signature not to break any functionality and support backward compatibility.
Instead, the Output function might invoke the OutputLevel function directly.

func Output(calldepth int, s string) error {
	return std.OutputLevel(NoneLevel, calldepth+1, s) // +1 for this frame.
}

We can set the logger level using the following method.

// SetLoggerLevel sets the log level for the logger.
func (l *Logger) SetLoggerLevel(level Level) {}

To enable the level mechanism, we can use a flag named Llevel:

log.SetFlags(LstdFlags | Llevel | Lmsgprefix)

The following levels can be supported:

type Level uint32

// These are the different logger levels. You can set the logger level
// on your instance of logger
const (
	NoneLevel Level = -(iota + 1)
	PanicLevel
	FatalLevel
	ErrorLevel
	WarnLevel
	InfoLevel
	DebugLevel
	TraceLevel
)

The following methods can be added to the current implementation in order to write log outputs at different levels. They will only invoke the OutputLevel function and pass the level value to it.

func (l *Logger) Error(v ...interface{}) {}

// Errorf is equivalent to Printf() and logs the message at level Error.
func (l *Logger) Errorf(format string, v ...interface{}) {}

// Errorln is equivalent to Println() and logs the message at level Error.
func (l *Logger) Errorln(v ...interface{}) {}

// Warn is equivalent to Print() and logs the message at level Warning.
func (l *Logger) Warn(v ...interface{}) {}

// Warnf is equivalent to Printf() and logs the message at level Warning.
func (l *Logger) Warnf(format string, v ...interface{})}

// Warnln is equivalent to Println() and logs the message at level Warning.
func (l *Logger) Warnln(v ...interface{}) {}

// Info is equivalent to Print() and logs the message at level Info.
func (l *Logger) Info(v ...interface{}) {}

// Infof is equivalent to Printf() and logs the message at level Info.
func (l *Logger) Infof(format string, v ...interface{}) {}

// Infoln is equivalent to Println() and logs the message at level Info.
func (l *Logger) Infoln(v ...interface{}) {}

// Debug is equivalent to Print() and logs the message at level Debug.
func (l *Logger) Debug(v ...interface{}) {}

// Debugf is equivalent to Printf() and logs the message at level Debug.
func (l *Logger) Debugf(format string, v ...interface{}) {}

// Debugln is equivalent to Println() and logs the message at level Debug.
func (l *Logger) Debugln(v ...interface{}) {}

// Trace is equivalent to Print() and logs the message at level Trace.
func (l *Logger) Trace(v ...interface{}) {}

// Tracef is equivalent to Printf() and logs the message at level Trace.
func (l *Logger) Tracef(format string, v ...interface{}) {}

// Traceln is equivalent to Println() and logs the message at level Trace.
func (l *Logger) Traceln(v ...interface{}) {}

Formatter

In case we would like to format the output based on our needs or requirements, we can format the log output with the help of an interface.

The interface I have in mind is this:

// The LoggerFormatter interface is used to implement a custom formatter.
// So the log output can be customized by implementing this interface.
type LoggerFormatter interface {
	Format(entry *Entry) ([]byte, error)
}

Entry might look like this:
(Entry fields will be set in the OutputLevel function and we will have all necessary data for logging.)

// The Entry is a logging entry that contains context set by the user and needed data
// for the log.
// Entry fields are used by a custom formatter while formatting output.
type Entry struct {
	logger    *Logger         // logger which will be used to log the entry
	context   context.Context // context set by the user
	calldepth int             // calldepth is the count of the number of frames to skip
	level     *Level          // level of the entry
	message   string          // message contains the text to print
}

// Logger returns the logger which will write entry to the output destination.
func (e *Entry) Logger() *Logger {}

// Context returns the context set by the user for entry.
func (e *Entry) Context() context.Context {}

// LogLevel returns the log level for entry.
func (e *Entry) LogLevel() *Level {}

// Message returns the log message for entry.
func (e *Entry) Message() string {}

// CallDepth returns the calldepth for entry.
func (e *Entry) CallDepth() int {}

// Print, Panic, Fatal, Error, Info methods...

We can set or get formatter by using the following methods.

func (l *Logger) Formatter() LoggerFormatter {}

// SetFormatter sets the formatter for the logger.
func (l *Logger) SetFormatter(formatter LoggerFormatter) {}

Sample Formatter:

type testFormatter struct {
}

func (f *testFormatter) Format(entry *log.Entry) ([]byte, error) {
	prefix := entry.Logger().Prefix()
	level := log.LevelText(*entry.LogLevel())
	traceId := entry.Context().Value("traceId")
	
	return []byte(prefix + " " + level + " [" + traceId.(string) + "] " + entry.Message()), nil
}

context.Context

log.Logger should be context-aware. So that we can add values or fields into the output from context.Context using a custom formatter. In order to make it context-aware, we can add a method as shown below.

The following method which will be added creates an entry and adds the given context to it. See the Formatter section for more details about Entry.

// WithContext creates an entry from the logger and adds a context to it.
func (l *Logger) WithContext(ctx context.Context) *Entry {
	entry := l.newEntry()
	entry.context = ctx
	return entry
}

In addition to this, the logger should have its own context. It can be set using the following method.

// SetContext sets the context for the logger.
func (l *Logger) SetContext(ctx context.Context) {}

Root Logger

In case we would like to have multiple loggers with different prefixes which write to the same output destination, we should be able to do this as shown below. In the following example, log.GetLogger will return two loggers with different prefixes whose root logger is the standard logger. These loggers will have separate logger levels and contexts however they will write the same output destination where the standard logger points to. Moreover, they will share the root logger's flag and formatter.

The benefit of this feature will be that each module/package can have a separate logger with different prefixes and logs can be differentiated easily.

func main() {
	log.SetFlags(LstdFlags | Llevel | Lmsgprefix)
	logger1 := log.GetLogger("logger1 - ")
	logger1.SetLoggerLevel(log.InfoLevel)
	logger1.Info("hello")
	logger1.Warn("hello")
	logger1.Error("hello")
	logger1.WithContext(context.Background()).Trace("hello")
	logger1.Debug("hello")

	logger2 := log.GetLogger("logger2 - ")
	logger2.SetLoggerLevel(log.TraceLevel)
	logger2.Info("hello")
	logger2.Warn("hello")
	logger2.Error("hello")
	logger2.Trace("hello")
	logger2.Debug("hello")
}

Sample output looks like this:

2021/09/20 23:53:01 INFO  logger1 - hello
2021/09/20 23:53:01 WARN  logger1 - hello
2021/09/20 23:53:01 ERROR logger1 - hello
2021/09/20 23:53:01 INFO  logger2 - hello
2021/09/20 23:53:01 WARN  logger2 - hello
2021/09/20 23:53:01 ERROR logger2 - hello
2021/09/20 23:53:01 TRACE logger2 - hello
2021/09/20 23:53:01 DEBUG logger2 - hello

This proposal might be too broad. I'm looking forward to your feedback and ideas :)

@gopherbot gopherbot added this to the Proposal milestone Sep 20, 2021
@ianlancetaylor ianlancetaylor changed the title proposal: Improve the existing logger without breaking any existing functionalities proposal: log: improve the existing logger without breaking any existing functionalities Sep 20, 2021
@ianlancetaylor ianlancetaylor added this to Incoming in Proposals Sep 20, 2021
@ericlagergren
Copy link
Contributor

@ericlagergren ericlagergren commented Sep 22, 2021

This change is not going to break the libraries that use the output function directly.

Except for

var _ func(calldepth int, s string) error = log.Output

Loading

@burakkoken
Copy link
Author

@burakkoken burakkoken commented Sep 22, 2021

Thanks for your feedback @ericlagergren, you're right. When this case is considered, it will not have complete backward compatibility.

Loading

@AlexanderYastrebov
Copy link
Contributor

@AlexanderYastrebov AlexanderYastrebov commented Oct 3, 2021

Except for
When this case is considered, it will not have complete backward compatibility.

https://go.dev/blog/module-compatibility#adding-to-a-function
Maybe this:

func (l *Logger) Output(calldepth int, s string) error {
    return l.OutputLevel(nil/*or default backward-compatible level*/, calldepth+1, s) // +1 for this frame.
}

func (l *Logger) OutputLevel(level Level, calldepth int, s string) error {
...
}
...
func Output(calldepth int, s string) error {
	return std.Output(calldepth+1, s) // +1 for this frame.
}

func OutputLevel(level Level, calldepth int, s string) error {
	return std.OutputLevel(level, calldepth+1, s) // +1 for this frame.
}

Loading

@burakkoken
Copy link
Author

@burakkoken burakkoken commented Oct 3, 2021

Your suggestion seems like an appropriate solution to this backward compatibility problem, I'm gonna update my proposal and MR according to your suggestion. Thanks for your feedback @AlexanderYastrebov .

Loading

@burakkoken
Copy link
Author

@burakkoken burakkoken commented Oct 4, 2021

The proposal and MR have been updated according to @AlexanderYastrebov's suggestion.
I guess, now it's not gonna break any functionality.

Loading

@rsc
Copy link
Contributor

@rsc rsc commented Oct 6, 2021

There are of course many other logging packages.
We tried once to decide how to extend package log and failed.
In addition to not breaking existing functionality,
the new API has to feel like it fits with the current package.
The API described above adds quite a lot.
It's far from clear that we want to add leveled logging to package log at all.

Loading

@rsc
Copy link
Contributor

@rsc rsc commented Oct 6, 2021

This proposal has been added to the active column of the proposals project
and will now be reviewed at the weekly proposal review meetings.
— rsc for the proposal review group

Loading

@rsc rsc moved this from Incoming to Active in Proposals Oct 6, 2021
@rsc rsc moved this from Active to Likely Decline in Proposals Oct 13, 2021
@rsc
Copy link
Contributor

@rsc rsc commented Oct 13, 2021

Based on the discussion above, this proposal seems like a likely decline.
— rsc for the proposal review group

Loading

@burakkoken
Copy link
Author

@burakkoken burakkoken commented Oct 13, 2021

Which parts of the proposal are not exactly fit? Could you please share your thoughts in comment before declining? It would be better to discuss each part of it indivually.

Loading

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Oct 14, 2021

See the comment above: #48503 (comment).

There are many existing logging packages. I think the way to move this forward is to build consensus among logging package authors and users as to the common set that should be supported by all. It may make sense to put that common set in the standard library's log package. But previous efforts at this have failed.

With respect, given the existing ecosystem and history, I don't think it's an effective use of the proposal committee's time to discuss each part of this complex proposal individually. The goal of the proposal committee in complex areas like this is to find consensus. To do that we need to bring more people into the discussion, not just the proposal committee.

Thanks.

Loading

@rsc rsc moved this from Likely Decline to Declined in Proposals Oct 20, 2021
@rsc
Copy link
Contributor

@rsc rsc commented Oct 20, 2021

No change in consensus, so declined.
— rsc for the proposal review group

Loading

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Proposals
Declined
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
6 participants