1 | // SPDX-License-Identifier: GPL-2.0 |
2 | /* Copyright (c) 2023 Meta Platforms, Inc. and affiliates. */ |
3 | |
4 | #include <test_progs.h> |
5 | #include <bpf/btf.h> |
6 | |
7 | #include "test_log_buf.skel.h" |
8 | |
9 | |
10 | static bool check_prog_load(int prog_fd, bool expect_err, const char *tag) |
11 | { |
12 | if (expect_err) { |
13 | if (!ASSERT_LT(prog_fd, 0, tag)) { |
14 | close(prog_fd); |
15 | return false; |
16 | } |
17 | } else /* !expect_err */ { |
18 | if (!ASSERT_GT(prog_fd, 0, tag)) |
19 | return false; |
20 | } |
21 | if (prog_fd >= 0) |
22 | close(prog_fd); |
23 | return true; |
24 | } |
25 | |
26 | static struct { |
27 | /* strategically placed before others to avoid accidental modification by kernel */ |
28 | char filler[1024]; |
29 | char buf[1024]; |
30 | /* strategically placed after buf[] to catch more accidental corruptions */ |
31 | char reference[1024]; |
32 | } logs; |
33 | static const struct bpf_insn *insns; |
34 | static size_t insn_cnt; |
35 | |
36 | static int load_prog(struct bpf_prog_load_opts *opts, bool expect_load_error) |
37 | { |
38 | int prog_fd; |
39 | |
40 | prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, "log_prog" , |
41 | "GPL" , insns, insn_cnt, opts); |
42 | check_prog_load(prog_fd, expect_load_error, "prog_load" ); |
43 | |
44 | return prog_fd; |
45 | } |
46 | |
47 | static void verif_log_subtest(const char *name, bool expect_load_error, int log_level) |
48 | { |
49 | LIBBPF_OPTS(bpf_prog_load_opts, opts); |
50 | char *exp_log, prog_name[16], op_name[32]; |
51 | struct test_log_buf *skel; |
52 | struct bpf_program *prog; |
53 | size_t fixed_log_sz; |
54 | __u32 log_true_sz_fixed, log_true_sz_rolling; |
55 | int i, mode, err, prog_fd, res; |
56 | |
57 | skel = test_log_buf__open(); |
58 | if (!ASSERT_OK_PTR(skel, "skel_open" )) |
59 | return; |
60 | |
61 | bpf_object__for_each_program(prog, skel->obj) { |
62 | if (strcmp(bpf_program__name(prog), name) == 0) |
63 | bpf_program__set_autoload(prog, true); |
64 | else |
65 | bpf_program__set_autoload(prog, false); |
66 | } |
67 | |
68 | err = test_log_buf__load(skel); |
69 | if (!expect_load_error && !ASSERT_OK(err, "unexpected_load_failure" )) |
70 | goto cleanup; |
71 | if (expect_load_error && !ASSERT_ERR(err, "unexpected_load_success" )) |
72 | goto cleanup; |
73 | |
74 | insns = bpf_program__insns(skel->progs.good_prog); |
75 | insn_cnt = bpf_program__insn_cnt(skel->progs.good_prog); |
76 | |
77 | opts.log_buf = logs.reference; |
78 | opts.log_size = sizeof(logs.reference); |
79 | opts.log_level = log_level | 8 /* BPF_LOG_FIXED */; |
80 | load_prog(&opts, expect_load_error); |
81 | |
82 | fixed_log_sz = strlen(logs.reference) + 1; |
83 | if (!ASSERT_GT(fixed_log_sz, 50, "fixed_log_sz" )) |
84 | goto cleanup; |
85 | memset(logs.reference + fixed_log_sz, 0, sizeof(logs.reference) - fixed_log_sz); |
86 | |
87 | /* validate BPF_LOG_FIXED works as verifier log used to work, that is: |
88 | * we get -ENOSPC and beginning of the full verifier log. This only |
89 | * works for log_level 2 and log_level 1 + failed program. For log |
90 | * level 2 we don't reset log at all. For log_level 1 + failed program |
91 | * we don't get to verification stats output. With log level 1 |
92 | * for successful program final result will be just verifier stats. |
93 | * But if provided too short log buf, kernel will NULL-out log->ubuf |
94 | * and will stop emitting further log. This means we'll never see |
95 | * predictable verifier stats. |
96 | * Long story short, we do the following -ENOSPC test only for |
97 | * predictable combinations. |
98 | */ |
99 | if (log_level >= 2 || expect_load_error) { |
100 | opts.log_buf = logs.buf; |
101 | opts.log_level = log_level | 8; /* fixed-length log */ |
102 | opts.log_size = 25; |
103 | |
104 | prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, "log_fixed25" , |
105 | "GPL" , insns, insn_cnt, &opts); |
106 | if (!ASSERT_EQ(prog_fd, -ENOSPC, "unexpected_log_fixed_prog_load_result" )) { |
107 | if (prog_fd >= 0) |
108 | close(prog_fd); |
109 | goto cleanup; |
110 | } |
111 | if (!ASSERT_EQ(strlen(logs.buf), 24, "log_fixed_25" )) |
112 | goto cleanup; |
113 | if (!ASSERT_STRNEQ(logs.buf, logs.reference, 24, "log_fixed_contents_25" )) |
114 | goto cleanup; |
115 | } |
116 | |
117 | /* validate rolling verifier log logic: try all variations of log buf |
118 | * length to force various truncation scenarios |
119 | */ |
120 | opts.log_buf = logs.buf; |
121 | |
122 | /* rotating mode, then fixed mode */ |
123 | for (mode = 1; mode >= 0; mode--) { |
124 | /* prefill logs.buf with 'A's to detect any write beyond allowed length */ |
125 | memset(logs.filler, 'A', sizeof(logs.filler)); |
126 | logs.filler[sizeof(logs.filler) - 1] = '\0'; |
127 | memset(logs.buf, 'A', sizeof(logs.buf)); |
128 | logs.buf[sizeof(logs.buf) - 1] = '\0'; |
129 | |
130 | for (i = 1; i < fixed_log_sz; i++) { |
131 | opts.log_size = i; |
132 | opts.log_level = log_level | (mode ? 0 : 8 /* BPF_LOG_FIXED */); |
133 | |
134 | snprintf(prog_name, sizeof(prog_name), |
135 | "log_%s_%d" , mode ? "roll" : "fixed" , i); |
136 | prog_fd = bpf_prog_load(BPF_PROG_TYPE_RAW_TRACEPOINT, prog_name, |
137 | "GPL" , insns, insn_cnt, &opts); |
138 | |
139 | snprintf(op_name, sizeof(op_name), |
140 | "log_%s_prog_load_%d" , mode ? "roll" : "fixed" , i); |
141 | if (!ASSERT_EQ(prog_fd, -ENOSPC, op_name)) { |
142 | if (prog_fd >= 0) |
143 | close(prog_fd); |
144 | goto cleanup; |
145 | } |
146 | |
147 | snprintf(op_name, sizeof(op_name), |
148 | "log_%s_strlen_%d" , mode ? "roll" : "fixed" , i); |
149 | ASSERT_EQ(strlen(logs.buf), i - 1, op_name); |
150 | |
151 | if (mode) |
152 | exp_log = logs.reference + fixed_log_sz - i; |
153 | else |
154 | exp_log = logs.reference; |
155 | |
156 | snprintf(op_name, sizeof(op_name), |
157 | "log_%s_contents_%d" , mode ? "roll" : "fixed" , i); |
158 | if (!ASSERT_STRNEQ(logs.buf, exp_log, i - 1, op_name)) { |
159 | printf("CMP:%d\nS1:'%s'\nS2:'%s'\n" , |
160 | strncmp(logs.buf, exp_log, i - 1), |
161 | logs.buf, exp_log); |
162 | goto cleanup; |
163 | } |
164 | |
165 | /* check that unused portions of logs.buf is not overwritten */ |
166 | snprintf(op_name, sizeof(op_name), |
167 | "log_%s_unused_%d" , mode ? "roll" : "fixed" , i); |
168 | if (!ASSERT_STREQ(logs.buf + i, logs.filler + i, op_name)) { |
169 | printf("CMP:%d\nS1:'%s'\nS2:'%s'\n" , |
170 | strcmp(logs.buf + i, logs.filler + i), |
171 | logs.buf + i, logs.filler + i); |
172 | goto cleanup; |
173 | } |
174 | } |
175 | } |
176 | |
177 | /* (FIXED) get actual log size */ |
178 | opts.log_buf = logs.buf; |
179 | opts.log_level = log_level | 8; /* BPF_LOG_FIXED */ |
180 | opts.log_size = sizeof(logs.buf); |
181 | opts.log_true_size = 0; |
182 | res = load_prog(&opts, expect_load_error); |
183 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_fixed" ); |
184 | |
185 | log_true_sz_fixed = opts.log_true_size; |
186 | ASSERT_GT(log_true_sz_fixed, 0, "log_true_sz_fixed" ); |
187 | |
188 | /* (FIXED, NULL) get actual log size */ |
189 | opts.log_buf = NULL; |
190 | opts.log_level = log_level | 8; /* BPF_LOG_FIXED */ |
191 | opts.log_size = 0; |
192 | opts.log_true_size = 0; |
193 | res = load_prog(&opts, expect_load_error); |
194 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_fixed_null" ); |
195 | ASSERT_EQ(opts.log_true_size, log_true_sz_fixed, "log_sz_fixed_null_eq" ); |
196 | |
197 | /* (ROLLING) get actual log size */ |
198 | opts.log_buf = logs.buf; |
199 | opts.log_level = log_level; |
200 | opts.log_size = sizeof(logs.buf); |
201 | opts.log_true_size = 0; |
202 | res = load_prog(&opts, expect_load_error); |
203 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_rolling" ); |
204 | |
205 | log_true_sz_rolling = opts.log_true_size; |
206 | ASSERT_EQ(log_true_sz_rolling, log_true_sz_fixed, "log_true_sz_eq" ); |
207 | |
208 | /* (ROLLING, NULL) get actual log size */ |
209 | opts.log_buf = NULL; |
210 | opts.log_level = log_level; |
211 | opts.log_size = 0; |
212 | opts.log_true_size = 0; |
213 | res = load_prog(&opts, expect_load_error); |
214 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_rolling_null" ); |
215 | ASSERT_EQ(opts.log_true_size, log_true_sz_rolling, "log_true_sz_null_eq" ); |
216 | |
217 | /* (FIXED) expect -ENOSPC for one byte short log */ |
218 | opts.log_buf = logs.buf; |
219 | opts.log_level = log_level | 8; /* BPF_LOG_FIXED */ |
220 | opts.log_size = log_true_sz_fixed - 1; |
221 | opts.log_true_size = 0; |
222 | res = load_prog(&opts, true /* should fail */); |
223 | ASSERT_EQ(res, -ENOSPC, "prog_load_res_too_short_fixed" ); |
224 | |
225 | /* (FIXED) expect *not* -ENOSPC with exact log_true_size buffer */ |
226 | opts.log_buf = logs.buf; |
227 | opts.log_level = log_level | 8; /* BPF_LOG_FIXED */ |
228 | opts.log_size = log_true_sz_fixed; |
229 | opts.log_true_size = 0; |
230 | res = load_prog(&opts, expect_load_error); |
231 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_just_right_fixed" ); |
232 | |
233 | /* (ROLLING) expect -ENOSPC for one byte short log */ |
234 | opts.log_buf = logs.buf; |
235 | opts.log_level = log_level; |
236 | opts.log_size = log_true_sz_rolling - 1; |
237 | res = load_prog(&opts, true /* should fail */); |
238 | ASSERT_EQ(res, -ENOSPC, "prog_load_res_too_short_rolling" ); |
239 | |
240 | /* (ROLLING) expect *not* -ENOSPC with exact log_true_size buffer */ |
241 | opts.log_buf = logs.buf; |
242 | opts.log_level = log_level; |
243 | opts.log_size = log_true_sz_rolling; |
244 | opts.log_true_size = 0; |
245 | res = load_prog(&opts, expect_load_error); |
246 | ASSERT_NEQ(res, -ENOSPC, "prog_load_res_just_right_rolling" ); |
247 | |
248 | cleanup: |
249 | test_log_buf__destroy(skel); |
250 | } |
251 | |
252 | static const void *btf_data; |
253 | static u32 btf_data_sz; |
254 | |
255 | static int load_btf(struct bpf_btf_load_opts *opts, bool expect_err) |
256 | { |
257 | int fd; |
258 | |
259 | fd = bpf_btf_load(btf_data, btf_data_sz, opts); |
260 | if (fd >= 0) |
261 | close(fd); |
262 | if (expect_err) |
263 | ASSERT_LT(fd, 0, "btf_load_failure" ); |
264 | else /* !expect_err */ |
265 | ASSERT_GT(fd, 0, "btf_load_success" ); |
266 | return fd; |
267 | } |
268 | |
269 | static void verif_btf_log_subtest(bool bad_btf) |
270 | { |
271 | LIBBPF_OPTS(bpf_btf_load_opts, opts); |
272 | struct btf *btf; |
273 | struct btf_type *t; |
274 | char *exp_log, op_name[32]; |
275 | size_t fixed_log_sz; |
276 | __u32 log_true_sz_fixed, log_true_sz_rolling; |
277 | int i, res; |
278 | |
279 | /* prepare simple BTF contents */ |
280 | btf = btf__new_empty(); |
281 | if (!ASSERT_OK_PTR(btf, "btf_new_empty" )) |
282 | return; |
283 | res = btf__add_int(btf, "whatever" , 4, 0); |
284 | if (!ASSERT_GT(res, 0, "btf_add_int_id" )) |
285 | goto cleanup; |
286 | if (bad_btf) { |
287 | /* btf__add_int() doesn't allow bad value of size, so we'll just |
288 | * force-cast btf_type pointer and manually override size to invalid |
289 | * 3 if we need to simulate failure |
290 | */ |
291 | t = (void *)btf__type_by_id(btf, res); |
292 | if (!ASSERT_OK_PTR(t, "int_btf_type" )) |
293 | goto cleanup; |
294 | t->size = 3; |
295 | } |
296 | |
297 | btf_data = btf__raw_data(btf, &btf_data_sz); |
298 | if (!ASSERT_OK_PTR(btf_data, "btf_data" )) |
299 | goto cleanup; |
300 | |
301 | load_btf(&opts, bad_btf); |
302 | |
303 | opts.log_buf = logs.reference; |
304 | opts.log_size = sizeof(logs.reference); |
305 | opts.log_level = 1 | 8 /* BPF_LOG_FIXED */; |
306 | load_btf(&opts, bad_btf); |
307 | |
308 | fixed_log_sz = strlen(logs.reference) + 1; |
309 | if (!ASSERT_GT(fixed_log_sz, 50, "fixed_log_sz" )) |
310 | goto cleanup; |
311 | memset(logs.reference + fixed_log_sz, 0, sizeof(logs.reference) - fixed_log_sz); |
312 | |
313 | /* validate BPF_LOG_FIXED truncation works as verifier log used to work */ |
314 | opts.log_buf = logs.buf; |
315 | opts.log_level = 1 | 8; /* fixed-length log */ |
316 | opts.log_size = 25; |
317 | res = load_btf(&opts, true); |
318 | ASSERT_EQ(res, -ENOSPC, "half_log_fd" ); |
319 | ASSERT_EQ(strlen(logs.buf), 24, "log_fixed_25" ); |
320 | ASSERT_STRNEQ(logs.buf, logs.reference, 24, op_name); |
321 | |
322 | /* validate rolling verifier log logic: try all variations of log buf |
323 | * length to force various truncation scenarios |
324 | */ |
325 | opts.log_buf = logs.buf; |
326 | opts.log_level = 1; /* rolling log */ |
327 | |
328 | /* prefill logs.buf with 'A's to detect any write beyond allowed length */ |
329 | memset(logs.filler, 'A', sizeof(logs.filler)); |
330 | logs.filler[sizeof(logs.filler) - 1] = '\0'; |
331 | memset(logs.buf, 'A', sizeof(logs.buf)); |
332 | logs.buf[sizeof(logs.buf) - 1] = '\0'; |
333 | |
334 | for (i = 1; i < fixed_log_sz; i++) { |
335 | opts.log_size = i; |
336 | |
337 | snprintf(op_name, sizeof(op_name), "log_roll_btf_load_%d" , i); |
338 | res = load_btf(&opts, true); |
339 | if (!ASSERT_EQ(res, -ENOSPC, op_name)) |
340 | goto cleanup; |
341 | |
342 | exp_log = logs.reference + fixed_log_sz - i; |
343 | snprintf(op_name, sizeof(op_name), "log_roll_contents_%d" , i); |
344 | if (!ASSERT_STREQ(logs.buf, exp_log, op_name)) { |
345 | printf("CMP:%d\nS1:'%s'\nS2:'%s'\n" , |
346 | strcmp(logs.buf, exp_log), |
347 | logs.buf, exp_log); |
348 | goto cleanup; |
349 | } |
350 | |
351 | /* check that unused portions of logs.buf are not overwritten */ |
352 | snprintf(op_name, sizeof(op_name), "log_roll_unused_tail_%d" , i); |
353 | if (!ASSERT_STREQ(logs.buf + i, logs.filler + i, op_name)) { |
354 | printf("CMP:%d\nS1:'%s'\nS2:'%s'\n" , |
355 | strcmp(logs.buf + i, logs.filler + i), |
356 | logs.buf + i, logs.filler + i); |
357 | goto cleanup; |
358 | } |
359 | } |
360 | |
361 | /* (FIXED) get actual log size */ |
362 | opts.log_buf = logs.buf; |
363 | opts.log_level = 1 | 8; /* BPF_LOG_FIXED */ |
364 | opts.log_size = sizeof(logs.buf); |
365 | opts.log_true_size = 0; |
366 | res = load_btf(&opts, bad_btf); |
367 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_fixed" ); |
368 | |
369 | log_true_sz_fixed = opts.log_true_size; |
370 | ASSERT_GT(log_true_sz_fixed, 0, "log_true_sz_fixed" ); |
371 | |
372 | /* (FIXED, NULL) get actual log size */ |
373 | opts.log_buf = NULL; |
374 | opts.log_level = 1 | 8; /* BPF_LOG_FIXED */ |
375 | opts.log_size = 0; |
376 | opts.log_true_size = 0; |
377 | res = load_btf(&opts, bad_btf); |
378 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_fixed_null" ); |
379 | ASSERT_EQ(opts.log_true_size, log_true_sz_fixed, "log_sz_fixed_null_eq" ); |
380 | |
381 | /* (ROLLING) get actual log size */ |
382 | opts.log_buf = logs.buf; |
383 | opts.log_level = 1; |
384 | opts.log_size = sizeof(logs.buf); |
385 | opts.log_true_size = 0; |
386 | res = load_btf(&opts, bad_btf); |
387 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_rolling" ); |
388 | |
389 | log_true_sz_rolling = opts.log_true_size; |
390 | ASSERT_EQ(log_true_sz_rolling, log_true_sz_fixed, "log_true_sz_eq" ); |
391 | |
392 | /* (ROLLING, NULL) get actual log size */ |
393 | opts.log_buf = NULL; |
394 | opts.log_level = 1; |
395 | opts.log_size = 0; |
396 | opts.log_true_size = 0; |
397 | res = load_btf(&opts, bad_btf); |
398 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_rolling_null" ); |
399 | ASSERT_EQ(opts.log_true_size, log_true_sz_rolling, "log_true_sz_null_eq" ); |
400 | |
401 | /* (FIXED) expect -ENOSPC for one byte short log */ |
402 | opts.log_buf = logs.buf; |
403 | opts.log_level = 1 | 8; /* BPF_LOG_FIXED */ |
404 | opts.log_size = log_true_sz_fixed - 1; |
405 | opts.log_true_size = 0; |
406 | res = load_btf(&opts, true); |
407 | ASSERT_EQ(res, -ENOSPC, "btf_load_res_too_short_fixed" ); |
408 | |
409 | /* (FIXED) expect *not* -ENOSPC with exact log_true_size buffer */ |
410 | opts.log_buf = logs.buf; |
411 | opts.log_level = 1 | 8; /* BPF_LOG_FIXED */ |
412 | opts.log_size = log_true_sz_fixed; |
413 | opts.log_true_size = 0; |
414 | res = load_btf(&opts, bad_btf); |
415 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_just_right_fixed" ); |
416 | |
417 | /* (ROLLING) expect -ENOSPC for one byte short log */ |
418 | opts.log_buf = logs.buf; |
419 | opts.log_level = 1; |
420 | opts.log_size = log_true_sz_rolling - 1; |
421 | res = load_btf(&opts, true); |
422 | ASSERT_EQ(res, -ENOSPC, "btf_load_res_too_short_rolling" ); |
423 | |
424 | /* (ROLLING) expect *not* -ENOSPC with exact log_true_size buffer */ |
425 | opts.log_buf = logs.buf; |
426 | opts.log_level = 1; |
427 | opts.log_size = log_true_sz_rolling; |
428 | opts.log_true_size = 0; |
429 | res = load_btf(&opts, bad_btf); |
430 | ASSERT_NEQ(res, -ENOSPC, "btf_load_res_just_right_rolling" ); |
431 | |
432 | cleanup: |
433 | btf__free(btf); |
434 | } |
435 | |
436 | void test_verifier_log(void) |
437 | { |
438 | if (test__start_subtest("good_prog-level1" )) |
439 | verif_log_subtest("good_prog" , false, 1); |
440 | if (test__start_subtest("good_prog-level2" )) |
441 | verif_log_subtest("good_prog" , false, 2); |
442 | if (test__start_subtest("bad_prog-level1" )) |
443 | verif_log_subtest("bad_prog" , true, 1); |
444 | if (test__start_subtest("bad_prog-level2" )) |
445 | verif_log_subtest("bad_prog" , true, 2); |
446 | if (test__start_subtest("bad_btf" )) |
447 | verif_btf_log_subtest(true /* bad btf */); |
448 | if (test__start_subtest("good_btf" )) |
449 | verif_btf_log_subtest(false /* !bad btf */); |
450 | } |
451 | |