From 5aa165b0216900b6696b6148ead95c22bc6fbcc8 Mon Sep 17 00:00:00 2001 From: yinchuang Date: Fri, 7 Jul 2023 19:47:51 +0800 Subject: [PATCH] Add linker log Issue:I7EFAP Signed-off-by: yinchuang --- porting/linux/user/ldso/cfi.c | 49 +++++++++---------- porting/linux/user/ldso/dynlink.c | 25 +++++++--- porting/linux/user/ldso/ld_log.h | 4 +- .../linux/user/src/thread/pthread_create.c | 18 +++++-- 4 files changed, 55 insertions(+), 41 deletions(-) diff --git a/porting/linux/user/ldso/cfi.c b/porting/linux/user/ldso/cfi.c index e23b808a..314e740a 100644 --- a/porting/linux/user/ldso/cfi.c +++ b/porting/linux/user/ldso/cfi.c @@ -184,12 +184,9 @@ static uintptr_t get_cfi_check_addr(uint16_t value, void* func_ptr) static inline void cfi_slowpath_common(uint64_t call_site_type_id, void *func_ptr, void *diag_data) { - LD_LOGI("[CFI] [%{public}s] func_ptr[%{public}p] !\n", __FUNCTION__, func_ptr); - uint16_t value = sv_invalid; if (func_ptr == NULL) { - LD_LOGE("[CFI] [%{public}s] func_ptr is NULL!\n", __FUNCTION__); return; } @@ -214,7 +211,11 @@ static inline void cfi_slowpath_common(uint64_t call_site_type_id, void *func_pt } else { value = *((uint16_t*)(cfi_shadow_start + offset)); } - LD_LOGI("[CFI] [%{public}s] the value is 0x%{public}x!\n", __FUNCTION__, value); + LD_LOGD("[CFI] [%{public}s] called from %{public}s to %{public}s func_ptr:0x%{public}p shadow value:%{public}d diag_data:0x%{public}p call_site_type_id[%{public}p.\n", + __FUNCTION__, + ((struct dso *)addr2dso((size_t)__builtin_return_address(0)))->name, + ((struct dso *)addr2dso((size_t)func_ptr))->name, + func_ptr, value, diag_data, call_site_type_id); struct dso *dso = NULL; switch (value) @@ -232,7 +233,7 @@ static inline void cfi_slowpath_common(uint64_t call_site_type_id, void *func_pt LD_LOGE("[CFI] [%{public}s] can not find the dso!\n", __FUNCTION__); __builtin_trap(); } - LD_LOGI("[CFI] [%{public}s] dso name[%{public}s]!\n", __FUNCTION__, dso->name); + LD_LOGD("[CFI] [%{public}s] dso name[%{public}s]!\n", __FUNCTION__, dso->name); struct symdef cfi_check_sym = find_cfi_check_sym(dso); if (!cfi_check_sym.sym) { @@ -255,7 +256,7 @@ static inline void cfi_slowpath_common(uint64_t call_site_type_id, void *func_pt int init_cfi_shadow(struct dso *dso_list, struct dso *ldso) { - LD_LOGI("[CFI] [%{public}s] start!\n", __FUNCTION__); + LD_LOGD("[CFI] [%{public}s] start!\n", __FUNCTION__); if (dso_list == NULL) { LD_LOGW("[CFI] [%{public}s] has null param!\n", __FUNCTION__); @@ -271,8 +272,6 @@ int init_cfi_shadow(struct dso *dso_list, struct dso *ldso) int map_dso_to_cfi_shadow(struct dso *dso) { - LD_LOGI("[CFI] [%{public}s] start!\n", __FUNCTION__); - bool has_cfi_check = false; if (dso == NULL) { @@ -285,7 +284,7 @@ int map_dso_to_cfi_shadow(struct dso *dso) /* Find __cfi_check symbol in dso list */ for (struct dso *p = dso; p; p = p->next) { if (find_cfi_check_sym(p).sym) { - LD_LOGI("[CFI] [%{public}s] find __cfi_check function in dso %{public}s!\n", __FUNCTION__, p->name); + LD_LOGD("[CFI] [%{public}s] find __cfi_check function in dso %{public}s!\n", __FUNCTION__, p->name); has_cfi_check = true; break; } @@ -296,13 +295,11 @@ int map_dso_to_cfi_shadow(struct dso *dso) LD_LOGE("[CFI] [%{public}s] create cfi shadow failed!\n", __FUNCTION__); return CFI_FAILED; } - LD_LOGD("[CFI] [%{public}s] add_dso_to_cfi_shadow with dso_list_head!\n", __FUNCTION__); add_dso_to_cfi_shadow(dso_list_head); prctl(PR_SET_VMA, PR_SET_VMA_ANON_NAME, cfi_shadow_start, shadow_size, "cfi_shadow:musl"); } /* If the cfi shadow exists, map the current dso and its dependents to it. */ } else { - LD_LOGD("[CFI] [%{public}s] add_dso_to_cfi_shadow with dso!\n", __FUNCTION__); add_dso_to_cfi_shadow(dso); prctl(PR_SET_VMA, PR_SET_VMA_ANON_NAME, cfi_shadow_start, shadow_size, "cfi_shadow:musl"); } @@ -312,14 +309,12 @@ int map_dso_to_cfi_shadow(struct dso *dso) void unmap_dso_from_cfi_shadow(struct dso *dso) { - LD_LOGD("[CFI] [%{public}s] start!\n", __FUNCTION__); - if (dso == NULL) { - LD_LOGE("[CFI] [%{public}s] has null param!\n", __FUNCTION__); + LD_LOGD("[CFI] [%{public}s] has null param!\n", __FUNCTION__); return; } - LD_LOGI("[CFI] [%{public}s] unmap dso %{public}s from shadow!\n", __FUNCTION__, dso->name); + LD_LOGD("[CFI] [%{public}s] unmap dso %{public}s from shadow!\n", __FUNCTION__, dso->name); if (cfi_shadow_start == NULL) return; @@ -354,17 +349,16 @@ static int create_cfi_shadow(void) } cfi_shadow_start = (char*)mmap_addr; - LD_LOGI("[CFI] [%{public}s] the cfi_shadow_start addr is %{public}p!\n", __FUNCTION__, cfi_shadow_start); + LD_LOGD("[CFI] [%{public}s] the cfi_shadow_start addr is %{public}p!\n", __FUNCTION__, cfi_shadow_start); return CFI_SUCCESS; } static int add_dso_to_cfi_shadow(struct dso *dso) { - LD_LOGI("[CFI] [%{public}s] start!\n", __FUNCTION__); - + LD_LOGD("[CFI] [%{public}s] start with %{public}s !\n", __FUNCTION__, dso->name); for (struct dso *p = dso; p; p = p->next) { - LD_LOGI("[CFI] [%{public}s] start to deal with dso %{public}s!\n", __FUNCTION__, p->name); + LD_LOGD("[CFI] [%{public}s] adding %{public}s to cfi shadow!\n", __FUNCTION__, p->name); if (p->map == 0 || p->map_len == 0) { LD_LOGW("[CFI] [%{public}s] the dso has no data! map[%{public}p] map_len[0x%{public}x]\n", __FUNCTION__, p->map, p->map_len); @@ -372,43 +366,44 @@ static int add_dso_to_cfi_shadow(struct dso *dso) } if (p->is_mapped_to_shadow == true) { - LD_LOGW("[CFI] [%{public}s] the dso is already in shadow!\n", __FUNCTION__); + LD_LOGW("[CFI] [%{public}s] %{public}s is already in shadow!\n", __FUNCTION__, p->name); continue; } struct symdef cfi_check_sym = find_cfi_check_sym(p); /* If the dso doesn't have __cfi_check(), set it's shadow value unchecked. */ if (!cfi_check_sym.sym) { - LD_LOGI("[CFI] [%{public}s] the dso has no __cfi_check()!\n", __FUNCTION__); + LD_LOGD("[CFI] [%{public}s] %{public}s has no __cfi_check()!\n", __FUNCTION__, p->name); if (fill_shadow_value_to_shadow(p->map, p->map + p->map_len, 0, sv_uncheck) == CFI_FAILED) { LD_LOGE("[CFI] [%{public}s] add dso to cfi shadow failed!\n", __FUNCTION__); return CFI_FAILED; } /* If the dso has __cfi_check(), set it's shadow value valid. */ } else { - LD_LOGI("[CFI] [%{public}s] the dso has __cfi_check()!\n", __FUNCTION__); + LD_LOGD("[CFI] [%{public}s] %{public}s has __cfi_check()!\n", __FUNCTION__, p->name); uintptr_t end = p->map + p->map_len; uintptr_t cfi_check = LADDR(cfi_check_sym.dso, cfi_check_sym.sym->st_value); if (cfi_check == 0) { - LD_LOGE("[CFI] [%{public}s] the dso has null cfi_check func!\n", __FUNCTION__); + LD_LOGE("[CFI] [%{public}s] %{public}s has null cfi_check func!\n", __FUNCTION__, p->name); return CFI_FAILED; } if (fill_shadow_value_to_shadow(p->map, end, cfi_check, sv_valid_min) == CFI_FAILED) { - LD_LOGE("[CFI] [%{public}s] add dso to cfi shadow failed!\n", __FUNCTION__); + LD_LOGE("[CFI] [%{public}s] add %{public}s to cfi shadow failed!\n", __FUNCTION__, p->name); return CFI_FAILED; } } p->is_mapped_to_shadow = true; - LD_LOGI("[CFI] [%{public}s] finish to deal with dso %{public}s!\n", __FUNCTION__, p->name); + LD_LOGD("[CFI] [%{public}s] add %{public}s to cfi shadow succeed.\n", __FUNCTION__, p->name); } + LD_LOGD("[CFI] [%{public}s] %{public}s done.\n", __FUNCTION__, dso->name); return CFI_SUCCESS; } static int fill_shadow_value_to_shadow(uintptr_t begin, uintptr_t end, uintptr_t cfi_check, uint16_t type) { - LD_LOGI("[CFI] [%{public}s] begin[%{public}x] end[%{public}x] cfi_check[%{public}x] type[%{public}x]!\n", + LD_LOGD("[CFI] [%{public}s] begin[%{public}x] end[%{public}x] cfi_check[%{public}x] type[%{public}x]!\n", __FUNCTION__, begin, end, cfi_check, type); /* To ensure the atomicity of the CFI shadow operation, we create a temp_shadow, write the shadow value to @@ -445,7 +440,7 @@ static int fill_shadow_value_to_shadow(uintptr_t begin, uintptr_t end, uintptr_t uint16_t shadow_value_begin = ((begin + shadow_alignment - cfi_check) >> cfi_check_granularity) + sv_valid_min; #endif - LD_LOGI("[CFI] [%{public}s] shadow_value_begin is 0x%{public}x!\n", __FUNCTION__, shadow_value_begin); + LD_LOGD("[CFI] [%{public}s] shadow_value_begin is 0x%{public}x!\n", __FUNCTION__, shadow_value_begin); uint16_t shadow_value_step = 1 << (shadow_granularity - cfi_check_granularity); uint16_t shadow_value = shadow_value_begin; diff --git a/porting/linux/user/ldso/dynlink.c b/porting/linux/user/ldso/dynlink.c index ff932d9c..d8a2353b 100644 --- a/porting/linux/user/ldso/dynlink.c +++ b/porting/linux/user/ldso/dynlink.c @@ -2305,10 +2305,8 @@ static void do_android_relocs(struct dso *p, size_t dt_name, size_t dt_size) } if (dt_name == DT_ANDROID_REL) { - LD_LOGI("do_android_relocs REL %{public}x %{public}x", rel[0], rel[1]); do_relocs(p, rel, sizeof(size_t)*2, 2); } else { - LD_LOGI("do_android_relocs RELA %{public}x %{public}x %{public}x", rel[0], rel[1], rel[2]); do_relocs(p, rel, sizeof(size_t)*3, 3); } } @@ -3388,11 +3386,9 @@ void *dlopen(const char *file, int mode) void dlns_init(Dl_namespace *dlns, const char *name) { if (!dlns) { - LD_LOGE("dlns_init dlns is null."); return; } if (!name) { - LD_LOGE("dlns_init name is null."); dlns->name[0] = 0; return; } @@ -3636,20 +3632,25 @@ static int dlclose_impl(struct dso *p) return -1; if (!p->by_dlopen) { - error("Library %s is not loaded by dlopen", p->name); + LD_LOGD("dlclose skip unload %{public}s because so isn't loaded by dlopen", p->name); return -1; } /* dso is marked as RTLD_NODELETE library, do nothing here. */ if ((p->flags & DSO_FLAGS_NODELETE) != 0) { + LD_LOGD("dlclose skip unload %{public}s because flags is RTLD_NODELETE", p->name); return 0; } - if (--(p->nr_dlopen) > 0) + if (--(p->nr_dlopen) > 0) { + LD_LOGD("dlclose skip unload %{public}s because nr_dlopen=%{public}d > 0", p->name, p->nr_dlopen); return 0; + } - if (p->parents_count > 0) + if (p->parents_count > 0) { + LD_LOGD("dlclose skip unload %{public}s because parents_count=%{public}d > 0", p->name, p->parents_count); return 0; + } trace_marker_reset(); trace_marker_begin(HITRACE_TAG_MUSL, "dlclose", p->name); @@ -3731,6 +3732,7 @@ static int dlclose_impl(struct dso *p) } if (p->deps != no_deps) free(p->deps); + LD_LOGD("dlclose unloading %{public}s @%{public}p", p->name, p); unmap_library(p); if (p->parents) { @@ -4787,6 +4789,8 @@ static bool load_library_header(struct loadtask *task) task->p = find_library_by_name(name, namespace, check_inherited); if (task->p) { task->isloaded = true; + LD_LOGD("find_library_by_name(name=%{public}s ns=%{public}s) already loaded by %{public}s in %{public}s namespace ", + name, namespace->ns_name, task->p->name, task->p->namespace->ns_name); return true; } if (strlen(name) > NAME_MAX) { @@ -4853,6 +4857,8 @@ static bool load_library_header(struct loadtask *task) close(task->fd); task->fd = -1; task->isloaded = true; + LD_LOGD("find_library_by_fstat(name=%{public}s ns=%{public}s) already loaded by %{public}s in %{public}s namespace ", + name, namespace->ns_name, task->p->name, task->p->namespace->ns_name); return true; } @@ -4920,6 +4926,7 @@ static bool load_library_header(struct loadtask *task) static void task_load_library(struct loadtask *task, struct reserved_address_params *reserved_params) { + LD_LOGD("load_library loading ns=%{public}s name=%{public}s by_dlopen=%{public}d", task->namespace->ns_name, task->p->name, runtime); bool map = noload ? 0 : task_map_library(task, reserved_params); close(task->fd); task->fd = -1; @@ -5011,7 +5018,9 @@ static void preload_direct_deps(struct dso *p, ns_t *namespace, struct loadtasks if (p->dynv[i] != DT_NEEDED) { continue; } - struct loadtask *task = create_loadtask(p->strings + p->dynv[i + 1], p, namespace, true); + const char* dtneed_name = p->strings + p->dynv[i + 1]; + LD_LOGD("load_library %{public}s adding DT_NEEDED task %{public}s namespace(%{public}s)", p->name, dtneed_name, namespace->ns_name); + struct loadtask *task = create_loadtask(dtneed_name, p, namespace, true); if (!task) { LD_LOGE("Error loading dependencies %{public}s : create load task failed", p->name); error("Error loading dependencies for %s : create load task failed", p->name); diff --git a/porting/linux/user/ldso/ld_log.h b/porting/linux/user/ldso/ld_log.h index 697a01a0..47f70587 100644 --- a/porting/linux/user/ldso/ld_log.h +++ b/porting/linux/user/ldso/ld_log.h @@ -37,9 +37,7 @@ hidden void ld_log_reset(); hidden bool is_dlclose_debug_enable(); #if ((LD_LOG_LEVEL & LD_LOG_ERROR) && (defined(OHOS_ENABLE_PARAMETER) || defined(ENABLE_MUSL_LOG))) -#define LD_LOGE(...) if (get_ld_log_enable()) { \ - (void)HiLogAdapterPrint(MUSL_LOG_TYPE, LOG_ERROR, MUSL_LOG_DOMAIN, LD_LOG_TAG, __VA_ARGS__); \ -} +#define LD_LOGE(...) (void)HiLogAdapterPrint(MUSL_LOG_TYPE, LOG_ERROR, MUSL_LOG_DOMAIN, LD_LOG_TAG, __VA_ARGS__); #else #define LD_LOGE(...) #endif diff --git a/porting/linux/user/src/thread/pthread_create.c b/porting/linux/user/src/thread/pthread_create.c index a759c657..1ef15f1e 100644 --- a/porting/linux/user/src/thread/pthread_create.c +++ b/porting/linux/user/src/thread/pthread_create.c @@ -1,5 +1,6 @@ #define _GNU_SOURCE #define ANON_STACK_NAME_SIZE 50 +#include "musl_log.h" #include "pthread_impl.h" #include "stdio_impl.h" #include "libc.h" @@ -336,7 +337,10 @@ int __pthread_create(pthread_t *restrict res, const pthread_attr_t *restrict att pthread_attr_t attr = { 0 }; sigset_t set; - if (!libc.can_do_threads) return ENOSYS; + if (!libc.can_do_threads) { + MUSL_LOGE("pthread_create: can't do threads, err: %{public}s", strerror(errno)); + return ENOSYS; + } self = __pthread_self(); if (!libc.threaded) { for (FILE *f=*__ofl_lock(); f; f=f->next) @@ -383,15 +387,22 @@ int __pthread_create(pthread_t *restrict res, const pthread_attr_t *restrict att if (!tsd) { if (guard) { map = __mmap(0, size, PROT_NONE, MAP_PRIVATE|MAP_ANON, -1, 0); - if (map == MAP_FAILED) goto fail; + if (map == MAP_FAILED) { + MUSL_LOGE("pthread_create: mmap PROT_NONE failed, err:%{public}s", strerror(errno)); + goto fail; + } if (__mprotect(map+guard, size-guard, PROT_READ|PROT_WRITE) && errno != ENOSYS) { + MUSL_LOGE("pthread_create: mprotect failed, err:%{public}s", strerror(errno)); __munmap(map, size); goto fail; } } else { map = __mmap(0, size, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0); - if (map == MAP_FAILED) goto fail; + if (map == MAP_FAILED) { + MUSL_LOGE("pthread_create: mmap PROT_READ|PROT_WRITE failed, err:%{public}s", strerror(errno)); + goto fail; + } } tsd = map + size - __pthread_tsd_size; if (!stack) { @@ -476,6 +487,7 @@ int __pthread_create(pthread_t *restrict res, const pthread_attr_t *restrict att if (ret < 0) { if (map) __munmap(map, size); + MUSL_LOGE("pthread_create: ret:%{public}d, err:%{public}s", ret, strerror(errno)); return -ret; } -- GitLab