Fix a LLVMJIT bug (#82)

example/.gitignore

@@ -1,3 +1,4 @@
 simple_uretprobe_test*
 malloc-perf*
 go-trace-test*
+/simple-map-test

runtime/src/bpf_map/shared/array_map_kernel_user.cpp

@@ -52,8 +52,9 @@ void array_map_kernel_user_impl::init_map_fd()
 	// 	return;
 	// }
 	size_t mmap_sz = bpf_map_mmap_sz(_value_size, _max_entries);
-	spdlog::debug("mmap shared array map, fd={}, mmap_sz={}", map_fd,
-		      mmap_sz);
+	spdlog::debug(
+		"mmap shared array map, fd={}, mmap_sz={}, name={}, value_size={}, flags={}",
+		map_fd, mmap_sz, info.name, info.value_size, info.map_flags);
 	mmap_ptr = mmap(NULL, mmap_sz, PROT_READ | PROT_WRITE,
 			MAP_SHARED | MAP_ANONYMOUS, -1, 0);
 	if (mmap_ptr == MAP_FAILED) {
@@ -70,8 +71,9 @@ void array_map_kernel_user_impl::init_map_fd()
 	void *mmaped = mmap(mmap_ptr, mmap_sz, prot, MAP_SHARED | MAP_FIXED,
 			    map_fd, 0);
 	if (mmaped == MAP_FAILED) {
-		spdlog::error("Failed to mmap for kernel map id {}, err={}",
-			      kernel_map_id, errno);
+		spdlog::error(
+			"Failed to re-mmap for kernel map id {}, err={}, prot={}",
+			kernel_map_id, errno, prot);
 		return;
 	}
 	mmap_ptr = mmaped;
@@ -88,13 +90,20 @@ void *array_map_kernel_user_impl::elem_lookup(const void *key)
 	if (map_fd < 0) {
 		init_map_fd();
 	}
+	spdlog::debug("Run lookup of shared array map, key={:x}",
+		      (uintptr_t)key);
 	if (mmap_ptr != nullptr) {
 		auto key_val = *(uint32_t *)key;
+
+		spdlog::debug("mmap handled, key={}", key_val);
 		if (key_val >= _max_entries) {
 			errno = ENOENT;
+			spdlog::debug("Returned ENOENT");
 			return nullptr;
 		}
-		return &((uint8_t *)mmap_ptr)[key_val * _value_size];
+		auto result = &((uint8_t *)mmap_ptr)[key_val * _value_size];
+		spdlog::debug("Returned value addr: {:x}", (uintptr_t)result);
+		return result;
 	}
 	// fallback to read kernel maps
 	int res = bpf_map_lookup_elem(map_fd, key, value_data.data());

runtime/src/bpf_map/shared/array_map_kernel_user.hpp

@@ -17,7 +17,7 @@ class array_map_kernel_user_impl {
 	void init_map_fd();
 
     public:
-	const static bool should_lock = true;
+	const static bool should_lock = false;
 	array_map_kernel_user_impl(boost::interprocess::managed_shared_memory &memory,
 		       int km_id);
 	~array_map_kernel_user_impl();

runtime/src/bpftime_prog.cpp

@@ -72,10 +72,16 @@ int bpftime_prog::bpftime_prog_exec(void *memory, size_t memory_size,
 {
 	uint64_t val = 0;
 	int res = 0;
-
+	spdlog::debug(
+		"Calling bpftime_prog::bpftime_prog_exec, memory={:x}, memory_size={}, return_val={:x}, prog_name={}",
+		(uintptr_t)memory, memory_size, (uintptr_t)return_val,
+		this->name);
 	if (jitted) {
+		spdlog::debug("Directly call jitted function at {:x}",
+			      (uintptr_t)fn);
 		val = fn(memory, memory_size);
 	} else {
+		spdlog::debug("Running using ebpf_exec");
 		res = ebpf_exec(vm, memory, memory_size, &val);
 		if (res < 0) {
 			spdlog::error("ebpf_exec returned error: {}", res);

runtime/src/bpftime_shm.cpp

@@ -384,10 +384,12 @@ const uint64_t INVALID_MAP_PTR = ((uint64_t)0 - 1);
 
 extern "C" uint64_t map_ptr_by_fd(uint32_t fd)
 {
+	spdlog::debug("Call map_ptr_by_fd with fd={}", fd);
 	if (!shm_holder.global_shared_memory.get_manager() ||
 	    !shm_holder.global_shared_memory.is_map_fd(fd)) {
 		errno = ENOENT;
-		spdlog::error("Expected fd {} to be a map fd", fd);
+		spdlog::error("Expected fd {} to be a map fd (map_ptr_by_fd)",
+			      fd);
 		// Here we just ignore the wrong maps
 		return INVALID_MAP_PTR;
 	}
@@ -397,10 +399,12 @@ extern "C" uint64_t map_ptr_by_fd(uint32_t fd)
 
 extern "C" uint64_t map_val(uint64_t map_ptr)
 {
+	spdlog::debug("Call map_val with map_ptr={:x}", map_ptr);
 	int fd = (int)(map_ptr >> 32);
 	if (!shm_holder.global_shared_memory.get_manager() ||
 	    !shm_holder.global_shared_memory.is_map_fd(fd)) {
-		spdlog::error("Expected fd {} to be a map fd", fd);
+		spdlog::error("Expected fd {} to be a map fd (map_val call)",
+			      fd);
 		// here we just ignore the wrong maps
 		errno = ENOENT;
 		return 0;

vm/llvm-jit/src/bpf_jit.cpp

@@ -75,7 +75,7 @@ ebpf_jit_fn bpf_jit_context::compile()
 			spdlog::debug("Defining LDDW helper {} with addr {:x}",
 				      name, (uintptr_t)func);
 			auto sym =
-				JITEvaluatedSymbol::fromPointer(vm->map_by_fd);
+				JITEvaluatedSymbol::fromPointer(func);
 			sym.setFlags(JITSymbolFlags::Callable |
 				     JITSymbolFlags::Exported);
 			lddwSyms.try_emplace(jit->mangleAndIntern(name), sym);

vm/llvm-jit/src/bpf_jit_compile_module.cpp

@@ -624,6 +624,8 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 				      val, (uint64_t)inst.imm,
 				      (uint64_t)nextInst.imm);
 			if (inst.src_reg == 0) {
+				spdlog::debug("Emit lddw helper 0 at pc {}",
+					      pc);
 				builder.CreateStore(builder.getInt64(val),
 						    regs[inst.dst_reg]);
 			} else if (inst.src_reg == 1) {
@@ -632,6 +634,9 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 				    itr != lddwHelper.end())
 
 				{
+					spdlog::debug(
+						"Emit lddw helper 1 (map_by_fd) at pc {}, imm={}",
+						pc, inst.imm);
 					builder.CreateStore(
 						builder.CreateCall(
 							lddwHelperWithUint32,
@@ -668,6 +673,10 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 						builder.CreateStore(
 							finalRet,
 							regs[inst.dst_reg]);
+						spdlog::debug(
+							"Emit lddw helper 2 (map_by_fd + map_val) at pc {}, imm1={}, imm2={}",
+							pc, inst.imm,
+							nextInst.imm);
 					} else {
 						return llvm::make_error<
 							llvm::StringError>(
@@ -692,6 +701,9 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 							{ builder.getInt32(
 								inst.imm) }),
 						regs[inst.dst_reg]);
+					spdlog::debug(
+						"Emit lddw helper 3 (var_addr) at pc {}, imm1={}",
+						pc, inst.imm);
 				} else {
 					return llvm::make_error<
 						llvm::StringError>(
@@ -709,6 +721,9 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 							{ builder.getInt32(
 								inst.imm) }),
 						regs[inst.dst_reg]);
+					spdlog::debug(
+						"Emit lddw helper 4 (code_addr) at pc {}, imm1={}",
+						pc, inst.imm);
 				} else {
 					return llvm::make_error<
 						llvm::StringError>(
@@ -726,6 +741,9 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 							{ builder.getInt32(
 								inst.imm) }),
 						regs[inst.dst_reg]);
+					spdlog::debug(
+						"Emit lddw helper 4 (map_by_idx) at pc {}, imm1={}",
+						pc, inst.imm);
 				} else {
 					return llvm::make_error<
 						llvm::StringError>(
@@ -755,6 +773,10 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 						builder.CreateStore(
 							finalRet,
 							regs[inst.dst_reg]);
+						spdlog::debug(
+							"Emit lddw helper 6 (map_by_idx + map_val) at pc {}, imm1={}, imm2={}",
+							pc, inst.imm,
+							nextInst.imm);
 					} else {
 						return llvm::make_error<
 							llvm::StringError>(
@@ -832,7 +854,7 @@ bpf_jit_context::generateModule(const LLJIT &jit,
 			} else {
 				if (auto exp = emitExtFuncCall(
 					    builder, inst, extFunc, &regs[0],
-					    helperFuncTy);
+					    helperFuncTy, pc);
 				    !exp) {
 					return exp.takeError();
 				}

vm/llvm-jit/src/bpf_jit_helpers.h

@@ -331,12 +331,13 @@ static llvm::Expected<int> emitCondJmpWithDstAndSrc(
 static inline llvm::Expected<int>
 emitExtFuncCall(llvm::IRBuilder<> &builder, const ebpf_inst &inst,
 		const std::map<std::string, llvm::Function *> &extFunc,
-		llvm::Value **regs, llvm::FunctionType *helperFuncTy)
+		llvm::Value **regs, llvm::FunctionType *helperFuncTy,
+		uint16_t pc)
 {
 	auto funcNameToCall = ext_func_sym(inst.imm);
 	if (auto itr = extFunc.find(funcNameToCall); itr != extFunc.end()) {
-		spdlog::debug("Emitting ext func call to {} name {}", inst.imm,
-			      funcNameToCall);
+		spdlog::debug("Emitting ext func call to {} name {} at pc {}",
+			      inst.imm, funcNameToCall, pc);
 		auto callInst = builder.CreateCall(
 			helperFuncTy, itr->second,
 			{

vm/llvm-jit/src/ebpf_vm.cpp

@@ -272,6 +272,8 @@ int ebpf_exec(const struct ebpf_vm *vm, void *mem, size_t mem_len,
 {
 	bpf_jit_context *jit_context;
 	if (vm->jitted_function) {
+		spdlog::debug("LLJIT: called jitted function {:x}",
+			      (uintptr_t)vm->jitted_function);
 		// has jit yet
 		auto ret = vm->jitted_function(mem,
 					       static_cast<uint64_t>(mem_len));
@@ -284,6 +286,7 @@ int ebpf_exec(const struct ebpf_vm *vm, void *mem, size_t mem_len,
 	if (!func) {
 		return -1;
 	}
+	spdlog::debug("LLJIT: compiled function: {:x}", (uintptr_t)func);
 	// after compile, run
 	return ebpf_exec(vm, mem, mem_len, bpf_return_value);
 }