-vmodule does not work for users of klogr interface

[michael-db]

/kind bug

The -vmodule option works as expected where klog is used directly. However, where the the klog/klogr interface is used for logging, all such calls are treated as originating in klogr.go rather than the ultimate calling code.

What steps did you take and what happened:

package main

import (
    "errors"
    "flag"
    "github.com/go-logr/logr"
    "k8s.io/klog"
    "k8s.io/klog/klogr"
)

func main() {
    klog.InitFlags(nil)
    flag.Parse()

    var log logr.Logger
    log = klogr.New()
    log.V(0).Info("Info message.")
    log.V(1).Info("Info 1 message.")
    log.Error(errors.New("oops"), "Error.")
}

: logtest 112;  go build && ./logtest -vmodule main=1
I1112 17:02:45.832252   32339 main.go:46]  "msg"="Info message."  
E1112 17:02:45.832337   32339 main.go:48]  "msg"="Error." "error"="oops"  
: logtest 113;  go build && ./logtest -vmodule klogr=1
I1112 17:05:30.792956   32449 main.go:46]  "msg"="Info message."  
I1112 17:05:30.793030   32449 main.go:47]  "msg"="Info 1 message."  
E1112 17:05:30.793038   32449 main.go:48]  "msg"="Error." "error"="oops"  

What did you expect to happen:

: logtest 112;  go build && ./logtest -vmodule main=1
I1112 17:02:45.832252   32339 main.go:46]  "msg"="Info message."  
I1112 17:05:30.793030   32449 main.go:47]  "msg"="Info 1 message."  
E1112 17:02:45.832337   32339 main.go:48]  "msg"="Error." "error"="oops"  
: logtest 113;  go build && ./logtest -vmodule klogr=1
I1112 17:05:30.792956   32449 main.go:46]  "msg"="Info message."  
E1112 17:05:30.793038   32449 main.go:48]  "msg"="Error." "error"="oops"  

Anything else you would like to add:

From a casual review, this is probably an issue with klogr.go's framesToCaller() function.

[fejta-bot]

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

[fejta-bot]

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle rotten

[fejta-bot]

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

[k8s-ci-robot]

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[greut]

the vmodule filtering is done on the Verbose side, b598b73436b594359a89e548fe3caffab0f9cc93 However, klogr doesn't use it.