BpfLoader: drastically reduce logging am: 0eb98a22c3

Original change: https://android-review.googlesource.com/c/platform/system/bpf/+/3068096

Change-Id: If00644648090d39aab90baf114b6d6398274dc2a
Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
diff --git a/loader/BpfLoader.cpp b/loader/BpfLoader.cpp
index e6800e6..9f61ba1 100644
--- a/loader/BpfLoader.cpp
+++ b/loader/BpfLoader.cpp
@@ -119,7 +119,7 @@
                 if (critical) retVal = ret;
                 ALOGE("Failed to load object: %s, ret: %s", progPath.c_str(), std::strerror(-ret));
             } else {
-                ALOGI("Loaded object: %s", progPath.c_str());
+                ALOGV("Loaded object: %s", progPath.c_str());
             }
         }
         closedir(dir);
diff --git a/loader/Loader.cpp b/loader/Loader.cpp
index 746aca8..dd242e2 100644
--- a/loader/Loader.cpp
+++ b/loader/Loader.cpp
@@ -223,7 +223,7 @@
     vector<char> theBytes;
     int ret = readSectionByName(name, elfFile, theBytes);
     if (ret) {
-        ALOGD("Couldn't find section %s (defaulting to %u [0x%x]).", name, defVal, defVal);
+        ALOGV("Couldn't find section %s (defaulting to %u [0x%x]).", name, defVal, defVal);
         return defVal;
     } else if (theBytes.size() < sizeof(unsigned int)) {
         ALOGE("Section %s too short (defaulting to %u [0x%x]).", name, defVal, defVal);
@@ -237,7 +237,7 @@
         value += static_cast<unsigned char>(theBytes[1]);
         value <<= 8;
         value += static_cast<unsigned char>(theBytes[0]);
-        ALOGI("Section %s value is %u [0x%x]", name, value, value);
+        ALOGV("Section %s value is %u [0x%x]", name, value, value);
         return value;
     }
 }
@@ -438,7 +438,7 @@
 
         ret = readSectionByIdx(elfFile, i, cs_temp.data);
         if (ret) return ret;
-        ALOGD("Loaded code section %d (%s)", i, name.c_str());
+        ALOGV("Loaded code section %d (%s)", i, name.c_str());
 
         vector<string> csSymNames;
         ret = getSectionSymNames(elfFile, oldName, csSymNames, STT_FUNC);
@@ -458,13 +458,13 @@
             if (name == (".rel" + oldName)) {
                 ret = readSectionByIdx(elfFile, i + 1, cs_temp.rel_data);
                 if (ret) return ret;
-                ALOGD("Loaded relo section %d (%s)", i, name.c_str());
+                ALOGV("Loaded relo section %d (%s)", i, name.c_str());
             }
         }
 
         if (cs_temp.data.size() > 0) {
             cs.push_back(std::move(cs_temp));
-            ALOGD("Adding section %d to cs list", i);
+            ALOGV("Adding section %d to cs list", i);
         }
     }
     return 0;
@@ -559,14 +559,14 @@
         if (md[i].zero != 0) abort();
 
         if (kvers < md[i].min_kver) {
-            ALOGI("skipping map %s which requires kernel version 0x%x >= 0x%x",
+            ALOGD("skipping map %s which requires kernel version 0x%x >= 0x%x",
                   mapNames[i].c_str(), kvers, md[i].min_kver);
             mapFds.push_back(unique_fd());
             continue;
         }
 
         if (kvers >= md[i].max_kver) {
-            ALOGI("skipping map %s which requires kernel version 0x%x < 0x%x",
+            ALOGD("skipping map %s which requires kernel version 0x%x < 0x%x",
                   mapNames[i].c_str(), kvers, md[i].max_kver);
             mapFds.push_back(unique_fd());
             continue;
@@ -604,7 +604,7 @@
         if (access(mapPinLoc.c_str(), F_OK) == 0) {
             fd.reset(mapRetrieveRO(mapPinLoc.c_str()));
             saved_errno = errno;
-            ALOGD("bpf_create_map reusing map %s, ret: %d", mapNames[i].c_str(), fd.get());
+            ALOGV("bpf_create_map reusing map %s, ret: %d", mapNames[i].c_str(), fd.get());
             reuse = true;
         } else {
             union bpf_attr req = {
@@ -617,7 +617,7 @@
             strlcpy(req.map_name, mapNames[i].c_str(), sizeof(req.map_name));
             fd.reset(bpf(BPF_MAP_CREATE, req));
             saved_errno = errno;
-            ALOGD("bpf_create_map name %s, ret: %d", mapNames[i].c_str(), fd.get());
+            ALOGV("bpf_create_map name %s, ret: %d", mapNames[i].c_str(), fd.get());
         }
 
         if (!fd.ok()) return -saved_errno;
@@ -654,7 +654,7 @@
         if (mapId == -1) {
             ALOGE("bpfGetFdMapId failed, ret: %d [%d]", mapId, errno);
         } else {
-            ALOGI("map %s id %d", mapPinLoc.c_str(), mapId);
+            ALOGD("map %s id %d", mapPinLoc.c_str(), mapId);
         }
 
         mapFds.push_back(std::move(fd));
@@ -674,7 +674,7 @@
 
     // Occasionally might be useful for relocation debugging, but pretty spammy
     if (0) {
-        ALOGD("applying relo to instruction at byte offset: %llu, "
+        ALOGV("applying relo to instruction at byte offset: %llu, "
               "insn offset %d, insn %llx",
               (unsigned long long)offset, insnIndex, *(unsigned long long*)insn);
     }
@@ -739,10 +739,11 @@
 
         unsigned min_kver = cs[i].prog_def->min_kver;
         unsigned max_kver = cs[i].prog_def->max_kver;
-        ALOGD("cs[%d].name:%s min_kver:%x .max_kver:%x (kvers:%x)", i, name.c_str(), min_kver,
-             max_kver, kvers);
-        if (kvers < min_kver) continue;
-        if (kvers >= max_kver) continue;
+        if (kvers < min_kver || kvers >= max_kver) {
+            ALOGD("skipping program cs[%d].name:%s min_kver:%x max_kver:%x (kvers:%x)",
+                  i, name.c_str(), min_kver, max_kver, kvers);
+            continue;
+        }
 
         // strip any potential $foo suffix
         // this can be used to provide duplicate programs
@@ -756,7 +757,7 @@
                             objName + '_' + string(name);
         if (access(progPinLoc.c_str(), F_OK) == 0) {
             fd.reset(retrieveProgram(progPinLoc.c_str()));
-            ALOGD("New bpf prog load reusing prog %s, ret: %d (%s)", progPinLoc.c_str(), fd.get(),
+            ALOGV("New bpf prog load reusing prog %s, ret: %d (%s)", progPinLoc.c_str(), fd.get(),
                   (!fd.ok() ? std::strerror(errno) : "no error"));
             reuse = true;
         } else {
@@ -776,10 +777,10 @@
             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"));
-
             if (!fd.ok()) {
+                ALOGW("BPF_PROG_LOAD call for %s (%s) returned fd: %d (%s)", elfPath,
+                      cs[i].name.c_str(), fd.get(), std::strerror(errno));
+
                 vector<string> lines = android::base::Split(log_buf.data(), "\n");
 
                 ALOGW("BPF_PROG_LOAD - BEGIN log_buf contents:");
@@ -821,7 +822,7 @@
         if (progId == -1) {
             ALOGE("bpfGetFdProgId failed, ret: %d [%d]", progId, errno);
         } else {
-            ALOGI("prog %s id %d", progPinLoc.c_str(), progId);
+            ALOGD("prog %s id %d", progPinLoc.c_str(), progId);
         }
     }
 
@@ -848,13 +849,11 @@
     if (ret) {
         ALOGE("Couldn't find license in %s", elfPath);
         return ret;
-    } else {
-        ALOGD("Loading %s%s ELF object %s with license %s",
-              *isCritical ? "critical for " : "optional", *isCritical ? (char*)critical.data() : "",
-              elfPath, (char*)license.data());
     }
 
-    ALOGI("Platform BpfLoader processing ELF object %s", elfPath);
+    ALOGI("Platform BpfLoader loading %s%s ELF object %s with license %s",
+          *isCritical ? "critical for " : "optional", *isCritical ? (char*)critical.data() : "",
+          elfPath, (char*)license.data());
 
     ret = readCodeSections(elfFile, cs, location.allowedProgTypes, location.allowedProgTypesLength);
     if (ret) {
@@ -869,7 +868,7 @@
     }
 
     for (int i = 0; i < (int)mapFds.size(); i++)
-        ALOGD("map_fd found at %d is %d in %s", i, mapFds[i].get(), elfPath);
+        ALOGV("map_fd found at %d is %d in %s", i, mapFds[i].get(), elfPath);
 
     applyMapRelo(elfFile, mapFds, cs);