Skip to content

Commit d9fe1cc

Browse files
konstantin-s-bogomgvisor-bot
konstantin-s-bogom
authored and
gvisor-bot
committed
Put some WARNs in Systrap.
PiperOrigin-RevId: 789498131
1 parent 6cadfa6 commit d9fe1cc

File tree

6 files changed

+335
-2
lines changed

6 files changed

+335
-2
lines changed

‎pkg/log/BUILD

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ go_library(
1313
"json_k8s.go",
1414
"log.go",
1515
"rate_limited.go",
16+
"warn_on.go",
1617
],
1718
marshal = False,
1819
stateify = False,
@@ -32,6 +33,7 @@ go_test(
3233
srcs = [
3334
"json_test.go",
3435
"log_test.go",
36+
"warn_on_test.go",
3537
],
3638
library = ":log",
3739
)

‎pkg/log/log.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -396,4 +396,6 @@ func CopyStandardLogTo(l Level) error {
396396
func init() {
397397
// Store the initial value for the log.
398398
log.Store(&BasicLogger{Level: Info, Emitter: GoogleEmitter{&Writer{Next: os.Stderr}}})
399+
400+
warnedSet = make(map[string]struct{})
399401
}

‎pkg/log/log_test.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,10 @@ func (w *testWriter) Write(bytes []byte) (int, error) {
3737
return len(bytes), nil
3838
}
3939

40+
func (w *testWriter) clear() {
41+
w.lines = nil
42+
}
43+
4044
func TestDropMessages(t *testing.T) {
4145
tw := &testWriter{}
4246
w := Writer{Next: tw}

‎pkg/log/warn_on.go

Lines changed: 182 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,182 @@
1+
// Copyright 2025 The gVisor Authors.
2+
//
3+
// Licensed under the Apache License, Version 2.0 (the "License");
4+
// you may not use this file except in compliance with the License.
5+
// You may obtain a copy of the License at
6+
//
7+
// http://www.apache.org/licenses/LICENSE-2.0
8+
//
9+
// Unless required by applicable law or agreed to in writing, software
10+
// distributed under the License is distributed on an "AS IS" BASIS,
11+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
// See the License for the specific language governing permissions and
13+
// limitations under the License.
14+
15+
package log
16+
17+
import (
18+
"fmt"
19+
"runtime"
20+
"strings"
21+
22+
"gvisor.dev/gvisor/pkg/sync"
23+
)
24+
25+
const (
26+
warnFmtStr = "WARNING: BUG on %s:%d\n"
27+
warnUnknownLineStr = "WARNING: BUG on unknown line\n"
28+
catchAllMagic = "runtime.Caller failed"
29+
)
30+
31+
func warn(caller int, msg string) {
32+
var b strings.Builder
33+
if _, file, line, ok := runtime.Caller(caller); ok {
34+
b.WriteString(fmt.Sprintf(warnFmtStr, file, line))
35+
} else {
36+
b.WriteString(warnUnknownLineStr)
37+
}
38+
b.WriteByte('\n')
39+
if len(msg) > 0 {
40+
b.WriteString(msg)
41+
b.WriteByte('\n')
42+
}
43+
TracebackAll(b.String())
44+
}
45+
46+
var (
47+
// warnedMu protects the variables below.
48+
warnedMu sync.Mutex
49+
// warnedSet is used to keep track of which WarnOnOnce calls have fired.
50+
warnedSet map[string]struct{}
51+
)
52+
53+
func warnOnce(caller int, msg string) {
54+
var b strings.Builder
55+
if _, file, line, ok := runtime.Caller(caller); ok {
56+
key := fmt.Sprintf("%s:%d", file, line)
57+
58+
warnedMu.Lock()
59+
defer warnedMu.Unlock()
60+
61+
if _, ok = warnedSet[key]; !ok {
62+
b.WriteString(fmt.Sprintf(warnFmtStr, file, line))
63+
b.WriteByte('\n')
64+
if len(msg) > 0 {
65+
b.WriteString(msg)
66+
b.WriteByte('\n')
67+
}
68+
69+
TracebackAll(b.String())
70+
warnedSet[key] = struct{}{}
71+
}
72+
} else {
73+
warnedMu.Lock()
74+
defer warnedMu.Unlock()
75+
76+
// Use const string as a catch-all when runtime.Caller fails,
77+
// so as to avoid log-spam since that's the point of WARN_ONCE.
78+
if _, ok := warnedSet[catchAllMagic]; !ok {
79+
b.WriteString(warnUnknownLineStr)
80+
b.WriteByte('\n')
81+
if len(msg) > 0 {
82+
b.WriteString(msg)
83+
b.WriteByte('\n')
84+
}
85+
86+
TracebackAll(b.String())
87+
warnedSet[catchAllMagic] = struct{}{}
88+
}
89+
}
90+
}
91+
92+
// WARN serves the same purpose as the Linux kernel's WARN macro. Use it
93+
// for reporting abnormal bugs encountered at runtime that should be fixed.
94+
//
95+
// Will print out the full Go stacktrace at time of invocation.
96+
//
97+
// Do not use this for bad user input. Errors reported by this function should
98+
// not be fatal.
99+
func WARN(cond bool, s string, a ...any) {
100+
if !cond {
101+
return
102+
}
103+
msg := fmt.Sprintf(s, a...)
104+
warn(2, msg)
105+
}
106+
107+
// WARN_ON serves the same purpose as the Linux kernel's WARN_ON macro. Use it
108+
// for reporting abnormal bugs encountered at runtime that should be fixed.
109+
//
110+
// Will print out the full Go stacktrace at time of invocation.
111+
//
112+
// Do not use this for bad user input. Errors reported by this function should
113+
// not be fatal.
114+
func WARN_ON(cond bool) {
115+
if !cond {
116+
return
117+
}
118+
warn(2, "")
119+
}
120+
121+
// WARN_ERR is a more Go-friendly version of the typical Linux WARN* macros. If
122+
// the error isn't nil, it will report the error prefixed with the standard WARN
123+
// string. Use it for reporting abnormal bugs encountered at runtime that
124+
// should be fixed.
125+
//
126+
// Will print out the full Go stacktrace at time of invocation.
127+
//
128+
// Do not use this for bad user input. Errors reported by this function should
129+
// not be fatal.
130+
func WARN_ERR(err error) {
131+
if err == nil {
132+
return
133+
}
134+
warn(2, err.Error())
135+
}
136+
137+
// WARN_ONCE serves the same purpose as the Linux kernel's WARN_ONCE macro.
138+
// Use it for reporting abnormal bugs encountered at runtime that should be
139+
// fixed.
140+
//
141+
// Will print out the full Go stacktrace at time of invocation.
142+
//
143+
// Do not use this for bad user input. Errors reported by this function should
144+
// not be fatal.
145+
func WARN_ONCE(cond bool, s string, a ...any) {
146+
if !cond {
147+
return
148+
}
149+
msg := fmt.Sprintf(s, a...)
150+
warnOnce(2, msg)
151+
}
152+
153+
// WARN_ON_ONCE serves the same purpose as the Linux kernel's WARN_ON_ONCE macro.
154+
// Use it for reporting abnormal bugs encountered at runtime that should be
155+
// fixed.
156+
//
157+
// Will print out the full Go stacktrace at time of invocation.
158+
//
159+
// Do not use this for bad user input. Errors reported by this function should
160+
// not be fatal.
161+
func WARN_ON_ONCE(cond bool) {
162+
if !cond {
163+
return
164+
}
165+
warnOnce(2, "")
166+
}
167+
168+
// WARN_ERR_ONCE is a more Go-friendly version of the typical Linux WARN* macros.
169+
// If the error isn't nil, it will report the error prefixed with the standard
170+
// WARN string. Use it for reporting abnormal bugs encountered at runtime that
171+
// should be fixed.
172+
//
173+
// Will print out the full Go stacktrace at time of invocation.
174+
//
175+
// Do not use this for bad user input. Errors reported by this function should
176+
// not be fatal.
177+
func WARN_ERR_ONCE(err error) {
178+
if err == nil {
179+
return
180+
}
181+
warnOnce(2, err.Error())
182+
}

‎pkg/log/warn_on_test.go

Lines changed: 141 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,141 @@
1+
// Copyright 2025 The gVisor Authors.
2+
//
3+
// Licensed under the Apache License, Version 2.0 (the "License");
4+
// you may not use this file except in compliance with the License.
5+
// You may obtain a copy of the License at
6+
//
7+
// http://www.apache.org/licenses/LICENSE-2.0
8+
//
9+
// Unless required by applicable law or agreed to in writing, software
10+
// distributed under the License is distributed on an "AS IS" BASIS,
11+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
// See the License for the specific language governing permissions and
13+
// limitations under the License.
14+
15+
package log
16+
17+
import (
18+
"fmt"
19+
"strings"
20+
"testing"
21+
)
22+
23+
func TestWarnOn(t *testing.T) {
24+
tw := &testWriter{}
25+
e := GoogleEmitter{Writer: &Writer{Next: tw}}
26+
bl := &BasicLogger{
27+
Emitter: e,
28+
Level: Debug,
29+
}
30+
old := Log()
31+
log.Store(bl)
32+
defer log.Store(old)
33+
34+
testCases := map[string]func(t *testing.T){
35+
"testConditionControlsPrint": func(t *testing.T) {
36+
WARN_ON(false)
37+
if len(tw.lines) > 0 {
38+
t.Errorf("WARN_ON printed when it shouldn't have")
39+
}
40+
41+
WARN_ON(true)
42+
if len(tw.lines) == 0 {
43+
t.Errorf("WARN_ON didn't print anything when it should have")
44+
}
45+
},
46+
"testStringFormat": func(t *testing.T) {
47+
expectFile := "pkg/log/warn_on_test.go"
48+
// Don't try to match the line to make this test less
49+
// brittle to somebody accidentally sneezing on this file.
50+
expectStr := strings.SplitN(warnFmtStr, "%", 2)[0]
51+
52+
WARN_ON(true)
53+
54+
if len(tw.lines) == 0 {
55+
t.Errorf("WARN_ON didn't print anything when it should have")
56+
}
57+
if !strings.Contains(tw.lines[0], expectFile) {
58+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectFile, tw.lines[0])
59+
}
60+
if !strings.Contains(tw.lines[0], expectStr) {
61+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectStr, tw.lines[0])
62+
}
63+
},
64+
"testCustomFormat": func(t *testing.T) {
65+
expectFile := "pkg/log/warn_on_test.go"
66+
expectStr1 := strings.SplitN(warnFmtStr, "%", 2)[0]
67+
expectStr2 := "This is just a test warning"
68+
WARN(true, "This is just a test warning")
69+
70+
if len(tw.lines) == 0 {
71+
t.Errorf("WARN_ON didn't print anything when it should have")
72+
}
73+
if !strings.Contains(tw.lines[0], expectFile) {
74+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectFile, tw.lines[0])
75+
}
76+
if !strings.Contains(tw.lines[0], expectStr1) {
77+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectStr1, tw.lines[0])
78+
}
79+
if !strings.Contains(tw.lines[0], expectStr2) {
80+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectStr2, tw.lines[0])
81+
}
82+
},
83+
"testWarnErr": func(t *testing.T) {
84+
expectFile := "pkg/log/warn_on_test.go"
85+
expectStr1 := strings.SplitN(warnFmtStr, "%", 2)[0]
86+
expectStr2 := "My little error string"
87+
var err error
88+
WARN_ERR(err)
89+
if len(tw.lines) > 0 {
90+
t.Errorf("WARN_ON printed when it shouldn't have")
91+
}
92+
93+
err = fmt.Errorf("My little error string")
94+
WARN_ERR(err)
95+
if len(tw.lines) == 0 {
96+
t.Errorf("WARN_ON didn't print anything when it should have")
97+
}
98+
if !strings.Contains(tw.lines[0], expectFile) {
99+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectFile, tw.lines[0])
100+
}
101+
if !strings.Contains(tw.lines[0], expectStr1) {
102+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectStr1, tw.lines[0])
103+
}
104+
if !strings.Contains(tw.lines[0], expectStr2) {
105+
t.Errorf("WARN_ON didn't contain expected output, expected: '%s', got: '%s'", expectStr2, tw.lines[0])
106+
}
107+
},
108+
"testWarnOnceOnlyPrintsOnce": func(t *testing.T) {
109+
testHelperFunc := func() {
110+
WARN_ON_ONCE(true)
111+
}
112+
113+
testHelperFunc()
114+
if len(tw.lines) == 0 {
115+
t.Errorf("WarnOnOnce didn't print anything when it should have")
116+
}
117+
tw.clear()
118+
119+
testHelperFunc()
120+
if len(tw.lines) > 0 {
121+
t.Errorf("WarnOnOnce printed out a warning a second time when it shouldn't have")
122+
}
123+
},
124+
"testWarnOnceDoesntClobberOthers": func(t *testing.T) {
125+
WARN_ON_ONCE(true)
126+
if len(tw.lines) == 0 {
127+
t.Errorf("First WarnOnOnce didn't print anything when it should have")
128+
}
129+
tw.clear()
130+
131+
WARN_ON_ONCE(true)
132+
if len(tw.lines) == 0 {
133+
t.Errorf("Second WarnOnOnce didn't print anything when it should have")
134+
}
135+
},
136+
}
137+
for name, tc := range testCases {
138+
tw.clear()
139+
t.Run(name, tc)
140+
}
141+
}

‎pkg/sentry/platform/systrap/subprocess.go

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -228,7 +228,7 @@ func handlePtraceSyscallRequestError(req any, format string, values ...any) {
228228
case requestStub:
229229
req.(requestStub).done <- nil
230230
}
231-
log.Warningf("handlePtraceSyscallRequest failed: "+format, values...)
231+
log.WARN(true, "handlePtraceSyscallRequest failed: "+format, values...)
232232
}
233233

234234
// handlePtraceSyscallRequest executes system calls that can't be run via
@@ -846,7 +846,9 @@ func (s *subprocess) switchToApp(c *platformContext, ac *arch.Context64) (isSysc
846846
threadID := ctx.threadID()
847847
if threadID != invalidThreadID {
848848
if sysThread, ok := s.sysmsgThreads[threadID]; ok && sysThread.msg.Err != 0 {
849-
return false, false, hostarch.NoAccess, sysThread.msg.ConvertSysmsgErr()
849+
sysmsgErr := sysThread.msg.ConvertSysmsgErr()
850+
log.WARN_ERR(sysmsgErr)
851+
return false, false, hostarch.NoAccess, sysmsgErr
850852
}
851853
return false, false, hostarch.NoAccess, corruptedSharedMemoryErr(fmt.Sprintf("found unexpected ThreadContext.ThreadID field, expected %d found %d", invalidThreadID, threadID))
852854
}

0 commit comments

Comments
 (0)