Make LD_DEBUG more user-friendly.
This is more self-explanatory than arbitrary integers, actually does
explain itself if you typo or say LD_DEBUG=help, and makes statistics
and timing available without recompilation.
Some of the groups could probably use a little tweaking, and we could
probably use some more groups, but I think this is already better than
what we have, and the initial change moving LD_DEBUG from integers to
names should probably minimize the amount of change that regard.
There's also the continuing question of whether statistics and timing
should just be deleted. They're not super useful as-is, and we should
think about whether we want to make them more useful or just remove them.
The timing stuff in particular is probably questionable, because
systrace is probably a better way to do anything like that? But that too
sounds like a question for another day.
Bug: http://b/309528372
Test: adb shell LD_DEBUG=<various things> date
Change-Id: I52b96c4892a41f9d24873122aebe5c272f39cdae
diff --git a/linker/linker.cpp b/linker/linker.cpp
index 4365ea5..bcc2500 100644
--- a/linker/linker.cpp
+++ b/linker/linker.cpp
@@ -316,7 +316,7 @@
async_safe_fatal("library name \"%s\" too long", name);
}
- TRACE("name %s: allocating soinfo for ns=%p", name, ns);
+ LD_DEBUG(any, "name %s: allocating soinfo for ns=%p", name, ns);
soinfo* si = new (g_soinfo_allocator.alloc()) soinfo(ns, name, file_stat,
file_offset, rtld_flags);
@@ -326,7 +326,7 @@
si->generate_handle();
ns->add_soinfo(si);
- TRACE("name %s: allocated soinfo @ %p", name, si);
+ LD_DEBUG(any, "name %s: allocated soinfo @ %p", name, si);
return si;
}
@@ -349,7 +349,7 @@
munmap(reinterpret_cast<void*>(si->get_gap_start()), si->get_gap_size());
}
- TRACE("name %s: freeing soinfo @ %p", si->get_realpath(), si);
+ LD_DEBUG(any, "name %s: freeing soinfo @ %p", si->get_realpath(), si);
if (!solist_remove_soinfo(si)) {
async_safe_fatal("soinfo=%p is not in soinfo_list (double unload?)", si);
@@ -387,7 +387,7 @@
auto length = readlink(proc_self_fd, buf, sizeof(buf));
if (length == -1) {
if (!is_first_stage_init()) {
- PRINT("readlink(\"%s\" [fd=%d]) failed: %m", proc_self_fd, fd);
+ DL_WARN("readlink(\"%s\" [fd=%d]) failed: %m", proc_self_fd, fd);
}
return false;
}
@@ -818,8 +818,8 @@
}
if (s != nullptr) {
- TRACE_TYPE(LOOKUP, "%s s->st_value = %p, found->base = %p",
- name, reinterpret_cast<void*>(s->st_value), reinterpret_cast<void*>((*found)->base));
+ LD_DEBUG(lookup, "%s s->st_value = %p, found->base = %p",
+ name, reinterpret_cast<void*>(s->st_value), reinterpret_cast<void*>((*found)->base));
}
return s;
@@ -923,7 +923,7 @@
}
const char* const path = normalized_path.c_str();
- TRACE("Trying zip file open from path \"%s\" -> normalized \"%s\"", input_path, path);
+ LD_DEBUG(any, "Trying zip file open from path \"%s\" -> normalized \"%s\"", input_path, path);
// Treat an '!/' separator inside a path as the separator between the name
// of the zip file on disk and the subdirectory to search within it.
@@ -936,7 +936,7 @@
char buf[512];
if (strlcpy(buf, path, sizeof(buf)) >= sizeof(buf)) {
- PRINT("Warning: ignoring very long library path: %s", path);
+ DL_WARN("ignoring very long library path: %s", path);
return -1;
}
@@ -976,8 +976,8 @@
*realpath += separator;
} else {
if (!is_first_stage_init()) {
- PRINT("warning: unable to get realpath for the library \"%s\". Will use given path.",
- normalized_path.c_str());
+ DL_WARN("unable to get realpath for the library \"%s\". Will use given path.",
+ normalized_path.c_str());
}
*realpath = normalized_path;
}
@@ -988,7 +988,7 @@
static bool format_path(char* buf, size_t buf_size, const char* path, const char* name) {
int n = async_safe_format_buffer(buf, buf_size, "%s/%s", path, name);
if (n < 0 || n >= static_cast<int>(buf_size)) {
- PRINT("Warning: ignoring very long library path: %s/%s", path, name);
+ DL_WARN("ignoring very long library path: %s/%s", path, name);
return false;
}
@@ -1009,8 +1009,7 @@
*file_offset = 0;
if (!realpath_fd(fd, realpath)) {
if (!is_first_stage_init()) {
- PRINT("warning: unable to get realpath for the library \"%s\". Will use given path.",
- path);
+ DL_WARN("unable to get realpath for the library \"%s\". Will use given path.", path);
}
*realpath = path;
}
@@ -1043,7 +1042,7 @@
ZipArchiveCache* zip_archive_cache,
const char* name, soinfo *needed_by,
off64_t* file_offset, std::string* realpath) {
- TRACE("[ opening %s from namespace %s ]", name, ns->get_name());
+ LD_DEBUG(any, "[ opening %s from namespace %s ]", name, ns->get_name());
// If the name contains a slash, we should attempt to open it directly and not search the paths.
if (strchr(name, '/') != nullptr) {
@@ -1249,15 +1248,15 @@
// do not print this if a library is in the list of shared libraries for linked namespaces
if (!maybe_accessible_via_namespace_links(ns, name)) {
- PRINT("library \"%s\" (\"%s\") needed or dlopened by \"%s\" is not accessible for the"
- " namespace: [name=\"%s\", ld_library_paths=\"%s\", default_library_paths=\"%s\","
- " permitted_paths=\"%s\"]",
- name, realpath.c_str(),
- needed_or_dlopened_by,
- ns->get_name(),
- android::base::Join(ns->get_ld_library_paths(), ':').c_str(),
- android::base::Join(ns->get_default_library_paths(), ':').c_str(),
- android::base::Join(ns->get_permitted_paths(), ':').c_str());
+ DL_WARN("library \"%s\" (\"%s\") needed or dlopened by \"%s\" is not accessible for the"
+ " namespace: [name=\"%s\", ld_library_paths=\"%s\", default_library_paths=\"%s\","
+ " permitted_paths=\"%s\"]",
+ name, realpath.c_str(),
+ needed_or_dlopened_by,
+ ns->get_name(),
+ android::base::Join(ns->get_ld_library_paths(), ':').c_str(),
+ android::base::Join(ns->get_default_library_paths(), ':').c_str(),
+ android::base::Join(ns->get_permitted_paths(), ':').c_str());
}
return false;
}
@@ -1330,10 +1329,9 @@
std::string realpath;
if (!realpath_fd(extinfo->library_fd, &realpath)) {
if (!is_first_stage_init()) {
- PRINT(
- "warning: unable to get realpath for the library \"%s\" by extinfo->library_fd. "
- "Will use given name.",
- name);
+ DL_WARN("unable to get realpath for the library \"%s\" by extinfo->library_fd. "
+ "Will use given name.",
+ name);
}
realpath = name;
}
@@ -1474,8 +1472,8 @@
// Library might still be loaded, the accurate detection
// of this fact is done by load_library.
- TRACE("[ \"%s\" find_loaded_library_by_soname failed (*candidate=%s@%p). Trying harder... ]",
- task->get_name(), candidate == nullptr ? "n/a" : candidate->get_realpath(), candidate);
+ LD_DEBUG(any, "[ \"%s\" find_loaded_library_by_soname failed (*candidate=%s@%p). Trying harder... ]",
+ task->get_name(), candidate == nullptr ? "n/a" : candidate->get_realpath(), candidate);
if (load_library(ns, task, zip_archive_cache, load_tasks, rtld_flags,
true /* search_linked_namespaces */)) {
@@ -1906,8 +1904,8 @@
if (si->has_min_version(0)) {
soinfo* child = nullptr;
while ((child = si->get_children().pop_front()) != nullptr) {
- TRACE("%s@%p needs to unload %s@%p", si->get_realpath(), si,
- child->get_realpath(), child);
+ LD_DEBUG(any, "%s@%p needs to unload %s@%p", si->get_realpath(), si,
+ child->get_realpath(), child);
child->get_parents().remove(si);
@@ -2197,10 +2195,10 @@
if (file_exists(translated_name_holder.c_str())) {
soinfo* si = nullptr;
if (find_loaded_library_by_realpath(ns, original_path, true, &si)) {
- PRINT("linker_asan dlopen NOT translating \"%s\" -> \"%s\": library already loaded", name,
- translated_name_holder.c_str());
+ DL_WARN("linker_asan dlopen NOT translating \"%s\" -> \"%s\": library already loaded", name,
+ translated_name_holder.c_str());
} else {
- PRINT("linker_asan dlopen translating \"%s\" -> \"%s\"", name, translated_name);
+ DL_WARN("linker_asan dlopen translating \"%s\" -> \"%s\"", name, translated_name);
translated_name = translated_name_holder.c_str();
}
}
@@ -2217,10 +2215,10 @@
if (!translated_name_holder.empty() && file_exists(translated_name_holder.c_str())) {
soinfo* si = nullptr;
if (find_loaded_library_by_realpath(ns, original_path, true, &si)) {
- PRINT("linker_hwasan dlopen NOT translating \"%s\" -> \"%s\": library already loaded", name,
- translated_name_holder.c_str());
+ DL_WARN("linker_hwasan dlopen NOT translating \"%s\" -> \"%s\": library already loaded",
+ name, translated_name_holder.c_str());
} else {
- PRINT("linker_hwasan dlopen translating \"%s\" -> \"%s\"", name, translated_name);
+ DL_WARN("linker_hwasan dlopen translating \"%s\" -> \"%s\"", name, translated_name);
translated_name = translated_name_holder.c_str();
}
}
@@ -2589,8 +2587,8 @@
if (g_is_ldd) return 0;
ElfW(Addr) ifunc_addr = __bionic_call_ifunc_resolver(resolver_addr);
- TRACE_TYPE(RELO, "Called ifunc_resolver@%p. The result is %p",
- reinterpret_cast<void *>(resolver_addr), reinterpret_cast<void*>(ifunc_addr));
+ LD_DEBUG(calls, "ifunc_resolver@%p returned %p",
+ reinterpret_cast<void *>(resolver_addr), reinterpret_cast<void*>(ifunc_addr));
return ifunc_addr;
}
@@ -2842,8 +2840,8 @@
/* We can't log anything until the linker is relocated */
bool relocating_linker = (flags_ & FLAG_LINKER) != 0;
if (!relocating_linker) {
- INFO("[ Linking \"%s\" ]", get_realpath());
- DEBUG("si->base = %p si->flags = 0x%08x", reinterpret_cast<void*>(base), flags_);
+ LD_DEBUG(any, "[ Linking \"%s\" ]", get_realpath());
+ LD_DEBUG(any, "si->base = %p si->flags = 0x%08x", reinterpret_cast<void*>(base), flags_);
}
if (dynamic == nullptr) {
@@ -2853,7 +2851,7 @@
return false;
} else {
if (!relocating_linker) {
- DEBUG("dynamic = %p", dynamic);
+ LD_DEBUG(dynamic, "dynamic section @%p", dynamic);
}
}
@@ -2883,8 +2881,8 @@
// source: http://www.sco.com/developers/gabi/1998-04-29/ch5.dynamic.html
uint32_t needed_count = 0;
for (ElfW(Dyn)* d = dynamic; d->d_tag != DT_NULL; ++d) {
- DEBUG("d = %p, d[0](tag) = %p d[1](val) = %p",
- d, reinterpret_cast<void*>(d->d_tag), reinterpret_cast<void*>(d->d_un.d_val));
+ LD_DEBUG(dynamic, "dynamic entry @%p: d_tag=%p, d_val=%p",
+ d, reinterpret_cast<void*>(d->d_tag), reinterpret_cast<void*>(d->d_un.d_val));
switch (d->d_tag) {
case DT_SONAME:
// this is parsed after we have strtab initialized (see below).
@@ -3098,17 +3096,17 @@
case DT_INIT:
init_func_ = reinterpret_cast<linker_ctor_function_t>(load_bias + d->d_un.d_ptr);
- DEBUG("%s constructors (DT_INIT) found at %p", get_realpath(), init_func_);
+ LD_DEBUG(dynamic, "%s constructors (DT_INIT) found at %p", get_realpath(), init_func_);
break;
case DT_FINI:
fini_func_ = reinterpret_cast<linker_dtor_function_t>(load_bias + d->d_un.d_ptr);
- DEBUG("%s destructors (DT_FINI) found at %p", get_realpath(), fini_func_);
+ LD_DEBUG(dynamic, "%s destructors (DT_FINI) found at %p", get_realpath(), fini_func_);
break;
case DT_INIT_ARRAY:
init_array_ = reinterpret_cast<linker_ctor_function_t*>(load_bias + d->d_un.d_ptr);
- DEBUG("%s constructors (DT_INIT_ARRAY) found at %p", get_realpath(), init_array_);
+ LD_DEBUG(dynamic, "%s constructors (DT_INIT_ARRAY) found at %p", get_realpath(), init_array_);
break;
case DT_INIT_ARRAYSZ:
@@ -3117,7 +3115,7 @@
case DT_FINI_ARRAY:
fini_array_ = reinterpret_cast<linker_dtor_function_t*>(load_bias + d->d_un.d_ptr);
- DEBUG("%s destructors (DT_FINI_ARRAY) found at %p", get_realpath(), fini_array_);
+ LD_DEBUG(dynamic, "%s destructors (DT_FINI_ARRAY) found at %p", get_realpath(), fini_array_);
break;
case DT_FINI_ARRAYSZ:
@@ -3126,7 +3124,7 @@
case DT_PREINIT_ARRAY:
preinit_array_ = reinterpret_cast<linker_ctor_function_t*>(load_bias + d->d_un.d_ptr);
- DEBUG("%s constructors (DT_PREINIT_ARRAY) found at %p", get_realpath(), preinit_array_);
+ LD_DEBUG(dynamic, "%s constructors (DT_PREINIT_ARRAY) found at %p", get_realpath(), preinit_array_);
break;
case DT_PREINIT_ARRAYSZ:
@@ -3266,8 +3264,8 @@
}
}
- DEBUG("si->base = %p, si->strtab = %p, si->symtab = %p",
- reinterpret_cast<void*>(base), strtab_, symtab_);
+ LD_DEBUG(dynamic, "si->base = %p, si->strtab = %p, si->symtab = %p",
+ reinterpret_cast<void*>(base), strtab_, symtab_);
// Validity checks.
if (relocating_linker && needed_count != 0) {
@@ -3374,7 +3372,7 @@
return false;
}
- DEBUG("[ finished linking %s ]", get_realpath());
+ LD_DEBUG(any, "[ finished linking %s ]", get_realpath());
#if !defined(__LP64__)
if (has_text_relocations) {
@@ -3556,7 +3554,7 @@
{
std::string ld_config_file_path = get_ld_config_file_path(executable_path);
- INFO("[ Reading linker config \"%s\" ]", ld_config_file_path.c_str());
+ LD_DEBUG(any, "[ Reading linker config \"%s\" ]", ld_config_file_path.c_str());
ScopedTrace trace(("linker config " + ld_config_file_path).c_str());
std::string error_msg;
if (!Config::read_binary_config(ld_config_file_path.c_str(), executable_path, g_is_asan, g_is_hwasan,