Skip to content

Commit f440675

Browse files
committed
client: report caller line for OpenStack debug logs
The Logger.Printf wrapper used a hard-coded stack-frame window [10..20] and matched only /github.com/gophercloud/gophercloud, which fails to span gophercloud/utils where the RoundTripper now lives. With modern net/http the real caller is outside that window, so klog falls back to the wrapper's own line and every debug entry is shown as client.go:128. Walk the full stack and pick the frame above the deepest gophercloud frame (matching both gophercloud/gophercloud and gophercloud/utils) so klog attributes the log to the originating call site. Signed-off-by: SAY-5 <say.apm35@gmail.com>
1 parent f89581e commit f440675

2 files changed

Lines changed: 107 additions & 13 deletions

File tree

pkg/client/client.go

Lines changed: 11 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -106,22 +106,20 @@ func (l Logger) Printf(format string, args ...interface{}) {
106106

107107
// extra check in case, when verbosity has been changed dynamically
108108
if debugger {
109+
// Walk the stack and find the deepest gophercloud frame (matches both
110+
// gophercloud/gophercloud and gophercloud/utils, where the
111+
// RoundTripper lives). The frame above it is the actual caller that
112+
// triggered the API request, which is what we want klog to report.
113+
const gc = "/github.com/gophercloud/"
109114
var skip int
110-
var found bool
111-
var gc = "/github.com/gophercloud/gophercloud"
112-
113-
// detect the depth of the actual function, which calls gophercloud code
114-
// 10 is the common depth from the logger to "github.com/gophercloud/gophercloud/v2"
115-
for i := 10; i <= 20; i++ {
116-
if _, file, _, ok := runtime.Caller(i); ok && !found && strings.Contains(file, gc) {
117-
found = true
118-
continue
119-
} else if ok && found && !strings.Contains(file, gc) {
120-
skip = i
121-
break
122-
} else if !ok {
115+
for i := 1; ; i++ {
116+
_, file, _, ok := runtime.Caller(i)
117+
if !ok {
123118
break
124119
}
120+
if strings.Contains(file, gc) {
121+
skip = i + 1
122+
}
125123
}
126124

127125
for _, v := range strings.Split(fmt.Sprintf(format, args...), "\n") {

pkg/client/client_test.go

Lines changed: 96 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,96 @@
1+
/*
2+
Copyright 2026 The Kubernetes Authors.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
6+
You may obtain a copy of the License at
7+
8+
http://www.apache.org/licenses/LICENSE-2.0
9+
10+
Unless required by applicable law or agreed to in writing, software
11+
distributed under the License is distributed on an "AS IS" BASIS,
12+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
See the License for the specific language governing permissions and
14+
limitations under the License.
15+
*/
16+
17+
package client
18+
19+
import (
20+
"bytes"
21+
"context"
22+
"flag"
23+
"net/http"
24+
"net/http/httptest"
25+
"strings"
26+
"testing"
27+
28+
"github.com/gophercloud/gophercloud/v2"
29+
"github.com/gophercloud/gophercloud/v2/openstack"
30+
"github.com/gophercloud/utils/v2/client"
31+
"k8s.io/klog/v2"
32+
)
33+
34+
// TestLoggerReportsCallerLine verifies that debug log lines emitted through
35+
// the Logger wrapper are attributed to the caller that initiated the
36+
// gophercloud request, not to the wrapper file itself (issue #2300).
37+
func TestLoggerReportsCallerLine(t *testing.T) {
38+
state := klog.CaptureState()
39+
defer state.Restore()
40+
41+
var fs flag.FlagSet
42+
klog.InitFlags(&fs)
43+
if err := fs.Set("v", "6"); err != nil {
44+
t.Fatalf("failed to set verbosity: %v", err)
45+
}
46+
if err := fs.Set("logtostderr", "false"); err != nil {
47+
t.Fatalf("failed to set logtostderr: %v", err)
48+
}
49+
if err := fs.Set("skip_headers", "false"); err != nil {
50+
t.Fatalf("failed to set skip_headers: %v", err)
51+
}
52+
53+
var buf bytes.Buffer
54+
klog.SetOutput(&buf)
55+
56+
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
57+
w.Header().Set("Content-Type", "application/json")
58+
w.WriteHeader(http.StatusOK)
59+
_, _ = w.Write([]byte(`{}`))
60+
}))
61+
defer srv.Close()
62+
63+
provider, err := openstack.NewClient(srv.URL)
64+
if err != nil {
65+
t.Fatalf("failed to build provider: %v", err)
66+
}
67+
provider.HTTPClient = http.Client{
68+
Transport: &client.RoundTripper{
69+
Rt: http.DefaultTransport,
70+
Logger: &Logger{},
71+
},
72+
}
73+
74+
if _, err := provider.Request(context.Background(), http.MethodGet, srv.URL, &gophercloud.RequestOpts{
75+
KeepResponseBody: true,
76+
OkCodes: []int{http.StatusOK},
77+
}); err != nil {
78+
t.Fatalf("request failed: %v", err)
79+
}
80+
81+
klog.Flush()
82+
83+
output := buf.String()
84+
if output == "" {
85+
t.Fatalf("expected klog output, got none")
86+
}
87+
// The wrapper's own file must not appear as the source location, since
88+
// that would mean every debug line is mis-attributed to client.go (the
89+
// behavior reported in issue #2300).
90+
if strings.Contains(output, "client.go:") && !strings.Contains(output, "client_test.go:") {
91+
t.Fatalf("debug output is attributed to the wrapper, expected the caller; got:\n%s", output)
92+
}
93+
if !strings.Contains(output, "client_test.go:") {
94+
t.Fatalf("expected debug output to reference the test caller (client_test.go); got:\n%s", output)
95+
}
96+
}

0 commit comments

Comments
 (0)