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

Jump to bottom

log: add option to place prefix text immediately before log text #32062

Closed
cespare opened this issue May 15, 2019 · 11 comments
Closed

log: add option to place prefix text immediately before log text #32062

cespare opened this issue May 15, 2019 · 11 comments
Labels
early-in-cycle A change that should be done early in the 3 month dev cycle. FrozenDueToAge Proposal Proposal-Accepted
Milestone
Go1.14

Comments

@cespare
Copy link
Contributor

cespare commented May 15, 2019 •
edited

At my company we use the log package extensively. A shortcoming we often encounter is that we want to include a text prefix on every log line before the logged text but after the automatic prefix. That is, if you have

l := log.New(os.Stderr, "xyz: ", log.LstdFlags)
l.Print("Frobnicating the turboencabulator")

You get

xyz: 2019/05/15 11:36:18 Frobnicating the turboencabulator

And we often want

2019/05/15 11:36:18 xyz: Frobnicating the turboencabulator

One place this comes up is in scenarios where we are processing different items and we want to include context about them in the log messages:

logger := /* some previously created "parent" logger */
for id, item := range items {
	subLogger := log.New(logger.Writer(), fmt.Sprintf("%d: ", id), logger.Flags())
	process(item, subLogger)
}

// ...

func process(it *item, l *log.Logger) {
	l.Print("Frobnicating the turboencabulator")
	// ...
}

(This is tangentially related to creating a "child" logger, which is possible as of Go 1.12.)

Without any way to put the prefix where we want, we end up needing some workaround such as passing an additional logPrefix string around and remembering to include it in every log message, or else using custom logging code.

I think that if the standard logger became an interface then our code would mostly pass around that interface and it would be easy to implement this cleanly ourselves. But that has proved to be a thorny issue and little progress has been made in the past few years. In the meantime, here are two alternatives for addressing this issue today:

Idea 1

Add a new log flag:

@@ -40,6 +40,7 @@ const (
        Llongfile                     // full file name and line number: /a/b/c/d.go:23
        Lshortfile                    // final file name element and line number: d.go:23. overrides Llongfile
        LUTC                          // if Ldate or Ltime is set, use UTC rather than the local time zone
+       LmsgPrefix                    // place prefix text immediately before the message instead of the beginning of the line
        LstdFlags     = Ldate | Ltime // initial values for the standard logger
 )
l := log.New(os.Stderr, "xyz: ", log.LstdFlags|log.LmsgPrefix)
l.Print("Frobnicating the turboencabulator")
// 2019/05/15 11:36:18 xyz: Frobnicating the turboencabulator

Idea 2

// MessagePrefix returns the output message prefix for the logger.
func (l *Logger) MessagePrefix() string

// SetMessagePrefix sets the output message prefix for the logger.
func (l *Logger) SetMessagePrefix(prefix string)

(It would need better documentation.) There need not be top-level MessagePrefix/SetMessagePrefix functions because this type of prefix doesn't make much sense globally. Then we would do

l := log.New(os.Stderr, "", log.LstdFlags)
l.SetMessagePrefix("xyz: ")
l.Print("Frobnicating the turboencabulator")
// 2019/05/15 11:36:18 xyz: Frobnicating the turboencabulator
@gopherbot gopherbot added this to the Proposal milestone May 15, 2019
@bradfitz
Copy link
Contributor

This bites me every time I've tried to use the log prefix. Then I re-remember where it inserts it and I stop using the log prefix and write my own log wrapper func instead.

@rsc
Copy link
Contributor

rsc commented May 28, 2019

This hits me each time I try to use this too. I always expect the date to be before the prefix, not after. A bit to say "put the date and file (if there) before the prefix" makes sense to me, but I am not sure about the name. LmsgPrefix makes it sound like you just want to show the prefix, and the prefix is always shown.

/cc @robpike

@robpike robpike self-assigned this May 30, 2019
@rsc
Copy link
Contributor

rsc commented Jun 4, 2019

@robpike, thoughts about what the API change should be?

@robpike
Copy link
Contributor

robpike commented Jun 4, 2019

@rsc Does it need API? You have SetFlags. Add a flag with boolean effect like LdateFirst. Haven't thought about it much though.

@cespare
Copy link
Contributor Author

cespare commented Jun 19, 2019

Yeah, LmsgPrefix isn't great.

I was going to say that the problem with LdateFirst is that it's not just that the date should be first: the file:line (if present) should also precede the prefix text.

l := log.New(os.Stderr, "xyz: ", log.Ldate|log.Ltime|log.Lshortfile|log.LtoBeNamed)
l.Print("Hello")
// Should this print
//   2019/06/19 09:11:16 test.go:12: xyz: Hello
// or
//   2019/06/19 09:11:16 xyz: test.go:12: Hello

But now that I've written it out, I'm not sure. Either way kind of seems fine to me: the important part is that the date is first. So I'd be okay with LdateFirst and having it output

[date] [prefix] [file:line] text

@rsc
Copy link
Contributor

rsc commented Jun 25, 2019

I think the point of moving things was to attach the prefix more clearly to the message text being printed. That would mean putting it after the file:line too.

That would align nicely with the original request for Lmsgprefix. (Not LmsgPrefix; see Lshortfile, Llongfile etc. LstdFlags is the odd man out.)

Any objections to Lmsgprefix?

/cc @robpike

@robpike
Copy link
Contributor

robpike commented Jul 2, 2019

Fine with me.

@rsc rsc modified the milestones: Proposal, Go1.14 Jul 2, 2019
@rsc rsc changed the title proposal: log: add option to place prefix text immediately before log text log: add option to place prefix text immediately before log text Jul 2, 2019
@rsc rsc added the early-in-cycle A change that should be done early in the 3 month dev cycle. label Jul 2, 2019
@rsc
Copy link
Contributor

rsc commented Jul 2, 2019

Marking accepted based on discussion.

@rsc rsc mentioned this issue Jul 2, 2019
Closed
@gopherbot
Copy link

Change https://golang.org/cl/186182 mentions this issue: log: add Lmsgprefix flag

@anuj-agrawal
Copy link

Does LprefixAfterHeaders sound like a better name than LmsgPrefix?

@gopherbot
Copy link

Change https://golang.org/cl/217126 mentions this issue: doc/go1.14: mention new log.Lmsgprefix flag

gopherbot pushed a commit that referenced this issue Jan 31, 2020
@ianlancetaylor
doc/go1.14: mention new log.Lmsgprefix flag
b7689f5 
Updates #32062
Updates #36878

Change-Id: I06c7c9a9d253177155a6d46d58231ce26e659757
Reviewed-on: https://go-review.googlesource.com/c/go/+/217126
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@golang golang locked and limited conversation to collaborators Jan 30, 2021
@rsc rsc unassigned robpike Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
early-in-cycle A change that should be done early in the 3 month dev cycle. FrozenDueToAge Proposal Proposal-Accepted
Projects
None yet
Milestone
Go1.14
Development

No branches or pull requests
6 participants
@bradfitz @rsc @cespare @robpike @anuj-agrawal @gopherbot