Merge "Add more linker debug log."

2 files changed, 42 insertions, 24 deletions

diff --git a/linker/linker.cpp b/linker/linker.cpp
index 0bc312129..9aa648016 100644
--- a/linker/linker.cpp
+++ b/linker/linker.cpp
@@ -1325,25 +1325,26 @@ static bool load_library(android_namespace_t* ns,
   const char* name = task->get_name();
   const android_dlextinfo* extinfo = task->get_extinfo();
 
-  LD_LOG(kLogDlopen, "load_library(ns=%s, task=%s, flags=0x%x, realpath=%s)", ns->get_name(), name,
-         rtld_flags, realpath.c_str());
+  LD_LOG(kLogDlopen,
+         "load_library(ns=%s, task=%s, flags=0x%x, realpath=%s, search_linked_namespaces=%d)",
+         ns->get_name(), name, rtld_flags, realpath.c_str(), search_linked_namespaces);
 
   if ((file_offset % PAGE_SIZE) != 0) {
-    DL_ERR("file offset for the library \"%s\" is not page-aligned: %" PRId64, name, file_offset);
+    DL_OPEN_ERR("file offset for the library \"%s\" is not page-aligned: %" PRId64, name, file_offset);
     return false;
   }
   if (file_offset < 0) {
-    DL_ERR("file offset for the library \"%s\" is negative: %" PRId64, name, file_offset);
+    DL_OPEN_ERR("file offset for the library \"%s\" is negative: %" PRId64, name, file_offset);
     return false;
   }
 
   struct stat file_stat;
   if (TEMP_FAILURE_RETRY(fstat(task->get_fd(), &file_stat)) != 0) {
-    DL_ERR("unable to stat file for the library \"%s\": %s", name, strerror(errno));
+    DL_OPEN_ERR("unable to stat file for the library \"%s\": %s", name, strerror(errno));
     return false;
   }
   if (file_offset >= file_stat.st_size) {
-    DL_ERR("file offset for the library \"%s\" >= file size: %" PRId64 " >= %" PRId64,
+    DL_OPEN_ERR("file offset for the library \"%s\" >= file size: %" PRId64 " >= %" PRId64,
         name, file_offset, file_stat.st_size);
     return false;
   }
@@ -1363,13 +1364,13 @@ static bool load_library(android_namespace_t* ns,
   }
 
   if ((rtld_flags & RTLD_NOLOAD) != 0) {
-    DL_ERR("library \"%s\" wasn't loaded and RTLD_NOLOAD prevented it", name);
+    DL_OPEN_ERR("library \"%s\" wasn't loaded and RTLD_NOLOAD prevented it", name);
     return false;
   }
 
   struct statfs fs_stat;
   if (TEMP_FAILURE_RETRY(fstatfs(task->get_fd(), &fs_stat)) != 0) {
-    DL_ERR("unable to fstatfs file for the library \"%s\": %s", name, strerror(errno));
+    DL_OPEN_ERR("unable to fstatfs file for the library \"%s\": %s", name, strerror(errno));
     return false;
   }
 
@@ -1400,7 +1401,7 @@ static bool load_library(android_namespace_t* ns,
                                           "(unknown)" :
                                           task->get_needed_by()->get_realpath();
 
-      DL_ERR("library \"%s\" needed or dlopened by \"%s\" is not accessible for the namespace \"%s\"",
+      DL_OPEN_ERR("library \"%s\" needed or dlopened by \"%s\" is not accessible for the namespace \"%s\"",
              name, needed_or_dlopened_by, ns->get_name());
 
       // do not print this if a library is in the list of shared libraries for linked namespaces
@@ -1498,10 +1499,15 @@ static bool load_library(android_namespace_t* ns,
     return load_library(ns, task, load_tasks, rtld_flags, realpath, search_linked_namespaces);
   }
 
+  LD_LOG(kLogDlopen,
+         "load_library(ns=%s, task=%s, flags=0x%x, search_linked_namespaces=%d): calling "
+         "open_library with realpath=%s",
+         ns->get_name(), name, rtld_flags, search_linked_namespaces, realpath.c_str());
+
   // Open the file.
   int fd = open_library(ns, zip_archive_cache, name, needed_by, &file_offset, &realpath);
   if (fd == -1) {
-    DL_ERR("library \"%s\" not found", name);
+    DL_OPEN_ERR("library \"%s\" not found", name);
     return false;
   }
 
@@ -2267,26 +2273,26 @@ void* do_dlopen(const char* name, int flags,
       [&]() { LD_LOG(kLogDlopen, "... dlopen failed: %s", linker_get_error_buffer()); });
 
   if ((flags & ~(RTLD_NOW|RTLD_LAZY|RTLD_LOCAL|RTLD_GLOBAL|RTLD_NODELETE|RTLD_NOLOAD)) != 0) {
-    DL_ERR("invalid flags to dlopen: %x", flags);
+    DL_OPEN_ERR("invalid flags to dlopen: %x", flags);
     return nullptr;
   }
 
   if (extinfo != nullptr) {
     if ((extinfo->flags & ~(ANDROID_DLEXT_VALID_FLAG_BITS)) != 0) {
-      DL_ERR("invalid extended flags to android_dlopen_ext: 0x%" PRIx64, extinfo->flags);
+      DL_OPEN_ERR("invalid extended flags to android_dlopen_ext: 0x%" PRIx64, extinfo->flags);
       return nullptr;
     }
 
     if ((extinfo->flags & ANDROID_DLEXT_USE_LIBRARY_FD) == 0 &&
         (extinfo->flags & ANDROID_DLEXT_USE_LIBRARY_FD_OFFSET) != 0) {
-      DL_ERR("invalid extended flag combination (ANDROID_DLEXT_USE_LIBRARY_FD_OFFSET without "
+      DL_OPEN_ERR("invalid extended flag combination (ANDROID_DLEXT_USE_LIBRARY_FD_OFFSET without "
           "ANDROID_DLEXT_USE_LIBRARY_FD): 0x%" PRIx64, extinfo->flags);
       return nullptr;
     }
 
     if ((extinfo->flags & ANDROID_DLEXT_USE_NAMESPACE) != 0) {
       if (extinfo->library_namespace == nullptr) {
-        DL_ERR("ANDROID_DLEXT_USE_NAMESPACE is set but extinfo->library_namespace is null");
+        DL_OPEN_ERR("ANDROID_DLEXT_USE_NAMESPACE is set but extinfo->library_namespace is null");
         return nullptr;
       }
       ns = extinfo->library_namespace;
@@ -2403,7 +2409,7 @@ bool do_dlsym(void* handle,
   ScopedTrace trace("dlsym");
 #if !defined(__LP64__)
   if (handle == nullptr) {
-    DL_ERR("dlsym failed: library handle is null");
+    DL_SYM_ERR("dlsym failed: library handle is null");
     return false;
   }
 #endif
@@ -2431,7 +2437,7 @@ bool do_dlsym(void* handle,
       [&]() { LD_LOG(kLogDlsym, "... dlsym failed: %s", linker_get_error_buffer()); });
 
   if (sym_name == nullptr) {
-    DL_ERR("dlsym failed: symbol name is null");
+    DL_SYM_ERR("dlsym failed: symbol name is null");
     return false;
   }
 
@@ -2448,7 +2454,7 @@ bool do_dlsym(void* handle,
     sym = dlsym_linear_lookup(ns, sym_name, vi, &found, caller, handle);
   } else {
     if (si == nullptr) {
-      DL_ERR("dlsym failed: invalid handle: %p", handle);
+      DL_SYM_ERR("dlsym failed: invalid handle: %p", handle);
       return false;
     }
     sym = dlsym_handle_lookup(si, &found, sym_name, vi);
@@ -2464,8 +2470,8 @@ bool do_dlsym(void* handle,
         // copy of the symbol.
         const soinfo_tls* tls_module = found->get_tls();
         if (tls_module == nullptr) {
-          DL_ERR("TLS symbol \"%s\" in solib \"%s\" with no TLS segment",
-                 sym_name, found->get_realpath());
+          DL_SYM_ERR("TLS symbol \"%s\" in solib \"%s\" with no TLS segment",
+                     sym_name, found->get_realpath());
           return false;
         }
         void* tls_block = get_tls_block_for_this_thread(tls_module, /*should_alloc=*/true);
@@ -2480,11 +2486,11 @@ bool do_dlsym(void* handle,
       return true;
     }
 
-    DL_ERR("symbol \"%s\" found but not global", symbol_display_name(sym_name, sym_ver).c_str());
+    DL_SYM_ERR("symbol \"%s\" found but not global", symbol_display_name(sym_name, sym_ver).c_str());
     return false;
   }
 
-  DL_ERR("undefined symbol: %s", symbol_display_name(sym_name, sym_ver).c_str());
+  DL_SYM_ERR("undefined symbol: %s", symbol_display_name(sym_name, sym_ver).c_str());
   return false;
 }
 
@@ -2493,7 +2499,7 @@ int do_dlclose(void* handle) {
   ProtectedDataGuard guard;
   soinfo* si = soinfo_from_handle(handle);
   if (si == nullptr) {
-    DL_ERR("invalid handle: %p", handle);
+    DL_OPEN_ERR("invalid handle: %p", handle);
     return -1;
   }
 
diff --git a/linker/linker_globals.h b/linker/linker_globals.h
index de05238a5..83cedcab4 100644
--- a/linker/linker_globals.h
+++ b/linker/linker_globals.h
@@ -53,8 +53,20 @@ void DL_WARN_documented_change(int api_level, const char* doc_link, const char*
 
 #define DL_ERR_AND_LOG(fmt, x...) \
   do { \
-    DL_ERR(fmt, x); \
-    PRINT(fmt, x); \
+    DL_ERR(fmt, ##x); \
+    PRINT(fmt, ##x); \
+  } while (false)
+
+#define DL_OPEN_ERR(fmt, x...) \
+  do { \
+    DL_ERR(fmt, ##x); \
+    LD_LOG(kLogDlopen, fmt, ##x); \
+  } while (false)
+
+#define DL_SYM_ERR(fmt, x...) \
+  do { \
+    DL_ERR(fmt, ##x); \
+    LD_LOG(kLogDlsym, fmt, ##x); \
   } while (false)
 
 constexpr ElfW(Versym) kVersymNotNeeded = 0;