When using V-levels with glog or klog one common pattern is to avoid evaluation of logger invocation arguments when those might not be needed. So instead:

log.V(5).Info("Some message", "key", someComplexComputation())

something like this is used:

if log.V(5) {
  log.Info("Some message", "key", someComplexComputation())
}

In logr this translates to:

if log.V(5).Enabled() {
  log.Info("Some message", "key", someComplexComputation())
}

This unfortunately leads to a situation that the information about the log verbosity might be lost for the underlying logger implementation.
This can be problematic for implementations which have a fixed list of logging levels containing more then just error and info and would like to map different v-levels to the underlying logging levels.

This can be fixed by repeating V() function invocation:

if log.V(5).Enabled() {
  log.V(5).Info("Some message", "key", someComplexComputation())
}

but as this is not enforced by the API this might be error prone.

Some alternatives worth considering:

• Do not embed logr.InfoLogger in logr.Logger. This way following code will not compile:

if log.V(5).Enabled() {
  log.Info("Some message", "key", someComplexComputation())
}

• Remove V() method and logr.InfoLogger interface completely and pass verbosity as argument to Info method:

if log.InfoEnabled(5) {
  log.Info(5, "Some message", "key", someComplexComputation())
}

• Use closure with Enabled():

log.V(5).IfEnabled(func(log logr.InfoLogger) {
 log.Info("Some message", "key", someComplexComputation())
})

I'm currently using https://github.com/cloudevents/sdk-go which allows you to set the zap logger for it use internally.

I'm using zapr in my application and would like to access the underlying logger so that I can configure cloudevents. The part of my application which is using the cloudevents SDK only has access to the logr instance.

I could configure the cloudevents SDK in the main package (where the logger is configured), however it seems a bit of a hack as only a portion of my application is using cloudevents.

Maybe adding a function to the Logger interface, something along the lines of:

type Logger interface {
    ...
    Underlying() interface{}
}

I'm aware this would break the interfaces of each wrapper, so would require updating those packages. This could be mitigated temporarily with a new interface and once all wrapper libraries are updated, merge back into the single interface? Like:

type LoggerWithUnderlying {
    logr.Logger
    Underlying() interface {}
}

What are your thoughts? Happy to contribute a PR

Not strictly funcr, but could be done there as a ready-made function. Something like:

package main

import (
	"fmt"
	"io"
	"os"
	"time"
)

func fileSeek(f *os.File, pos int64, whence int) (int64, error) {
	return f.Seek(pos, whence)
}

func nullSeek(*os.File, int64, int) (int64, error) {
	return 0, nil
}

func fileSize(f *os.File) (int64, error) {
	st, err := f.Stat()
	if err != nil {
		return 0, err
	}
	return st.Size(), nil
}

func nullSize(*os.File) (int64, error) {
	return 0, nil
}

func main() {
	seek := nullSeek
	size := nullSize

	_, err := os.Stdout.Seek(0, io.SeekCurrent)
	if err == nil {
		seek = fileSeek
		size = fileSize
	}

	for i := 0; i < 10000; i++ {
		pos, err := seek(os.Stdout, 0, io.SeekCurrent)
		if err != nil {
			fmt.Fprintln(os.Stderr, "ERR", err)
			os.Exit(1)
		}
		siz, err := size(os.Stdout)
		if err != nil {
			fmt.Fprintln(os.Stderr, "ERR", err)
			os.Exit(1)
		}
		fmt.Fprintln(os.Stderr, "POS", pos, "SIZ", siz)
		if siz < pos {
			fmt.Fprintln(os.Stderr, "TRUNCATE")
			_, err := seek(os.Stdout, siz, io.SeekStart)
			if err != nil {
				fmt.Fprintln(os.Stderr, "ERR", err)
				os.Exit(1)
			}
		}

		fmt.Println(i)
		time.Sleep(100 * time.Millisecond)
	}
}

Hello,

In the below example i am using logr in combination with zap.

type nameValue struct {
   name string
   value int
}

// create a instance of this and try and log it
func main() {
    logger := logr.New(zap.New(zap.UseFlagOptions(&zap.Options)).GetSink())
    n := nameValue {
        name: "bingo",
        value: 10,
    }
    logger.V(2).Info("testing logging for nameValue", "nameValue", n)
}

This will print the following to the stdout:

testing logging for nameValue "nameValue": "{}"

Assumption made is that if you do not expose fields in a struct then you should also not print it out in logs. In general i agree but it seems too harsh a decision as you can enable debug logs and then get more detailed logs which also print the non-exposed fields of the struct (in other words it does not filter out unless explicitly coded for via MarshalLog).

I even wrote a String method (Stringer interface), which words when logging a single instance of the struct but when you have a slice of struct with un-exposed fields then it again prints out {} empty pair of curly braces. The only way to circumvent this behavior is therefore to directly use fmt.Sprintf and create a log message which beats the purpose of having a logging framework in the first place.

Also when native fmt package can easily print structs via %v and its variants then why should a logging framework be more restrictive than what golang natively provides? Also exposing fields just so that they can be logged is not a valid argument to expose them when there is no other package that requires it.

I would like to know if there are still better ways to achieve this and your reasoning for the current behavior.

Best Regards,
Madhav

It'd be nice to have a pre-1.0 release so that it's a bit easier to specify versions in tools/libraries that consume it (e.g. controller-runtime). Otherwise, they have to relying on pinning to specific git hashes, and that gets messy when pulling in multiple libraries that have dependencies on logr (e.g. library X depends on logr directly, plus zapr, which also depends on logr).

I was a little confused about the persistences of the logs.Is there a default file path for the log records??
If I did not set the file path for the log instance, will the log only print to standard out and not record to a file on the host running the program?

It is a conscious decision that funcr doesn't call String. But that begs the question how callers should log types where relevant fields are not exported. Here's an example:

diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go
index 735cbd6..f9050a7 100644
--- a/funcr/funcr_test.go
+++ b/funcr/funcr_test.go
@@ -191,6 +191,17 @@ func (c *capture) Func(prefix, args string) {
 	c.log = prefix + " " + args
 }
 
+
+type kmeta struct {
+	namespace, name string
+}
+
+func (k kmeta) String() string {
+	return k.namespace + "/" + k.name
+}
+
+var _ fmt.Stringer = kmeta{}
+
 func TestInfo(t *testing.T) {
 	testCases := []struct {
 		name   string
@@ -200,6 +211,13 @@ func TestInfo(t *testing.T) {
 		name:   "just msg",
 		args:   makeKV(),
 		expect: ` "level"=0 "msg"="msg"`,
+	}, {
+		name: "stringer",
+		args: makeKV("meta", kmeta{namespace: "foo", name: "bar"),
+		// funcr ignores String, so there is nothing to log for the
+		// internal type (unexported field not visible through
+		// reflection).
+		expect: ` "level"=0 "msg"="msg" "meta"={}`,
 	}, {
 		name:   "primitives",
 		args:   makeKV("int", 1, "str", "ABC", "bool", true),

If we want to push this to 1.0 (#38), we really need to make some intentional decisions about performance. The API as it stands was designed largely without considering performance, and (surprise!) it shows.

glogr_benchmark_test.go:

package bench

import (
	"flag"
	"os"
	"testing"

	"github.com/go-logr/glogr"
	"github.com/go-logr/logr"
	"github.com/golang/glog"
)

func init() {
	flag.Set("v", "1")
	flag.Set("logtostderr", "true")
	os.Stderr, _ = os.Open("/dev/null")
}

func BenchmarkGlogInfoOneArg(b *testing.B) {
	for i := 0; i < b.N; i++ {
		glog.Infof("this is a %s", "string")
	}
}

func BenchmarkGlogrInfoOneArg(b *testing.B) {
	var log logr.Logger = glogr.New()

	for i := 0; i < b.N; i++ {
		log.Info("this is", "a", "string")
	}
}

func BenchmarkGlogInfoSeveralArgs(b *testing.B) {
	for i := 0; i < b.N; i++ {
		glog.Infof("multi: bool %t, string %s, int %d, float %f, struct %v",
			true, "str", 42, 3.14, struct{ X, Y int }{93, 76})
	}
}

func BenchmarkGlogrInfoSeveralArgs(b *testing.B) {
	var log logr.Logger = glogr.New()

	for i := 0; i < b.N; i++ {
		log.Info("multi",
			"bool", true, "string", "str", "int", 42,
			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
	}
}

func BenchmarkGlogInfoV0(b *testing.B) {
	for i := 0; i < b.N; i++ {
		glog.V(0).Infof("multi: bool %t, string %s, int %d, float %f, struct %v",
			true, "str", 42, 3.14, struct{ X, Y int }{93, 76})
	}
}

func BenchmarkGlogrInfoV0(b *testing.B) {
	var log logr.Logger = glogr.New()

	for i := 0; i < b.N; i++ {
		log.V(0).Info("multi",
			"bool", true, "string", "str", "int", 42,
			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
	}
}

func BenchmarkGlogInfoV9(b *testing.B) {
	for i := 0; i < b.N; i++ {
		glog.V(9).Infof("multi: bool %t, string %s, int %d, float %f, struct %v",
			true, "str", 42, 3.14, struct{ X, Y int }{93, 76})
	}
}

func BenchmarkGlogrInfoV9(b *testing.B) {
	var log logr.Logger = glogr.New()

	for i := 0; i < b.N; i++ {
		log.V(9).Info("multi",
			"bool", true, "string", "str", "int", 42,
			"float", 3.14, "struct", struct{ X, Y int }{93, 76})
	}
}

Running this:

goos: linux
goarch: amd64
pkg: github.com/go-logr/glogr/bench
cpu: Intel(R) Xeon(R) W-2135 CPU @ 3.70GHz
BenchmarkGlogInfoOneArg-6         	  713682	      1675 ns/op
BenchmarkGlogrInfoOneArg-6        	  251154	      4761 ns/op
BenchmarkGlogInfoSeveralArgs-6    	  527288	      2285 ns/op
BenchmarkGlogrInfoSeveralArgs-6   	  167934	      7114 ns/op
BenchmarkGlogInfoV0-6             	  529798	      2286 ns/op
BenchmarkGlogrInfoV0-6            	  164413	      7293 ns/op
BenchmarkGlogInfoV9-6             	46018132	        25.70 ns/op
BenchmarkGlogrInfoV9-6            	 8412883	       142.2 ns/op

So it's notably slower. All of the variadic args escape to the heap, including the string keys (which regular glog does not suffer). But doesn't account for enough.

V() calls that are not taken also expand all their variadic args used.

Some of this is attributable to glogr being very dumb and wasteful (clone() on every call) but it's not clear how much. Before we call it 1.0 we need to do some homework.

v0.2.0 removed the InfoLogger interface in favor of returning a Logger from V(). This simplification is a nice improvement, but unfortunately this is a breaking change that makes it impossible to both satisfy the v0.1.0 and the v0.2.0 interface.

I am currently working on a Kubernetes operator using kubebuilder. When I switched to my own logr implementation (genericr), I found that Kubernetes depends on the v0.1.0 interface, while my backend implements the new v0.2.0 interface. I hit the following errors:

# sigs.k8s.io/controller-runtime/pkg/log
../../go/pkg/mod/sigs.k8s.io/[email protected]/pkg/log/null.go:48:32: undefined: logr.InfoLogger
# k8s.io/klog/v2
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:690:45: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:702:43: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:706:48: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:721:44: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:739:55: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:857:43: undefined: logr.InfoLogger
../../go/pkg/mod/k8s.io/klog/[email protected]/klog.go:1210:10: undefined: logr.InfoLogger

A quick look at klog suggests that that one can be fixed by declaring an internal InfoLogger interface without breaking anything, but I still need to verify this.

The custom null logger in the controller-runtime is a bigger problem. It is not possible to write an implementation of logr.Logger that works both with 0.1.0 and with 0.2.0. This is not a problem in a project where you control all the dependencies, but it is if you depend on third party code that may have their own implementation (e.g., for testing) of this interface.

Unfortunately this is a transition that is hard to manage for third party libraries, because the whole ecosystem would have to upgrade to v0.2.0 of the interface at the same time.

The problem can easily be solved by adding the following type alias to logr:

// InfoLogger provides compatibility with code that relies on the v0.1.0 interface
// Deprecated: use Logger instead. This will be removed in a future release.
type InfoLogger = Logger

This ensures that v0.1.0 implementations continue to work with a new logr v0.2.1. Once v0.2.1+ becomes the norm in the ecosystem, the type alias can be dropped in a future release.

It would be useful to automatically check that PRs don't break tests, formatting, and API stability.

Perhaps we can copy how klog handles this? See https://github.com/kubernetes/klog/tree/main/.github

This applies to all repos under go-logr.

It's supposed to test across versions

They are functionally identical.

1. EOL NullLogger in favor of logr.Discard()

2. Expose discardLogger type and make NullLogger embed it

3. Expose discardLogger type and make NullLogger a type alias

Anyone have feelings?

thanks to nice work, because of the funcr package use a api strconv.FormatComplex that come from go1.16, if some one want to use this log interface, he must update his golang version, this seems no need for a minimal log interface

We have custom logging library build using go-logr. After new commit on friday on go-logr repo our build is breaking. Can't we define only string in logging path.? Can you share the detailed changelog, which can help us to understand the new changes.

# k8s.io/klog
../../../../../go/src/k8s.io/klog/klog.go:705:10: invalid operation: logr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:724:10: invalid operation: logr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:742:10: invalid operation: logr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:763:10: invalid operation: logr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:782:11: invalid operation: loggr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:783:3: undefined: logr.WithCallDepth
../../../../../go/src/k8s.io/klog/klog.go:794:11: invalid operation: loggr != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:795:3: undefined: logr.WithCallDepth
../../../../../go/src/k8s.io/klog/klog.go:915:9: invalid operation: log != nil (mismatched types logr.Logger and nil)
../../../../../go/src/k8s.io/klog/klog.go:919:4: undefined: logr.WithCallDepth
../../../../../go/src/k8s.io/klog/klog.go:919:4: too many errors
make: *** [build] Error 2

github.com/go-logr/logr/funcr

../../go/src/github.com/go-logr/logr/funcr/funcr.go:398:16: undefined: strconv.FormatComplex
../../go/src/github.com/go-logr/logr/funcr/funcr.go:400:16: undefined: strconv.FormatComplex
../../go/src/github.com/go-logr/logr/funcr/funcr.go:443:16: undefined: strconv.FormatComplex
../../go/src/github.com/go-logr/logr/funcr/funcr.go:445:16: undefined: strconv.FormatComplex

There are some comments worth cleaning up

I'd like to think about WithStackTrace()

Is there anything else? @DirectXMan12

Please include this boilerplate with the appropriate {substitutions} in your source according to the guidance given in Appendix A of the Apache 2.0 license. We cannot use 'logr' (and therefore the structured logging features of 'klog') in our product otherwise.

   Copyright {yyyy} {name of copyright owner}

   Licensed under the Apache License, Version 2.0 (the "License");
   you may not use this file except in compliance with the License.
   You may obtain a copy of the License at

       http://www.apache.org/licenses/LICENSE-2.0

   Unless required by applicable law or agreed to in writing, software
   distributed under the License is distributed on an "AS IS" BASIS,
   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
   See the License for the specific language governing permissions and
   limitations under the License.

This was originally a comment on PR #31 that implements the idea proposed in #30.

There will always be a demand for more options to the Logger interface, but we have to balance the added value of these new options with the impact on the ecosystem of breaking changes. Constant breaking changes to the interface make this project less attractive. Ideally we will be able to define a v1.0 that will remain stable for years to come, without too many breaking changes getting there.

I would like to find a generic way to add arbitrary options and then just break compatibility once to add this new interface.

For example, we could add this method to the interface:

WithOption(option Option) Logger

with Option being some interface. This could be nothing more than an interface with some marker method that never actually gets called:

type Option interface {
    LogrOption()
}

Then we could define a new CallDepth option, which you would use as follows:

log = log.WithOption(logr.CallDepth(2))

Implementations would be required to ignore unknown options. Applications would be able to define their own custom options that get passed around.

We would always be able to add new 'official' options to the logr package without breaking the interface.

If we also add something similar to convert the logger into something else, we may never have to break the Logger interface again:

Convert(Conversion) interface{}

Usage example that would solve #11:

underlying := log.Convert(logr.Underlying).(*logrus.Logger)

When wrapping a logr instance with some additional helper functions, it may be necessary to inform the wrapped instance that it has to skip additional levels in the call stack to find the actual source code location for the log message.

Thanks for logr.

I've been using logr across the components of an app, deployed to different different Google Cloud Platform (GCP) services (GKE, Cloud Functions, Cloud Run) and all use Cloud Logging.

To benefit most from Cloud Logging, I want to use structured logging but:

1. Cloud Logging requires that log entries be JSON formatted
2. Cloud Logging requires that logs use GCP-specific keys (e.g. logging.googleapis.com/labels, logging.googleapis.com/sourceLocation)

For (1), I've switched from stdr to zerologr to emit JSON-formatted logs.

This requires taking a dependency on rs/zerolog when all I really need is the standard library's encoding/json.

Unfortunately, zerologr entries omit the caller (file, line) struct that's almost a match for Cloud Logging's SourceLocation.

Is there a way to retain this?

For (2), I'm using the GCP-specific keys when writing logs but I'd prefer to not be so tightly bound.

Should I consider writing a JSON LogSink?

Can I chain LogSinks or would I then also need to write a LogSink that combines to JSON and GCP-specific keys?

Thanks!

A related but different stupid question, why do LogSinks bind Info and Err to a single writer? For container logging, I'd prefer to write Info to os.Stdout but Err to os.Stderr. As it is, I can either have one or the other, or I need to have duplicate Loggers so that I can stdout.Info and stderr.Err (and never stdout.Err or stderr.Info) which seems redundant.

We use a bunch of web middlewares, if a web middleware needs to attach contextual information into the logger, we can achieve it as below:

...
logger, _ := logr.FromContext(ctx)
newLogger := logger.WithValues("foo", foo, "bar", bar)
ctx = NewContext(ctx, newLogger)
...

Since there are so many middlewares attaching contextual information into the logger, it will end up making a long chain of Contexts (Refer to the source), and only the last Context that carries a logger would be used.

If there is a method for logger (e.g. UpdateValues) that appends new values into the existing logger without spawning a new logger, the long chain of Contexts could be avoided:

...
logger, _ := logr.FromContext(ctx)
logger.UpdateValues("foo", foo, "bar", bar)
...

If I pass you an InfoLogger, you can never log an error or use WithValues(). Is that a valuable restriction? Or should V() just return a full Logger, and V(3).V(2).V(1) would be the same as V(6) ?

One common pattern for logging is to pass the current logging context to called functions and types using a Go context. This decouples much of the program from a specific implementation of the logr interface. This is similar to adding a logger argument to every function but is more general since it allows non logr-aware packages to pass contexts through to logr-aware packages.

A suggested API (these are top level functions):

// FromContext returns a logr.Logger constructed from the context or returns a null logger if no
// logger details are found in the context.
func FromContext(ctx context.Context) logr.Logger

// NewContext returns a new context that embeds the logger.
func NewContext(ctx context.Context, l logr.Logger) context.Context

This can already be implemented in a separate package (I created logctxr as an example) but I thought it would be worth considering as a core addition to the logr package.

Updated 2020-10-20 to remove NewLogger function based on discussion

We were wondering recently why a mismatch between comment and struct member (LogTimestamps vs LogTimestamp) was not reported.

The reason is that golangci-lint by default suppresses several issues, including the one about comments. This can be disabled, which then leads to:

golangci-lint run -E revive --exclude-use-default=false
funcr/example/main.go:26:6: exported: exported type E should have comment or be unexported (revive)
type E struct {
     ^
funcr/example/main.go:34:1: exported: exported function Helper should have comment or be unexported (revive)
func Helper(log logr.Logger, msg string) {
^
logr.go:327:1: exported: comment on exported method Logger.Helper should be of the form "Helper ..." (revive)
// WithCallStackHelper returns a new Logger instance that skips the
^
funcr/funcr.go:83:2: exported: exported const None should have comment (or a comment on this block) or be unexported (revive)
	None MessageClass = iota
	^
funcr/funcr.go:330:1: exported: comment on exported method Formatter.Init should be of the form "Init ..." (revive)
// Note that this receiver is a pointer, so depth can be saved.
^
funcr/funcr.go:335:1: exported: exported method Formatter.Enabled should have comment or be unexported (revive)
func (f Formatter) Enabled(level int) bool {
^
funcr/funcr.go:355:1: exported: comment on exported method Formatter.FormatError should be of the form "FormatError ..." (revive)
// FormatInfo flattens an Error log message into strings.
^
funcr/funcr.go:386:1: exported: exported method Formatter.AddValues should have comment or be unexported (revive)
func (f *Formatter) AddValues(kvList []interface{}) {
^
funcr/funcr.go:392:1: exported: exported method Formatter.AddCallDepth should have comment or be unexported (revive)
func (f *Formatter) AddCallDepth(depth int) {

I don't mind being stricter, i.e. adding --exclude-use-default=false and fixing these findings.

## What

I bumped into an issue in my application that there were some dependencies using logr v0.1.0 and some v0.2.0, which might cause some errors.

Please consider using the standard Go module versioning, so it's possible to depend on multiple versions of this library.

See https://blog.golang.org/v2-go-modules for more details.

We can't just print " + str + " - it might contain (for example) newlines.

@thockin and I had an offline chat about structured logging (some related to kubernetes/enhancements#1367) and one idea that came up was that some sort of tuple type might speed up logging performance. One concern was that tuples might be annoying to express in go, if you have to include a type annotation with each instantiation. But it turns out you don't need this, as long as the slice is annotated, so you can do something like this:

package main

import (
	"fmt"
)

type S struct {
	k string
	v interface{}
}

func Log(m string, args ...S) {
	fmt.Println(m, args)
}

func main() {
	type N struct {
		n string
	}
	a := N{"foo"}
	b := N{"bar"}
	Log("test", []S{{"foo", a}, {"bar", b}}...)
}

You can also invoke Log like Log("", S{"foo", a}, S{"bar", b}), but with an import prefix on the annotation that can get verbose. Either way, it would be up to the user how to invoke it.

Tim asked me to file an issue with these notes, so here it is :-).

/assign @thockin

Since #19 has been resolved, can a v0.2.1 release be cut?

keysAndValues are used at Error, Info and WithValues functions

WithValues(keysAndValues ...interface{}) Logger

Implementators will need to check for tuples, and deal with scenarios where odd number of parameters are passed. That sounds tricky at compile time.

A key value type like

type KV map[string]interface{}

would solve this problem, with the downside of enforcing key to be an string, which I guess is something we can take for granted.

The use case of "github.com/go-logr/logr/testing" is for testing, and in tests an import of stdlib's "testing" is guaranteed. Hence, any use of "github.com/go-logr/logr/testing" requires to alias the import by definition. Would it be possible to give it a smarter name instead? Or, because a rename will break backwards compatibility, would it make sense to create a testr pkg in the same spirt as zapr, stdr, etc.?

As discussed in https://github.com/go-logr/logr/pull/103/files#r725865981, replacing invalid keys with <non-string-key-%d> (unique for each key/value pair in the call) was replaced with <non-string-key> (same key for everything) because it could no longer be guaranteed that the number is correct and really unique when both WithValues and function call parameters have the issue.

It would be useful to bring that back because if a log consumer only stores unique keys, then information is lost.

Is it possible to extend the API to accept context when logging? The reason is that we want to extract information from the context like opentelemetry trace ids (trace_id/span_id) or other information that we propagate in the app using the context.

Hello, the README says:

Ideally only main() knows what logging implementation is being used.

yet the examples, even of the various implementations, contain just the main() function.

Can you please provide a basic example how to use this across multiple packages in a single application, for beginners like me, explaining how to make the app/packages logging implementation-agnostic?

Thanks!

Spec says:

// While users are generally free to use key names of their choice, it's generally best to avoid
// using the following keys, as they're frequently used by implementations:
//
// - `"error"`: the underlying error value in the `Error` method.
// - `"stacktrace"`: the stack trace associated with a particular log line or error
//                   (often from the `Error` message).
// - `"caller"`: the calling information (file/line) of a particular log line.
// - `"msg"`: the log message.
// - `"level"`: the log level.
// - `"ts"`: the timestamp for a log line.
//
// Implementations are encouraged to make use of these keys to represent the above
// concepts, when neccessary (for example, in a pure-JSON output form, it would be
// necessary to represent at least message and timestamp as ordinary named values).

Maybe we should just reserve all keys starting with "_" or all keys starting with "logr." or even just the key named "logr" (which can be a struct) to segregate things provided by the impl from things provided by the user?

@munnerz
@DirectXMan12

I don't know if this is appropriate here or it should be an issue in each of the adapters.

When you have a type that implements the Marshaler interface logr will take the expected action and Marshal the type before sending it to the sink. If you have a Marshaler in a slice, map, or object logr will not marshal this type before sending it.

This means that different adapters (zapr, logrusr etc) are marshaling the object at different levels. For example, stdr will recursively unmarshal and get the expected behavior, but I would have to implement zap's/logrus's Marshaler interface to have the same effect. I created a gist, and a playground that demonstrates this.

What I expect to happen is that the object eventually sent to the sink would be unmarshaled uniformly across all adapters. So from my example:
stdr would output:

2009/11/10 23:00:00 "level"=0 "msg"="slice" "y"=[{"Value":2},{"Value":3}]

And zap would output:

{"level":"info","msg":"slice","y":[{"Value":2},{"Value":3}]}

I have a Go application which depends indirectly on logr which has been working consistently for months, but it has suddenly started showing compilation errors. I haven't made any changes to the project, it compiled without errors as recently as last Friday (28th May) but started showing errors on Tuesday 1st June):

k8s.io/klog/klog.go:705:10: invalid operation: logr != nil (mismatched types logr.Logger and nil);
k8s.io/klog/klog.go:919:4: undefined: logr.WithCallDepth

I see a new tag marked "BREAKING CHANGE" was released for this project (https://github.com/go-logr/logr/releases/tag/v1.0.0-rc1) at the time this occurred but can't work out how it is related because the dependencies in my project explicitly rely on v0.1.0 and v0.2.0 of logr.

My go.mod file specifies this: k8s.io/apimachinery v0.21.1, which has given rise in the go.sum file to the following dependencies (among others):

github.com/go-logr/logr v0.1.0/go.mod h1:ixOQHD9gLJUVQQ2ZOR7zLEifBX6tGkNJF4QyIY7sIas=
github.com/go-logr/logr v0.2.0 h1:QvGt2nLcHH0WK9orKa+ppBPAxREcH364nPUedEpK0TY=
github.com/go-logr/logr v0.2.0/go.mod h1:z6/tIYblkpsD+a4lm/fGIIU9mZ+XfAiaFtq7xTgseGU=
k8s.io/klog v1.0.0 h1:Pt+yjF5aB1xDSVbau4VsWe+dQNzA0qv1LlXdC2dF6Q8=
k8s.io/klog v1.0.0/go.mod h1:4Bi6QPql/J/LkTDqv7R/cd3hPo4k2DG6Ptcz060Ez5I=
k8s.io/klog/v2 v2.0.0/go.mod h1:PBfzABfn139FHAV07az/IF9Wp1bkk3vpT2XSJ76fSDE=
k8s.io/klog/v2 v2.4.0 h1:7+X0fUguPyrKEC4WjH8iGDg3laWgMo5tMnRTIGTTxGQ=
k8s.io/klog/v2 v2.4.0/go.mod h1:Od+F08eJP+W3HUb4pSrPpgp9DGU4GzlpG/TmITuYh/Y=
k8s.io/apimachinery v0.20.0 h1:jjzbTJRXk0unNS71L7h3lxGDH/2HPxMPaQY+MjECKL8=
k8s.io/apimachinery v0.20.0/go.mod h1:WlLqWAHZGg07AeltaI0MV5uk1Omp8xaN0JGLY6gkRpU=
k8s.io/apimachinery v0.20.2 h1:hFx6Sbt1oG0n6DZ+g4bFt5f6BoMkOjKWsQFu077M3Vg=
k8s.io/apimachinery v0.20.2/go.mod h1:WlLqWAHZGg07AeltaI0MV5uk1Omp8xaN0JGLY6gkRpU=

I'd appreciate any insight into the cause of the issue and how to fix it.

Following discussion in #25, it is probably a good idea to add a null.Logger to logr that ignores all messages.

This can be used as a default logger by components that optionally allow you to pass in a logger. If none is passed in, it can simply use the null logger for all its logging.

The implementation would live under a "null" subpackage and could look like this (needs doc comments):

package null

import "github.com/go-logr/logr"

type Logger struct{}

func (n Logger) Enabled() bool {
	return false
}

func (n Logger) Info(msg string, keysAndValues ...interface{}) {
}

func (n Logger) Error(err error, msg string, keysAndValues ...interface{}) {
}

func (n Logger) V(level int) logr.Logger {
	return n
}

func (n Logger) WithValues(keysAndValues ...interface{}) logr.Logger {
	return n
}

func (n Logger) WithName(name string) logr.Logger {
	return n
}

Usage:

import "github.com/go-logr/logr/null"

func foo() {
	l := null.Logger{}
}

I ran into this with klog in Kubernetes (see kubernetes/klog#278). While I haven't tested it, funcr is probably also affected, at least here but potentially also elsewhere:

The problem is that log calls might pass a nil pointer for a struct which implements fmt.Stringer, but then segfaults when called. Here's an example:
https://github.com/kubernetes/kubernetes/blob/a1e8a5bf39d48719dfbcf49ea09223ee04840502/pkg/kubelet/kubelet.go#L2334-L2335

I think it is reasonable to expect that a logging implementation is resilient against such problems. That means that funcr must either check for nil beforehand or deal with the panic. I'm undecided. Perhaps fmt.Sprintf("%q", <nil stringer>) can serve as reference.

In #31 we discussed an approach for adding optional features to a logger and settled on optional interfaces, like this one:

https://github.com/go-logr/zapr/blob/97f3a0a6a3f0212bdc9326c2c17054e0a9cd2e9f/zapr.go#L164-L174

Users would then do something like:

func helper(log logr.Logger, msg string) {
	log.WithCallDepth(2).Info(msg)

	if zaplogger, ok := log.(zapr.Underlier); ok {
		log.Info("have zap logger", "zapr", zaplogger)
	}
}

That no longer works because logr.Logger is a struct.

I have set the verbosity level as follows, as I essentially would like these to be like Debug level logs-
l.Log.V(10).Info("req reconciled", "req", req.NamespacedName)

How do I ensure these logs get printed, when I do want to view the logs at this verbosity level ?
Currently I only see the logs printed at l.Log.Info , which is default verbosity level as 0.

It seems useful to make it do strict JSON output (probably as an option).

E.g.

    log := funcr.New(
        func(pfx, args string) { fmt.Printf("{%q:%q, %s}\n", "logger", pfx, args) },                                                                                    
        funcr.Options{
            LogCaller:    funcr.All,
            LogTimestamp: true,
            OutputFormat: funcr.JSON,
        })

Prefix is still weird, so it requires the caller to do some formatting. Maybe in strict mode, the prefix is always blank, and args comes in a single JSON object. We can pick a key for the prefix ("logger" or "name"?). Do we need output to be {"foo":"bar"} or just "foo":"bar" ?

This isn't an issue with go-logr but it may be worth identifying as a potential trap for the unwary; I will update my blog post.

My naive implementation of RenderValuesHook was:

renderLabels := func(kvList []interface{}) []interface{} {
  // loggingLabels becomes the only label key
  return []interface{}{
    loggingLabels,
    funcr.PseudoStruct(kvList),
  }
}

This worked fine if WithValues is only called once per Logger. If WithValues is called again, the existing labels are nested within the new set, i.e.:

{
  "jsonPayload": {
    "logging.googleapis.com/labels": {
      "logging.googleapis.com/labels": { <--- INCORRECT
        "foo": "X"
      },
      "bar": "Y"
    }
  }
  "labels": {
    "instanceId": "00bf4bf0..."
  }
}

NOTE In my case, Google Cloud Logging no longer recognized the borked logging.googleapis.com/labels as special values and does not merge them with the labels field.

Using NewStdoutLogger, the issue does not occur:

	l := NewStdoutLogger()
	l.Info("info")

	l = l.WithValues("foo", "X")
	l.Info("info")

	l = l.WithValues("bar", "Y")
	l.Info("info")

Outputs:

"level"=0 "msg"="info"
"level"=0 "msg"="info" "foo"="X"
"level"=0 "msg"="info" "foo"="X" "bar"="Y"

So, it's an issue with my implementation.

I revised the implementation (improvements welcome):

renderLabels := func(kvList []interface{}) []interface{} {
  // If loggingLabels is present, it will be the first label key
  k, _ := kvList[0].(string)
  if k == loggingLabels && len(kvList) > 2 {
    // The label values should be a PseudoStruct
    v, _ := kvList[1].(funcr.PseudoStruct)
    // Append additional ([2:]) label keys|values to the existing loggingLabels
    // loggingLabels becomes the only label key
      return []interface{}{
        loggingLabels,
        append(v, funcr.PseudoStruct(kvList[2:])...),
      }
    }

    // loggingLabels becomes the only label key
    return []interface{}{
      loggingLabels,
      funcr.PseudoStruct(kvList),
    }
}

And, replacing NewStdoutLogger with NewStructuredLogger, I get:

{"level":0,"msg":"info"}
{"level":0,"msg":"info","logging.googleapis.com/labels":{"foo":"X"}}
{"level":0,"msg":"info","logging.googleapis.com/labels":{"foo":"X","bar":"Y"}}

https://github.com/screenleap/zerologr/tree/master

https://pkg.go.dev/github.com/go-logr/[email protected] shows subsections like this:

Overview

Package logr defines a general-purpose logging API and abstract interfaces to back that API. Packages in the Go ecosystem can depend on this package, while callers can implement logging with whatever backend is appropriate.

Usage ----- 

In Kubernetes, sometimes klog.ErrorF is called without having an error. During the structured logging migration, that then gets translated to klog.ErrorS(nil, ...). I wonder whether the same nil error would or should be allowed for a logr.Logger. If yes, then we should document it.

Currently it is undefined behavior, so one could argue that explicitly allowing it is not an API change and just documents how loggers should have been implemented all along anyway (tolerate user errors if it was considered as one, don't crash, etc.).

type T struct {    
    P *T    
}    

func example(log logr.Logger) {    
    t := T{}    
    t.P = &t    
    log.Info("recurse", "t", t)     
}

yields a (predictable) stack overflow.

We probably should add a max-depth option or track a stack of pointers across pretty calls and not print pointers already in the stack. Or both.

To do this we'd need to change the API - function signature or something.

This might be another one of my ideas that aren't useful enough in practice, but let me share it anyway...

In a few places in Kubernetes, if Enabled() is used to choose between two different log calls where the difference is the amount of information that gets logged. In other words, at higher log levels one does not only get more log entries, but also more detailed ones.

This can be done at the call site with the existing API, but it becomes less readable:

if logV := logger.V(5); logV.Enabled() {
    logV.Info("hello", "v1", 1, "v3", 3, "v5", 5)
else if logV := logger.V(3); logV.Enabled() {
    logV.Info("hello", "v1", 1, "v3", 3)
} else {
    log.V(1).Info("hello", "v1", 1)
}

One option would be to create a []interface{} slice with the parameters. The klog logchecker will complain about that, though, because it cannot do a static analysis that the key/value pairs are well-formed:

kv := []interface{}{"v1", 1}
if logger.V(3).Enabled() {
    kv := append(kv, "v3", 3)
    if logger.V(5).Enabled() {
        kv := append(kv, "v5", 5)
    }
}
log.V(1).Info("hello", kv...)

This could remain a single call if we had a way to express verbosity of each key/value pair, for example like this:

log.V(1).Info("hello", "v1", 1, logr.KeyV(3, "v3"), 3, logr.KeyV(5, "v5"), 5)

func KeyV(int level, key string) { return keyV{level: level, key: key} }

type keyV struct {
    level int
    key string
}

func (k keyV) String { return k.key }
func (k keyV) Level int { return k.level }

type LeveledStringer interface {
    fmt.Stringer
    Level() int
}

Loggers which support this could check for this interface and skip key/value pairs which are above the threshold. Those that don't still can construct a string key, without having to be modified.

Today, I found the comparability of NullLogger useful to assert that a particular Logger instance was making it through a few layers of injection. A bit like the following two snippets:

https://play.golang.org/p/4V5uhqJor6J

ctx := context.Background()
double := struct{ logr.Logger }{testing.NullLogger{}}
assert.Equal(t, double, logr.FromContext(logr.NewContext(ctx, double)))

Do you think this is a property that can be documented and maintained here in logr? If so, this test might suffice:

package testing

import (
	"reflect"
	"testing"

	"github.com/go-logr/logr"
)

func TestNullComparable(t *testing.T) {
	var a logr.Logger = NullLogger{}
	if !reflect.TypeOf(a).Comparable() {
		t.Fatal("null logger should be comparable")
	}

	var b logr.Logger = NullLogger{}
	if a != b {
		t.Fatal("two null loggers should be equal")
	}
}