commit ea1d8f637677c216aa2ab41eb351495d332ab304
author Maciej Żenczykowski <maze@google.com> Thu Sep 05 09:38:14 2024 -0700
committer Maciej Żenczykowski <maze@google.com> Thu Sep 05 22:00:33 2024 +0000
tree 0fdc86af6a00d1af83ee53e4fe69279e65687a7a
parent bf1591834ed430d42ca980d369068aa5bcd50fde

NetBpfLoad: fix empty log_buf detection logic

log_buf.size() was always BPF_LOAD_LOG_SZ and thus != 0

After changing ALOGD to ALOGI you now see (for example):
  NetBpfLoad: BPF_PROG_LOAD call for /apex/com.android.tethering/etc/bpf/net_shared/block.o (bind4_block_port) returned 'processed 55 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 1' fd: 6 (ok)

(ALOGV/ALOGD's are effectively silently dropped by the KernelLogger we use)

Test: TreeHugger
Signed-off-by: Maciej Żenczykowski <maze@google.com>
Change-Id: I4a296976ae3f1e2217c46d81ed48850fdfa95a3c

bpf/loader/NetBpfLoad.cpp

diff --git a/bpf/loader/NetBpfLoad.cpp b/bpf/loader/NetBpfLoad.cpp
index 31f40d6..69f1cb5 100644
--- a/bpf/loader/NetBpfLoad.cpp
+++ b/bpf/loader/NetBpfLoad.cpp
@@ -141,9 +141,6 @@
 
 #define BPF_FS_PATH "/sys/fs/bpf/"
 
-// Size of the BPF log buffer for verifier logging
-#define BPF_LOAD_LOG_SZ 0xfffff
-
 static unsigned int page_size = static_cast<unsigned int>(getpagesize());
 
 constexpr const char* lookupSelinuxContext(const domain d) {
@@ -1006,7 +1003,7 @@
                   (!fd.ok() ? std::strerror(errno) : "no error"));
             reuse = true;
         } else {
-            vector<char> log_buf(BPF_LOAD_LOG_SZ, 0);
+            static char log_buf[1 << 20];  // 1 MiB logging buffer
 
             union bpf_attr req = {
               .prog_type = cs[i].type,
@@ -1014,8 +1011,8 @@
               .insns = ptr_to_u64(cs[i].data.data()),
               .license = ptr_to_u64(license.c_str()),
               .log_level = 1,
-              .log_size = static_cast<__u32>(log_buf.size()),
-              .log_buf = ptr_to_u64(log_buf.data()),
+              .log_size = sizeof(log_buf),
+              .log_buf = ptr_to_u64(log_buf),
               .kern_version = kvers,
               .expected_attach_type = cs[i].attach_type,
             };
@@ -1023,12 +1020,23 @@
                 strlcpy(req.prog_name, cs[i].name.c_str(), sizeof(req.prog_name));
             fd.reset(bpf(BPF_PROG_LOAD, req));
 
-            ALOGD("BPF_PROG_LOAD call for %s (%s) returned fd: %d (%s)", elfPath,
-                  cs[i].name.c_str(), fd.get(), (!fd.ok() ? std::strerror(errno) : "no error"));
+            // Kernel should have NULL terminated the log buffer, but force it anyway for safety
+            log_buf[sizeof(log_buf) - 1] = 0;
+
+            // Strip out final newline if present
+            int log_chars = strlen(log_buf);
+            if (log_chars && log_buf[log_chars - 1] == '\n') log_buf[--log_chars] = 0;
+
+            bool log_oneline = !strchr(log_buf, '\n');
+
+            ALOGD("BPF_PROG_LOAD call for %s (%s) returned '%s' fd: %d (%s)", elfPath,
+                  cs[i].name.c_str(), log_oneline ? log_buf : "{multiline}",
+                  fd.get(), (!fd.ok() ? std::strerror(errno) : "ok"));
 
             if (!fd.ok()) {
-                if (log_buf.size()) {
-                    vector<string> lines = Split(log_buf.data(), "\n");
+                // kernel NULL terminates log_buf, so this checks for non-empty string
+                if (log_buf[0]) {
+                    vector<string> lines = Split(log_buf, "\n");
 
                     ALOGW("BPF_PROG_LOAD - BEGIN log_buf contents:");
                     for (const auto& line : lines) ALOGW("%s", line.c_str());