From 87a8901d6eca582812ee84f8ab2ae3d10740adce Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E4=BA=91=E5=BE=AE?= <1067852565@qq.com> Date: Sat, 10 Aug 2024 20:26:01 +1000 Subject: [PATCH] fix: improve error message and handling in syscall-server (#321) * use bench in CI and fix handle error * make error message more friendly * skip bench * update error info --- .github/workflows/build-benchmarks.yml | 3 + .gitignore | 2 + .../src/frida_attach_utils.cpp | 40 +++++----- .../src/frida_uprobe_attach_impl.cpp | 2 +- benchmark/.gitignore | 3 +- benchmark/Makefile | 2 +- benchmark/README.md | 9 ++- benchmark/run_benchmark.py | 8 +- runtime/agent/agent.cpp | 4 +- runtime/src/attach/bpf_attach_ctx.cpp | 12 ++- runtime/src/bpftime_prog.cpp | 8 +- runtime/syscall-server/CMakeLists.txt | 5 ++ .../syscall-server/syscall_server_main.cpp | 73 ++++++++++++++----- tools/bpftimetool/README.md | 18 ----- vm/compat/include/bpftime_vm_compat.hpp | 2 +- 15 files changed, 115 insertions(+), 76 deletions(-) diff --git a/.github/workflows/build-benchmarks.yml b/.github/workflows/build-benchmarks.yml index 7de67892..f1c515ae 100644 --- a/.github/workflows/build-benchmarks.yml +++ b/.github/workflows/build-benchmarks.yml @@ -29,3 +29,6 @@ jobs: - name: build benchmarks run: make -C benchmark + + # - name: run benchmarks + # run: cd benchmark && python3 run_benchmark.py diff --git a/.gitignore b/.gitignore index b8377cf7..6acff2c3 100644 --- a/.gitignore +++ b/.gitignore @@ -49,3 +49,5 @@ third_party/frida third_party/phaole third_party/phaole1 output_metrics.json +perf.data +perf.data.old diff --git a/attach/frida_uprobe_attach_impl/src/frida_attach_utils.cpp b/attach/frida_uprobe_attach_impl/src/frida_attach_utils.cpp index 68a4cfac..81fb2a6b 100644 --- a/attach/frida_uprobe_attach_impl/src/frida_attach_utils.cpp +++ b/attach/frida_uprobe_attach_impl/src/frida_attach_utils.cpp @@ -11,23 +11,23 @@ static std::string get_executable_path() { char exec_path[PATH_MAX] = { 0 }; - #if __linux__ - ssize_t len = - readlink("/proc/self/exe", exec_path, sizeof(exec_path) - 1); - if (len != -1) { - exec_path[len] = '\0'; // Null-terminate the string - SPDLOG_INFO("Executable path: {}", exec_path); - } else { - SPDLOG_ERROR("Error retrieving executable path: {}", errno); - } - #elif __APPLE__ - pid_t pid = getpid(); - if (proc_pidpath(pid, exec_path, sizeof(exec_path)) > 0) { - SPDLOG_INFO("Executable path: {}", exec_path); - } else { - SPDLOG_ERROR("Error retrieving executable path: {}", errno); - } - #endif +#if __linux__ + ssize_t len = + readlink("/proc/self/exe", exec_path, sizeof(exec_path) - 1); + if (len != -1) { + exec_path[len] = '\0'; // Null-terminate the string + SPDLOG_INFO("Executable path: {}", exec_path); + } else { + SPDLOG_ERROR("Error retrieving executable path: {}", errno); + } +#elif __APPLE__ + pid_t pid = getpid(); + if (proc_pidpath(pid, exec_path, sizeof(exec_path)) > 0) { + SPDLOG_INFO("Executable path: {}", exec_path); + } else { + SPDLOG_ERROR("Error retrieving executable path: {}", errno); + } +#endif return exec_path; } namespace bpftime @@ -47,8 +47,10 @@ resolve_function_addr_by_module_offset(const std::string_view &module_name, get_module_base_addr(std::string(module_name).c_str()); } if (!module_base_addr) { - SPDLOG_ERROR("Failed to find module base address for {}", - module_name); + // It's not a bug, it might be attach to a unrelated process + // when using the LD_PRELOAD + SPDLOG_INFO("Failed to find module base address for {}", + module_name); return nullptr; } diff --git a/attach/frida_uprobe_attach_impl/src/frida_uprobe_attach_impl.cpp b/attach/frida_uprobe_attach_impl/src/frida_uprobe_attach_impl.cpp index 1e35721b..d9d629a8 100644 --- a/attach/frida_uprobe_attach_impl/src/frida_uprobe_attach_impl.cpp +++ b/attach/frida_uprobe_attach_impl/src/frida_uprobe_attach_impl.cpp @@ -214,7 +214,7 @@ int frida_attach_impl::create_attach_with_ebpf_callback( } } if (!ok) { - SPDLOG_ERROR( + SPDLOG_INFO( "Unable to attach: module name {} doesn't exist in current process's memory maps", sub.module_name); return -EINVAL; diff --git a/benchmark/.gitignore b/benchmark/.gitignore index aed1e316..173b04ce 100644 --- a/benchmark/.gitignore +++ b/benchmark/.gitignore @@ -1,2 +1,3 @@ test -micro-bench \ No newline at end of file +micro-bench +benchmark-output.json diff --git a/benchmark/Makefile b/benchmark/Makefile index 74cce8c8..fe24fd85 100644 --- a/benchmark/Makefile +++ b/benchmark/Makefile @@ -1,6 +1,6 @@ all: benchmark test test: test.c - gcc test.c -O3 -lpthread -o test + gcc test.c -g -O3 -lpthread -o test # test with the files in bpf-loader TEST_CASES_DIRS=$(filter-out $(SKIP_TESTS),$(shell ls -l $(./) | grep ^d | awk '{print $$9}')) diff --git a/benchmark/README.md b/benchmark/README.md index 6e0d34d5..3d71c865 100644 --- a/benchmark/README.md +++ b/benchmark/README.md @@ -13,7 +13,7 @@ With userspace eBPF runntime, we can: | Syscall Tracepoint | 151.82801 | 232.57691 | 4 | | Embedding runtime | Not avaliable | 110.008430 | 4 | -## build +## build and run at a click Build the agent first. In project root: @@ -27,6 +27,13 @@ build the benchmark driver: make -C benchmark ``` +Run the uprobe bench: + +```sh +cd benchmark +python3 run_benchmark.py +``` + ## test environment ```console diff --git a/benchmark/run_benchmark.py b/benchmark/run_benchmark.py index 15683adf..5f1b964c 100644 --- a/benchmark/run_benchmark.py +++ b/benchmark/run_benchmark.py @@ -90,7 +90,7 @@ async def run_userspace_uprobe_test(): await server_start_cb.wait() print("server started!") result = None - for i in range(100): + for i in range(10): victim = await asyncio.subprocess.create_subprocess_shell( str(CURR_FILE_DIR / "test"), stdout=asyncio.subprocess.PIPE, @@ -138,7 +138,7 @@ async def run_kernel_uprobe_test(): print("server started!") # await asyncio.sleep(10) result = None - for i in range(100): + for i in range(10): victim = await asyncio.subprocess.create_subprocess_shell( str(CURR_FILE_DIR / "test"), stdout=asyncio.subprocess.PIPE, @@ -170,7 +170,7 @@ def handle_embed_victim_out(i: str) -> float: async def run_embed_vm_test(): result = {"embed": []} bpf_path = str(CURR_FILE_DIR / "uprobe/.output/uprobe.bpf.o") - for i in range(100): + for i in range(10): victim = await asyncio.subprocess.create_subprocess_shell( " ".join( [ @@ -198,7 +198,7 @@ async def main(): out = {"kernel_uprobe": k, "userspace_uprobe": u, "embed": e} with open("benchmark-output.json", "w") as f: json.dump(out, f) - + print(out) if __name__ == "__main__": asyncio.run(main()) diff --git a/runtime/agent/agent.cpp b/runtime/agent/agent.cpp index f4a59b5e..6dda93f8 100644 --- a/runtime/agent/agent.cpp +++ b/runtime/agent/agent.cpp @@ -166,11 +166,11 @@ extern "C" void bpftime_agent_main(const gchar *data, gboolean *stay_resident) res = ctx_holder.ctx.init_attach_ctx_from_handlers( bpftime_get_agent_config()); if (res != 0) { - SPDLOG_ERROR("Failed to initialize attach context"); + SPDLOG_INFO("Failed to initialize attach context, exiting.."); return; } } catch (std::exception &ex) { - SPDLOG_ERROR("Unable to instantiate handlers: {}", ex.what()); + SPDLOG_ERROR("Unable to instantiate handlers with error: {}", ex.what()); return; } SPDLOG_INFO("Attach successfully"); diff --git a/runtime/src/attach/bpf_attach_ctx.cpp b/runtime/src/attach/bpf_attach_ctx.cpp index bba56dfd..f15ac35f 100644 --- a/runtime/src/attach/bpf_attach_ctx.cpp +++ b/runtime/src/attach/bpf_attach_ctx.cpp @@ -70,9 +70,10 @@ int bpf_attach_ctx::init_attach_ctx_from_handlers( if (int err = instantiate_handler_at(manager, i, stk, config); err < 0) { - SPDLOG_ERROR("Failed to instantiate handler {}", + SPDLOG_INFO("Failed to instantiate handler {}", i); - return err; + // Unable to instantiate handler may not be an error. + // We can continue trying to instantiate other handlers. } } } @@ -146,7 +147,7 @@ int bpf_attach_ctx::instantiate_handler_at(const handler_manager *manager, } if (int err = instantiate_bpf_link_handler_at(id, link_handler); err < 0) { - SPDLOG_ERROR( + SPDLOG_DEBUG( "Unable to instantiate bpf link handler {}: {}", id, err); return err; @@ -216,6 +217,7 @@ int bpf_attach_ctx::instantiate_bpf_link_handler_at( auto &[priv_data, attach_type] = instantiated_perf_events[handler.attach_target_id]; attach::base_attach_impl *attach_impl; + // Find what kind of attach type it is if (auto itr = attach_impls.find(attach_type); itr != attach_impls.end()) { attach_impl = itr->second.first; @@ -234,7 +236,9 @@ int bpf_attach_ctx::instantiate_bpf_link_handler_at( }, *priv_data, attach_type); if (attach_id < 0) { - SPDLOG_ERROR("Unable to instantiate bpf link handler {}: {}", + // Since the agent might be attach to a unrelated process + // Using LD_PRELOAD, it's not an error here. + SPDLOG_DEBUG("Unable to instantiate bpf link handler {}: {}", id, attach_id); return attach_id; } diff --git a/runtime/src/bpftime_prog.cpp b/runtime/src/bpftime_prog.cpp index 7c4ccfaa..3180ce91 100644 --- a/runtime/src/bpftime_prog.cpp +++ b/runtime/src/bpftime_prog.cpp @@ -18,10 +18,8 @@ using namespace std; namespace bpftime { - thread_local std::optional current_thread_bpf_cookie; - bpftime_prog::bpftime_prog(const struct ebpf_inst *insn, size_t insn_cnt, const char *name) : name(name) @@ -29,7 +27,8 @@ bpftime_prog::bpftime_prog(const struct ebpf_inst *insn, size_t insn_cnt, SPDLOG_DEBUG("Creating bpftime_prog with name {}", name); insns.assign(insn, insn + insn_cnt); vm = ebpf_create(); - ebpf_toggle_bounds_check(vm, false); + // Disable bounds check because we have no implementation yet + // ebpf_toggle_bounds_check(vm, false); ebpf_set_lddw_helpers(vm, map_ptr_by_fd, nullptr, map_val, nullptr, nullptr); } @@ -111,7 +110,8 @@ int bpftime_prog::bpftime_prog_register_raw_helper( return ebpf_register(vm, info.index, info.name.c_str(), info.fn); } -int bpftime_prog::load_aot_object(const std::vector &buf) { +int bpftime_prog::load_aot_object(const std::vector &buf) +{ ebpf_jit_fn res = ebpf_load_aot_object(vm, buf.data(), buf.size()); if (res == nullptr) { SPDLOG_ERROR("Failed to load aot object"); diff --git a/runtime/syscall-server/CMakeLists.txt b/runtime/syscall-server/CMakeLists.txt index ff39a159..77f8e5f8 100644 --- a/runtime/syscall-server/CMakeLists.txt +++ b/runtime/syscall-server/CMakeLists.txt @@ -9,13 +9,16 @@ add_library(bpftime-syscall-server SHARED syscall_server_main.cpp syscall_server_utils.cpp ) + target_link_libraries(bpftime-syscall-server PUBLIC runtime -lpthread -lm -ldl spdlog::spdlog) + add_dependencies(bpftime-syscall-server spdlog::spdlog) + if(${BPFTIME_BUILD_WITH_LIBBPF}) target_include_directories(bpftime-syscall-server PUBLIC @@ -31,10 +34,12 @@ target_include_directories(bpftime-syscall-server ${SPDLOG_INCLUDE} ) endif() + set_target_properties(bpftime-syscall-server PROPERTIES CXX_STANDARD 20 LINK_DEPENDS ${CMAKE_CURRENT_SOURCE_DIR}/syscall-server.version) if(UNIX AND NOT APPLE) target_link_options(bpftime-syscall-server PRIVATE -Wl,--version-script=${CMAKE_CURRENT_SOURCE_DIR}/syscall-server.version) endif() + if(${ENABLE_EBPF_VERIFIER}) add_dependencies(bpftime-syscall-server bpftime-verifier) target_link_libraries(bpftime-syscall-server PRIVATE bpftime-verifier) diff --git a/runtime/syscall-server/syscall_server_main.cpp b/runtime/syscall-server/syscall_server_main.cpp index fd95e8f8..0a8dfb7b 100644 --- a/runtime/syscall-server/syscall_server_main.cpp +++ b/runtime/syscall-server/syscall_server_main.cpp @@ -21,49 +21,83 @@ using namespace bpftime; // global context for bpf syscall server static syscall_context context; +template +auto handle_exceptions(F &&f, Args &&...args) noexcept + -> decltype(f(std::forward(args)...)) +{ + try { + return f(std::forward(args)...); + } catch (const boost::interprocess::bad_alloc &e) { + SPDLOG_ERROR("Boost interprocess bad_alloc: {}", e.what()); + SPDLOG_ERROR("Consider increasing the shared memory size by " + "setting the BPFTIME_SHM_MEMORY_MB env var."); + std::abort(); + // Terminate the program after logging the exception + } + // More exceptions can be added here +} + extern "C" int epoll_wait(int epfd, epoll_event *evt, int maxevents, int timeout) { SPDLOG_DEBUG("epoll_wait {}", epfd); - return context.handle_epoll_wait(epfd, evt, maxevents, timeout); + return handle_exceptions([&]() { + return context.handle_epoll_wait(epfd, evt, maxevents, timeout); + }); } extern "C" int epoll_ctl(int epfd, int op, int fd, epoll_event *evt) { SPDLOG_DEBUG("epoll_ctl {} {} {} {}", epfd, op, fd, (uintptr_t)evt); - return context.handle_epoll_ctl(epfd, op, fd, evt); + return handle_exceptions( + [&]() { return context.handle_epoll_ctl(epfd, op, fd, evt); }); } extern "C" int epoll_create1(int flags) { SPDLOG_DEBUG("epoll_create1 {}", flags); - return context.handle_epoll_create1(flags); + return handle_exceptions( + [&]() { return context.handle_epoll_create1(flags); }); } extern "C" int ioctl(int fd, unsigned long req, int data) { SPDLOG_DEBUG("ioctl {} {} {}", fd, req, data); - return context.handle_ioctl(fd, req, data); + return handle_exceptions( + [&]() { return context.handle_ioctl(fd, req, data); }); } extern "C" void *mmap64(void *addr, size_t length, int prot, int flags, int fd, off64_t offset) { SPDLOG_DEBUG("mmap64 {:x}", (uintptr_t)addr); - return context.handle_mmap64(addr, length, prot, flags, fd, offset); + return handle_exceptions([&]() { + return context.handle_mmap64(addr, length, prot, flags, fd, + offset); + }); } extern "C" void *mmap(void *addr, size_t length, int prot, int flags, int fd, - off_t offset) + off_t offset) { SPDLOG_DEBUG("mmap {:x}", (uintptr_t)addr); - return context.handle_mmap(addr, length, prot, flags, fd, offset); + return handle_exceptions([&]() { + return context.handle_mmap(addr, length, prot, flags, fd, + offset); + }); +} + +extern "C" int munmap(void *addr, size_t size) +{ + return handle_exceptions([&]() { + return context.handle_munmap(addr, size); + }); } extern "C" int close(int fd) { SPDLOG_DEBUG("Closing fd {}", fd); - return context.handle_close(fd); + return handle_exceptions([&]() { return context.handle_close(fd); }); } #if __linux__ @@ -82,27 +116,26 @@ extern "C" long syscall(long sysno, ...) va_end(args); if (sysno == __NR_bpf) { SPDLOG_DEBUG("SYS_BPF {} {} {} {} {} {}", arg1, arg2, arg3, - arg4, arg5, arg6); + arg4, arg5, arg6); int cmd = (int)arg1; auto attr = (union bpf_attr *)(uintptr_t)arg2; auto size = (size_t)arg3; - return context.handle_sysbpf(cmd, attr, size); + return handle_exceptions([&]() { + return context.handle_sysbpf(cmd, attr, size); + }); } else if (sysno == __NR_perf_event_open) { SPDLOG_DEBUG("SYS_PERF_EVENT_OPEN {} {} {} {} {} {}", arg1, - arg2, arg3, arg4, arg5, arg6); - return context.handle_perfevent( - (perf_event_attr *)(uintptr_t)arg1, (pid_t)arg2, - (int)arg3, (int)arg4, (unsigned long)arg5); + arg2, arg3, arg4, arg5, arg6); + return handle_exceptions([&]() { + return context.handle_perfevent( + (perf_event_attr *)(uintptr_t)arg1, (pid_t)arg2, + (int)arg3, (int)arg4, (unsigned long)arg5); + }); } else if (sysno == __NR_ioctl) { SPDLOG_DEBUG("SYS_IOCTL {} {} {} {} {} {}", arg1, arg2, arg3, - arg4, arg5, arg6); + arg4, arg5, arg6); } return context.orig_syscall_fn(sysno, arg1, arg2, arg3, arg4, arg5, arg6); } #endif - -extern "C" int munmap(void *addr, size_t size) -{ - return context.handle_munmap(addr, size); -} diff --git a/tools/bpftimetool/README.md b/tools/bpftimetool/README.md index 6ac25996..233239d2 100644 --- a/tools/bpftimetool/README.md +++ b/tools/bpftimetool/README.md @@ -28,21 +28,3 @@ SPDLOG_LEVEL=Debug ~/.bpftime/bpftimetool import /home/yunwei/bpftime/tools/bpft [2023-10-23 19:02:04.956] [info] import handler type bpf_perf_event_handler fd 5 INFO [99712]: Global shm destructed ``` - -## Run program with bpftime - -```console -$ SPDLOG_LEVEL=Debug bpftime start ./example/minimal/victim -[2023-10-23 19:03:26.105] [info] Entering bpftime agent -[2023-10-23 19:03:26.106] [info] Global shm constructed. shm_open_type 1 for bpftime_maps_shm -[2023-10-23 19:03:26.106] [info] Initializing agent.. -[2023-10-23 19:03:26][info][99986] Executable path: /home/yunwei/bpftime/example/minimal/victim -[2023-10-23 19:03:26][info][99986] Attached 1 uprobe programs to function 5590e1d41169 -[2023-10-23 19:03:26][info][99986] Attach successfully -target_func called. -target_func -target_func called. -target_func -target_func called. -target_func -``` \ No newline at end of file diff --git a/vm/compat/include/bpftime_vm_compat.hpp b/vm/compat/include/bpftime_vm_compat.hpp index cb178f5b..2e94af72 100644 --- a/vm/compat/include/bpftime_vm_compat.hpp +++ b/vm/compat/include/bpftime_vm_compat.hpp @@ -41,7 +41,7 @@ class bpftime_vm_impl { */ virtual bool toggle_bounds_check(bool enable) { - SPDLOG_WARN("Not implemented yet: toggle_bounds_check"); + SPDLOG_DEBUG("Not implemented yet: toggle_bounds_check"); return false; } /**