feat: log runtime output to env var "BPFTIME_LOG_OUTPUT"

attach/text_segment_transformer/CMakeLists.txt

@@ -1,6 +1,7 @@
 add_library(bpftime_text_segment_transformer SHARED
     agent-transformer.cpp
     text_segment_transformer.cpp
+    ../../runtime/src/bpftime_logger.cpp
 )
 add_dependencies(bpftime_text_segment_transformer spdlog::spdlog FridaGum)
 set_target_properties(bpftime_text_segment_transformer PROPERTIES CXX_STANDARD 20 OUTPUT_NAME "bpftime-agent-transformer")
@@ -14,4 +15,5 @@ target_include_directories(bpftime_text_segment_transformer
     PRIVATE
     ${FRIDA_GUM_INSTALL_DIR}
     ${SPDLOG_INCLUDE}
+    ../../runtime/include
 )

attach/text_segment_transformer/agent-transformer.cpp

@@ -1,12 +1,8 @@
-#include "spdlog/cfg/env.h"
-#include "spdlog/sinks/stdout_color_sinks.h"
-#include "spdlog/sinks/stdout_sinks.h"
-#include "spdlog/spdlog.h"
 #include <cstdlib>
 #include <dlfcn.h>
 #include <frida-gum.h>
+#include "bpftime_logger.hpp"
 #include "text_segment_transformer.hpp"
-#include <spdlog/cfg/env.h>
 #include <string>
 #include <frida-gum.h>
 
@@ -35,6 +31,7 @@ extern "C" int __libc_start_main(int (*main)(int, char **, char **), int argc,
 				 void (*fini)(void), void (*rtld_fini)(void),
 				 void *stack_end)
 {
+	bpftime::bpftime_set_logger_from_env();
 	injected_with_frida = false;
 	SPDLOG_INFO("Entering bpftime syscal transformer agent");
 	orig_main_func = main;
@@ -47,9 +44,6 @@ extern "C" int __libc_start_main(int (*main)(int, char **, char **), int argc,
 
 extern "C" void bpftime_agent_main(const gchar *data, gboolean *stay_resident)
 {
-	auto logger = spdlog::stderr_color_mt("stderr");
-	spdlog::set_default_logger(logger);
-	spdlog::cfg::load_env_levels();
 	/* We don't want to our library to be unloaded after we return. */
 	*stay_resident = TRUE;
 

runtime/agent/CMakeLists.txt

@@ -1,5 +1,6 @@
 add_library(bpftime-agent SHARED
   agent.cpp
+  ../src/bpftime_logger.cpp
 )
 if(${BPFTIME_BUILD_WITH_LIBBPF})
   add_dependencies(bpftime-agent FridaGum spdlog::spdlog bpftime_frida_uprobe_attach_impl bpftime_syscall_trace_attach_impl)

runtime/agent/agent.cpp

@@ -6,6 +6,9 @@
 #include "spdlog/common.h"
 #include "spdlog/sinks/stdout_color_sinks.h"
 #include "spdlog/sinks/stdout_sinks.h"
+#include "bpftime_logger.hpp"
+#include "syscall_trace_attach_impl.hpp"
+#include "syscall_trace_attach_private_data.hpp"
 #include <chrono>
 #include <csignal>
 #include <exception>
@@ -25,6 +28,7 @@
 #include "syscall_trace_attach_impl.hpp"
 #include "syscall_trace_attach_private_data.hpp"
 #endif
+
 using namespace bpftime;
 using namespace bpftime::attach;
 using main_func_t = int (*)(int, char **, char **);
@@ -94,13 +98,13 @@ static void sig_handler_sigusr1(int sig)
 	shm_holder.global_shared_memory.remove_pid_from_alive_agent_set(
 		getpid());
 	SPDLOG_DEBUG("Detaching done");
+	bpftime_logger_flush();
 }
 
 extern "C" void bpftime_agent_main(const gchar *data, gboolean *stay_resident)
 {
-	auto logger = spdlog::stderr_color_mt("stderr");
-	logger->set_pattern("[%Y-%m-%d %H:%M:%S][%^%l%$][%t] %v");
-	spdlog::set_default_logger(logger);
+	bpftime_set_logger_from_env();
+
 	SPDLOG_DEBUG("Entered bpftime_agent_main");
 	SPDLOG_DEBUG("Registering signal handler");
 	// We use SIGUSR1 to indicate the detaching

runtime/include/bpftime_logger.hpp

@@ -0,0 +1,20 @@
+#include "spdlog/spdlog.h"
+#include "spdlog/cfg/env.h"
+#include "spdlog/sinks/basic_file_sink.h"
+#include "spdlog/sinks/stdout_color_sinks.h"
+
+namespace bpftime {
+
+void bpftime_set_logger_from_env();
+
+/*
+	Set global logger for this process.
+	- "console": Default. Output to stderr. Suggested for temporary debugging.
+	- "syslog": Output to syslog. Suggested for daemon as deployed service.
+	- some file path. Output to file.
+*/
+void bpftime_set_logger(const std::string& target);
+
+void bpftime_logger_flush();
+
+}

runtime/src/bpftime_logger.cpp

@@ -0,0 +1,41 @@
+/* SPDX-License-Identifier: MIT
+ *
+ * Copyright (c) 2022, eunomia-bpf org
+ * All rights reserved.
+ */
+
+#include "bpftime_logger.hpp"
+#include <cstdlib>
+#include <iostream>
+
+void bpftime::bpftime_set_logger_from_env(){
+	const char* _target = std::getenv("BPFTIME_LOG_OUTPUT");
+	if (_target == NULL){
+		bpftime_set_logger("");
+	} else {
+		bpftime_set_logger(std::string(_target));
+	}
+}
+
+void bpftime::bpftime_set_logger(const std::string& target){
+	if (target == "syslog") {
+		throw "Not implemented yet";
+	} else if (target == "console" || target == "") { // Default to be console.
+		spdlog::debug("Set logger to stderr");
+		auto logger = spdlog::stderr_color_mt("stderr");
+		logger->set_pattern("[%Y-%m-%d %H:%M:%S][%^%l%$][%t] %v");
+		logger->flush_on(spdlog::level::info);
+		spdlog::set_default_logger(logger);
+	} else {
+		spdlog::debug("Set logger to file: {}", target);
+		auto logger = spdlog::basic_logger_mt("glogger", target); // Todo. What happens if target invalid || target be wiped?
+		logger->set_pattern("[%Y-%m-%d %H:%M:%S][%^%l%$][%t] %v");
+		logger->flush_on(spdlog::level::info);
+		spdlog::set_default_logger(logger);
+	}
+	spdlog::cfg::load_env_levels();
+}
+
+void bpftime::bpftime_logger_flush(){
+	spdlog::default_logger()->flush();
+}

runtime/syscall-server/CMakeLists.txt

@@ -8,6 +8,7 @@ add_library(bpftime-syscall-server SHARED
     syscall_context.cpp
     syscall_server_main.cpp
     syscall_server_utils.cpp
+    ../src/bpftime_logger.cpp
 )
 target_link_libraries(bpftime-syscall-server PUBLIC
     runtime
@@ -19,6 +20,7 @@ add_dependencies(bpftime-syscall-server spdlog::spdlog)
 if(${BPFTIME_BUILD_WITH_LIBBPF})
 target_include_directories(bpftime-syscall-server
     PUBLIC
+    "../include"
     "../../core"
     "../../third_party/libbpf/include"
     "../../third_party/libbpf/include/uapi"

runtime/syscall-server/syscall_context.cpp

@@ -3,6 +3,8 @@
  * Copyright (c) 2022, eunomia-bpf org
  * All rights reserved.
  */
+#include "bpftime_logger.hpp"
+#include "syscall_context.hpp"
 #include "bpftime_shm.hpp"
 #include "syscall_context.hpp"
 #include "handler/perf_event_handler.hpp"
@@ -32,6 +34,7 @@ using namespace bpftime_epoll;
 
 void syscall_context::load_config_from_env()
 {
+	bpftime::bpftime_set_logger_from_env();
 	const char *run_with_kernel_env = getenv("BPFTIME_RUN_WITH_KERNEL");
 	if (run_with_kernel_env != nullptr) {
 		run_with_kernel = true;

tools/cli/main.cpp

@@ -1,7 +1,6 @@
 #include "bpftime_shm.hpp"
 #include "bpftime_shm_internal.hpp"
-#include "spdlog/spdlog.h"
-#include "spdlog/cfg/env.h"
+#include "bpftime_logger.hpp"
 #include <cerrno>
 #include <csignal>
 #include <cstdlib>
@@ -181,6 +180,7 @@ static void signal_handler(int sig)
 int main(int argc, const char **argv)
 {
 	spdlog::cfg::load_env_levels();
+
 	signal(SIGINT, signal_handler);
 	signal(SIGTSTP, signal_handler);
 	argparse::ArgumentParser program(argv[0]);
@@ -238,6 +238,14 @@ int main(int argc, const char **argv)
 	argparse::ArgumentParser detach_command("detach");
 	detach_command.add_description("Detach all attached agents");
 
+	// TODO. Add trace command here.
+	// argparse::ArgumentParser trace_command("trace");
+
+	// trace_command.add_description("Show bpftime runtime log of some process.");
+	// attach_command.add_argument("-s", "--")
+	// 	.help("Whether to enable syscall trace")
+	// 	.flag();
+
 	program.add_subparser(load_command);
 	program.add_subparser(start_command);
 	program.add_subparser(attach_command);