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

@@ -29,3 +29,6 @@ jobs:
 
     - name: build benchmarks
       run:  make -C benchmark
+
+    # - name: run benchmarks
+    #   run:  cd benchmark && python3 run_benchmark.py

.gitignore

@@ -49,3 +49,5 @@ third_party/frida
 third_party/phaole
 third_party/phaole1
 output_metrics.json
+perf.data
+perf.data.old

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;
 	}
 

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;

benchmark/.gitignore

@@ -1,2 +1,3 @@
 test
-micro-bench
+micro-bench
+benchmark-output.json

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}'))

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

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())

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");

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;
 	}

runtime/src/bpftime_prog.cpp

@@ -18,18 +18,17 @@ using namespace std;
 namespace bpftime
 {
 
-
 thread_local std::optional<uint64_t> current_thread_bpf_cookie;
 
-
 bpftime_prog::bpftime_prog(const struct ebpf_inst *insn, size_t insn_cnt,
 			   const char *name)
 	: name(name)
 {
 	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<uint8_t> &buf) {
+int bpftime_prog::load_aot_object(const std::vector<uint8_t> &buf)
+{
 	ebpf_jit_fn res = ebpf_load_aot_object(vm, buf.data(), buf.size());
 	if (res == nullptr) {
 		SPDLOG_ERROR("Failed to load aot object");

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)

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 <typename F, typename... Args>
+auto handle_exceptions(F &&f, Args &&...args) noexcept
+	-> decltype(f(std::forward<Args>(args)...))
+{
+	try {
+		return f(std::forward<Args>(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);
-}