From 9fe3826be139e8e40f9694c653bfb430a99900a0 Mon Sep 17 00:00:00 2001 From: Martin Stjernholm Date: Tue, 27 Aug 2019 17:08:45 +0100 Subject: [PATCH] Add more linker debug log. Main change is to log errors directly where they occur, to correlate with other dlopen/dlsym logs. Test: Build & boot with and without LinkerLogger::flags_ initialised to kLogDlopen Change-Id: If36f52914dc97cedd95dc9375c291640c6891728 --- linker/linker.cpp | 50 +++++++++++++++++++++++------------------ linker/linker_globals.h | 16 +++++++++++-- 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;