Skip to content

fix(libpman): only append errno to error logs - #3070

Open
aroberts87 wants to merge 1 commit into
falcosecurity:masterfrom
aroberts87:fix/libpman-stale-errno-log
Open

fix(libpman): only append errno to error logs#3070
aroberts87 wants to merge 1 commit into
falcosecurity:masterfrom
aroberts87:fix/libpman-stale-errno-log

Conversation

@aroberts87

Copy link
Copy Markdown
Contributor

What type of PR is this?

/kind bug

Any specific area of the project related to this PR?

/area libpman

/area libscap-engine-modern-bpf

/area tests

What this PR does / why we need it:

libpman's log_msg_v() appends the current errno to every log message it formats, regardless of severity. But several libpman code paths run libbpf feature probes right before logging a non-error line:

  • libbpf_probe_bpf_helper() in pman_prepare_progs_before_loading()
  • libbpf_find_vmlinux_btf_id() in is_kernel_symbol_available()

These probes signal their result through the return value and leave a stale errno behind (e.g. EACCES when the verifier rejects the probe program, ENOENT for a missing kernel symbol). The subsequent FALCOSECURITY_LOG_SEV_DEBUG "satisfied required feature" success line then wrongly rendered as:

BPF program 'foo' satisfied required feature [1] (errno: 13 | message: Permission denied)

which is confusing: nothing failed, the feature is supported.

This PR fixes the leak at its root instead of clearing errno at each probe call site:

  • log_msg_v() now appends the errno detail only for FALCOSECURITY_LOG_SEV_ERROR, where errno is meaningful. Lower severities (debug/info/warning) report their result via return values, not errno.
  • The errno = ENXIO in pman_prepare_progs_before_loading() is now set before its log_errorf(), so the error line carries the right code.

Special notes for your reviewer:

Adds a libpman_log unit suite (test/libscap/test_suites/engines/modern_bpf/libpman_log.cpp) that exercises the gate directly, without root or a loaded BPF probe: it installs a capturing log callback via pman_init_state() and asserts that a stale errno is not appended to debug/info/warning lines, that error lines still carry it, and that no bogus errno is appended when errno is 0. Reverting the gate turns the debug/info/warning assertions red while the error-log assertions stay green.

The bug only reproduces on a kernel where a feature probe actually fails (leaving EACCES/ENOENT in errno); on a fully-supported kernel every probe passes clean, so the unit suite — which injects errno deterministically — is the reliable regression guard.

Does this PR introduce a user-facing change?:

fix(libpman): stop appending a stale errno to non-error log messages emitted after libbpf feature probing

libbpf_probe_bpf_helper() and libbpf_find_vmlinux_btf_id() signal
their result via the return value but leave errno set (e.g. EACCES
from the verifier rejecting the probe program). log_msg_v() appended
any non-zero errno to every message, so debug success lines wrongly
showed "(errno: 13 | message: Permission denied)".

Gate the errno append on FALCOSECURITY_LOG_SEV_ERROR, where errno is
meaningful, instead of clearing errno at each probe call site. Also
set errno=ENXIO before its log_errorf so the error line carries the
right code.

Add a libpman_log unit suite covering the gate: stale errno is not
appended to debug/info/warning lines, error lines still carry it,
and no bogus errno is appended when errno is 0.

Signed-off-by: Adam Roberts <adam.roberts@sysdig.com>
@poiana

poiana commented Jul 28, 2026

Copy link
Copy Markdown
Contributor

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: aroberts87
Once this PR has been reviewed and has the lgtm label, please assign therealbobo for approval. For more information see the Kubernetes Code Review Process.

The full list of commands accepted by this bot can be found here.

Details Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@github-actions

Copy link
Copy Markdown

Perf diff from master - unit tests

     8.40%    +15.57%  [.] sinsp_thread_manager::create_thread_dependencies(std::shared_ptr<sinsp_threadinfo> const&)
    24.33%    -13.33%  [.] sinsp_threadinfo::get_main_thread()
    18.43%     -8.82%  [.] std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_add_ref_lock_nothrow()
    11.51%     +7.89%  [.] std::__shared_ptr<sinsp_threadinfo, (__gnu_cxx::_Lock_policy)2>::__shared_ptr(std::__weak_ptr<sinsp_threadinfo, (__gnu_cxx::_Lock_policy)2> const&, std::nothrow_t)
    13.46%     -7.34%  [.] std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count(std::__weak_count<(__gnu_cxx::_Lock_policy)2> const&, std::nothrow_t)
     3.12%     +5.88%  [.] std::__shared_count<(__gnu_cxx::_Lock_policy)2>::_M_get_use_count() const
     4.79%     -0.51%  [.] thread_group_info::get_first_thread() const
     9.29%     -0.48%  [.] std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release()
     0.04%     +0.08%  [.] sinsp_split[abi:cxx11](std::basic_string_view<char, std::char_traits<char> >, char)
     0.08%     +0.08%  [.] std::basic_string_view<char, std::char_traits<char> >::compare(std::basic_string_view<char, std::char_traits<char> >) const

Heap diff from master - unit tests

peak heap memory consumption: -395.11K
peak RSS (including heaptrack overhead): 0B
total memory leaked: 0B

Heap diff from master - scap file

peak heap memory consumption: -33.10K
peak RSS (including heaptrack overhead): 0B
total memory leaked: 0B

Benchmarks diff from master

Comparing gbench_data.json to /root/actions-runner/_work/libs/libs/build/gbench_data.json
Benchmark                                                                             Time             CPU      Time Old      Time New       CPU Old       CPU New
------------------------------------------------------------------------------------------------------------------------------------------------------------------
BM_sinsp_split_mean                                                                -0.0285         -0.0285           282           274           282           274
BM_sinsp_split_median                                                              -0.0317         -0.0317           282           273           282           273
BM_sinsp_split_stddev                                                              +0.9739         +0.9557             1             3             1             3
BM_sinsp_split_cv                                                                  +1.0318         +1.0132             0             0             0             0
BM_sinsp_concatenate_paths_relative_path_mean                                      +0.0752         +0.0752            63            68            63            68
BM_sinsp_concatenate_paths_relative_path_median                                    +0.0859         +0.0859            63            68            63            68
BM_sinsp_concatenate_paths_relative_path_stddev                                    +5.2792         +5.2732             0             2             0             2
BM_sinsp_concatenate_paths_relative_path_cv                                        +4.8398         +4.8347             0             0             0             0
BM_sinsp_concatenate_paths_empty_path_mean                                         +0.0795         +0.0794            48            52            48            52
BM_sinsp_concatenate_paths_empty_path_median                                       +0.0804         +0.0804            48            52            48            52
BM_sinsp_concatenate_paths_empty_path_stddev                                       +1.1668         +1.1949             0             0             0             0
BM_sinsp_concatenate_paths_empty_path_cv                                           +1.0072         +1.0334             0             0             0             0
BM_sinsp_concatenate_paths_absolute_path_mean                                      +0.1099         +0.1098            60            66            60            66
BM_sinsp_concatenate_paths_absolute_path_median                                    +0.1108         +0.1105            60            66            60            66
BM_sinsp_concatenate_paths_absolute_path_stddev                                    +2.0199         +2.0540             0             0             0             0
BM_sinsp_concatenate_paths_absolute_path_cv                                        +1.7208         +1.7517             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_ascii_short_mean                                  -0.0027         -0.0027            15            15            15            15
BM_sinsp_utf8_sanitize_fast_path_ascii_short_median                                -0.0051         -0.0053            15            15            15            15
BM_sinsp_utf8_sanitize_fast_path_ascii_short_stddev                                -0.0762         -0.0685             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_ascii_short_cv                                    -0.0737         -0.0660             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_ascii_long_mean                                   +0.0001         +0.0001            87            87            87            87
BM_sinsp_utf8_sanitize_fast_path_ascii_long_median                                 +0.0002         +0.0001            87            87            87            87
BM_sinsp_utf8_sanitize_fast_path_ascii_long_stddev                                 -0.1649         -0.1534             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_ascii_long_cv                                     -0.1649         -0.1534             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_multibyte_short_mean                              -0.0231         -0.0231            13            12            13            12
BM_sinsp_utf8_sanitize_fast_path_multibyte_short_median                            -0.0004         -0.0003            12            12            12            12
BM_sinsp_utf8_sanitize_fast_path_multibyte_short_stddev                            -0.9912         -0.9918             1             0             1             0
BM_sinsp_utf8_sanitize_fast_path_multibyte_short_cv                                -0.9910         -0.9916             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_multibyte_long_mean                               +0.0804         +0.0803          3803          4109          3802          4107
BM_sinsp_utf8_sanitize_fast_path_multibyte_long_median                             +0.0804         +0.0804          3803          4109          3801          4107
BM_sinsp_utf8_sanitize_fast_path_multibyte_long_stddev                             +0.3405         +0.0282             1             2             1             1
BM_sinsp_utf8_sanitize_fast_path_multibyte_long_cv                                 +0.2408         -0.0483             0             0             0             0
BM_sinsp_utf8_sanitize_fast_path_mixed_long_mean                                   +0.0287         +0.0286          1752          1802          1751          1801
BM_sinsp_utf8_sanitize_fast_path_mixed_long_median                                 +0.0022         +0.0023          1753          1757          1752          1756
BM_sinsp_utf8_sanitize_fast_path_mixed_long_stddev                                 +7.2555         +7.2430            12            99            12            99
BM_sinsp_utf8_sanitize_fast_path_mixed_long_cv                                     +7.0251         +7.0141             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_alloc_mean                       +0.2489         +0.2489          1122          1402          1122          1401
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_alloc_median                     +0.2473         +0.2475          1123          1401          1122          1400
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_alloc_stddev                     +0.6175         +0.5665             3             5             3             5
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_alloc_cv                         +0.2951         +0.2544             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_noalloc_mean                     +0.2581         +0.2582          1118          1407          1118          1406
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_noalloc_median                   +0.2584         +0.2584          1117          1406          1117          1406
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_noalloc_stddev                   +0.0546         +0.0283             5             6             5             6
BM_sinsp_utf8_sanitize_slow_path_c1_controls_long_noalloc_cv                       -0.1618         -0.1827             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_alloc_mean                    -0.0042         -0.0042           234           233           233           232
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_alloc_median                  -0.0058         -0.0057           232           231           232           231
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_alloc_stddev                  +0.0096         +0.0111             5             5             5             5
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_alloc_cv                      +0.0139         +0.0153             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_noalloc_mean                  +0.0054         +0.0054           143           144           143           144
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_noalloc_median                +0.0057         +0.0058           143           144           143           144
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_noalloc_stddev                -0.4931         -0.4977             1             0             1             0
BM_sinsp_utf8_sanitize_slow_path_sparse_invalid_long_noalloc_cv                    -0.4958         -0.5004             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_alloc_mean                       +0.0048         +0.0049         11746         11803         11741         11799
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_alloc_median                     +0.0020         +0.0022         11733         11756         11726         11752
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_alloc_stddev                     +0.2189         +0.2132            80            98            80            97
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_alloc_cv                         +0.2130         +0.2072             0             0             0             0
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_noalloc_mean                     +0.0105         +0.0106         11573         11695         11569         11692
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_noalloc_median                   +0.0094         +0.0093         11625         11734         11622         11730
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_noalloc_stddev                   -0.0616         -0.0634            89            84            89            84
BM_sinsp_utf8_sanitize_slow_path_all_invalid_long_noalloc_cv                       -0.0714         -0.0732             0             0             0             0

@codecov

codecov Bot commented Jul 29, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 76.27%. Comparing base (6f682e8) to head (690eebe).
⚠️ Report is 25 commits behind head on master.

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #3070      +/-   ##
==========================================
+ Coverage   75.94%   76.27%   +0.32%     
==========================================
  Files         300      300              
  Lines       33276    33397     +121     
  Branches     5057     5032      -25     
==========================================
+ Hits        25271    25473     +202     
+ Misses       8005     7924      -81     
Flag Coverage Δ
libsinsp 76.27% <ø> (+0.32%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

@terror96

terror96 commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

Hi @aroberts87, I think your PR is a step towards the right direction and I agree this should be fixed. I was checking the cases where log_msgf is called with other severity levels, and in some cases it would make sense to report the return value especially if the operation fails. Is seems also that e.g. fdinfo_from_task_file_memfd_evt() might still output a stale error message, because it calls log_errorf but just looking at it quickly, I can't see where errno would be set to a meaningful value.

@gnosek

gnosek commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

That certainly is an approach :D

Personally, I'd prefer passing errno explicitly where we want it, and zero where we don't (regardless of log level), but I see that would require more extensive surgery (changing the signature of the pman log callback). Still, I'm not going to block it so I'm happy to ✔️ if you want to leave it as is.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

Status: Todo

Development

Successfully merging this pull request may close these issues.

4 participants