program/loader: properly log verifier errors #504
Merged
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
michi-covalent
approved these changes
Oct 24, 2022
|
nice, one nit - there are some places that still set it to 5 because of the generic name I thought it's used elsewhere for verbose output, |
|
Nice let's just get rid of those instances then @olsajiri. Any objections? |
Recent changes to cilium/ebpf have changed the way verifier logs are handled such that
they are truncated to a single line by default and can be expanded with a `"%+v"`
formatting directive. An unfortunate consequence of this was that our current implementation
would always truncate verifier log dumps to a single line because the fmt.Errorf wrapper was
implicitly using a `"%s"` formatting directive to print the root cause.
To rectify this issue, use the `errors.As()` helper to cast the verifier error down to an
ebpf.VerifierError and use the entire verifier error in the call to `slimVerifierError`.
This enables us to pretty print the first and last 30 lines as before.
While fixing this bug, I realized it would probably be a reasonable idea to support higher
verbosity levels that would dump the entire verifier logs. While this wouldn't be useful
in many cases, one could imagine specific use cases coming up where just the truncated
dump may not be sufficient to debug an issue.
Finally, let's take advantage of the new default verifier log behaviour of cilium/ebpf to
append a one line description of the problem to program load error messages. Example output without
the --verbose flag looks like the following:
time="2022-10-24T17:45:51Z" level=fatal msg="Failed to start tetragon" error="failed prog bpf/objs/bpf_execve_event_v53.o kern_version 332544 LoadKprobeProgram: opening collection 'bpf/objs/bpf_execve_event_v53.o' failed: program event_execve: load program: permission denied: invalid access to map value, value_size=1872 off=327960 size=4: R2 min value is outside of the allowed memory range (520 line(s) omitted)"
Signed-off-by: William Findlay <[email protected]>
willfindlay
force-pushed
the
pr/willfindlay/verifier-log-fixes
branch
from
5df5262 to
6d1d312
Compare
olsajiri
approved these changes
Oct 24, 2022
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Recent changes to cilium/ebpf have changed the way verifier logs are handled such that they are truncated to a single line by default and can be expanded with a
"%+v"formatting directive. An unfortunate consequence of this was that our current implementation would always truncate verifier log dumps to a single line because the fmt.Errorf wrapper was implicitly using a"%s"formatting directive to print the root cause.To rectify this issue, use the
errors.As()helper to cast the verifier error down to an ebpf.VerifierError and use the entire verifier error in the call toslimVerifierError. This enables us to pretty print the first and last 30 lines as before.While fixing this bug, I realized it would probably be a reasonable idea to support higher verbosity levels that would dump the entire verifier logs. While this wouldn't be useful in many cases, one could imagine specific use cases coming up where just the truncated dump may not be sufficient to debug an issue.
Finally, let's take advantage of the new default verifier log behaviour of cilium/ebpf to append a one line description of the problem to program load error messages. Example output without the --verbose flag looks like the following:
Signed-off-by: William Findlay [email protected]