diff --git a/conf/stellar.toml b/conf/stellar.toml index b71d869..d7d1a01 100644 --- a/conf/stellar.toml +++ b/conf/stellar.toml @@ -81,4 +81,4 @@ exit = "packet_manager_on_exit" [[module]] path = "" init = "session_manager_on_init" -exit = "session_manager_on_exit" \ No newline at end of file +exit = "session_manager_on_exit" diff --git a/infra/packet_io/packet_io.c b/infra/packet_io/packet_io.c index 897f2c9..68b4f12 100644 --- a/infra/packet_io/packet_io.c +++ b/infra/packet_io/packet_io.c @@ -228,7 +228,7 @@ static void packet_io_config_print(const struct packet_io_config *cfg) PACKET_IO_LOG_INFO("packet_io.nr_worker_thread : %d", cfg->nr_worker_thread); for (uint16_t i = 0; i < cfg->nr_worker_thread; i++) { - PACKET_IO_LOG_INFO("packet_io.cpu_mask[%03d] : %d", i, cfg->cpu_mask[i]); + PACKET_IO_LOG_INFO("packet_io.cpu_mask[%03d] : %d", i, cfg->cpu_mask[i]); } PACKET_IO_LOG_INFO("packet_io.idle_yield_interval_ms : %lu", cfg->idle_yield_interval_ms); } diff --git a/infra/packet_manager/packet_manager.c b/infra/packet_manager/packet_manager.c index d9e5305..7e903a6 100644 --- a/infra/packet_manager/packet_manager.c +++ b/infra/packet_manager/packet_manager.c @@ -9,7 +9,7 @@ #define PACKET_MANAGER_LOG_ERROR(format, ...) STELLAR_LOG_ERROR(__thread_local_logger, "packet manager", format, ##__VA_ARGS__) #define PACKET_MANAGER_LOG_DEBUG(format, ...) STELLAR_LOG_DEBUG(__thread_local_logger, "packet manager", format, ##__VA_ARGS__) -#define PACKET_MANAGER_LOG_INFO(format, ...) STELLAR_LOG_WARN(__thread_local_logger, "packet manager", format, ##__VA_ARGS__) +#define PACKET_MANAGER_LOG_FATAL(format, ...) STELLAR_LOG_FATAL(__thread_local_logger, "packet manager", format, ##__VA_ARGS__) TAILQ_HEAD(packet_queue, packet); @@ -468,7 +468,7 @@ struct stellar_module *packet_manager_on_init(struct stellar_module_manager *mod } stellar_module_set_ctx(pkt_mgr_mod, pkt_mgr); - PACKET_MANAGER_LOG_INFO("packet_manager initialized"); + PACKET_MANAGER_LOG_FATAL("packet_manager initialized"); return pkt_mgr_mod; } @@ -480,6 +480,6 @@ void packet_manager_on_exit(struct stellar_module_manager *mod_mgr __attribute__ packet_manager_free(pkt_mgr); stellar_module_free(mod); - PACKET_MANAGER_LOG_INFO("packet_manager exited"); + PACKET_MANAGER_LOG_FATAL("packet_manager exited"); } } \ No newline at end of file diff --git a/infra/session_manager/session_manager.c b/infra/session_manager/session_manager.c index b4a7b17..d150dc9 100644 --- a/infra/session_manager/session_manager.c +++ b/infra/session_manager/session_manager.c @@ -305,6 +305,7 @@ void session_manager_free(struct session_manager *sess_mgr) clean_session(sess_mgr_rt, UINT64_MAX); } + session_manager_runtime_print_stat(sess_mgr_rt); session_manager_runtime_free(sess_mgr->runtime[i]); } @@ -320,7 +321,7 @@ struct session_manager *session_manager_new(struct stellar_polling_manager *poll assert(mq_schema); assert(toml_file); - uint16_t thread_num; + uint64_t thread_num; uint64_t instance_id; uint64_t now_ms = clock_get_real_time_ms(); @@ -354,7 +355,7 @@ struct session_manager *session_manager_new(struct stellar_polling_manager *poll goto error_out; } - sess_mgr->thread_num = thread_num; + sess_mgr->thread_num = (uint16_t)thread_num; for (int i = 0; i < sess_mgr->thread_num; i++) { sess_mgr->cfg->session_id_seed = instance_id << 8 | i; @@ -448,7 +449,7 @@ struct stellar_module *session_manager_on_init(struct stellar_module_manager *mo } stellar_module_set_ctx(sess_mgr_mod, sess_mgr); - SESSION_MANAGER_LOG_INFO("session_manager initialized"); + SESSION_MANAGER_LOG_FATAL("session_manager initialized"); return sess_mgr_mod; } @@ -460,6 +461,6 @@ void session_manager_on_exit(struct stellar_module_manager *mod_mgr __attribute_ session_manager_free(sess_mgr); stellar_module_free(mod); - SESSION_MANAGER_LOG_ERROR("session_manager exited"); + SESSION_MANAGER_LOG_FATAL("session_manager exited"); } } \ No newline at end of file diff --git a/infra/session_manager/session_manager_runtime.c b/infra/session_manager/session_manager_runtime.c index 2ea160c..14a4ed3 100644 --- a/infra/session_manager/session_manager_runtime.c +++ b/infra/session_manager/session_manager_runtime.c @@ -1292,23 +1292,23 @@ void session_manager_runtime_print_stat(struct session_manager_runtime *sess_mgr struct session_manager_stat *stat = &sess_mgr_rt->stat; // TCP session - SESSION_MANAGER_LOG_INFO("TCP session: history=%lu, used=%lu, opening=%lu, active=%lu, closing=%lu, discard=%lu, closed=%lu", - stat->history_tcp_sessions, stat->tcp_sess_used, stat->tcp_sess_opening, stat->tcp_sess_active, + SESSION_MANAGER_LOG_INFO("runtime[%p] => TCP session: history=%lu, used=%lu, opening=%lu, active=%lu, closing=%lu, discard=%lu, closed=%lu", + sess_mgr_rt, stat->history_tcp_sessions, stat->tcp_sess_used, stat->tcp_sess_opening, stat->tcp_sess_active, stat->tcp_sess_closing, stat->tcp_sess_discard, stat->tcp_sess_closed); // UDP session - SESSION_MANAGER_LOG_INFO("UDP session: history=%lu, used=%lu, opening=%lu, active=%lu, closing=%lu, discard=%lu, closed=%lu", - stat->history_udp_sessions, stat->udp_sess_used, stat->udp_sess_opening, stat->udp_sess_active, + SESSION_MANAGER_LOG_INFO("runtime[%p] => UDP session: history=%lu, used=%lu, opening=%lu, active=%lu, closing=%lu, discard=%lu, closed=%lu", + sess_mgr_rt, stat->history_udp_sessions, stat->udp_sess_used, stat->udp_sess_opening, stat->udp_sess_active, stat->udp_sess_closing, stat->udp_sess_discard, stat->udp_sess_closed); // evicted session - SESSION_MANAGER_LOG_INFO("evicted session: TCP=%lu, UDP=%lu", stat->tcp_sess_evicted, stat->udp_sess_evicted); + SESSION_MANAGER_LOG_INFO("runtime[%p] => evicted session: TCP=%lu, UDP=%lu", sess_mgr_rt, stat->tcp_sess_evicted, stat->udp_sess_evicted); // Bypassed packet - SESSION_MANAGER_LOG_INFO("bypassed TCP packet: table_full=%lu, session_not_found=%lu, duplicated=%lu", - stat->tcp_pkts_bypass_table_full, stat->tcp_pkts_bypass_session_not_found, stat->tcp_pkts_bypass_duplicated); - SESSION_MANAGER_LOG_INFO("bypassed UDP packet: table_full=%lu, session_evicted=%lu, duplicated=%lu", - stat->udp_pkts_bypass_table_full, stat->udp_pkts_bypass_session_evicted, stat->udp_pkts_bypass_duplicated); + SESSION_MANAGER_LOG_INFO("runtime[%p] => bypassed TCP packet: table_full=%lu, session_not_found=%lu, duplicated=%lu", + sess_mgr_rt, stat->tcp_pkts_bypass_table_full, stat->tcp_pkts_bypass_session_not_found, stat->tcp_pkts_bypass_duplicated); + SESSION_MANAGER_LOG_INFO("runtime[%p] => bypassed UDP packet: table_full=%lu, session_evicted=%lu, duplicated=%lu", + sess_mgr_rt, stat->udp_pkts_bypass_table_full, stat->udp_pkts_bypass_session_evicted, stat->udp_pkts_bypass_duplicated); // TCP segment - SESSION_MANAGER_LOG_INFO("TCP segment: input=%lu, consumed=%lu, timeout=%lu, retransmited=%lu, overlapped=%lu, omitted_too_many=%lu, inorder=%lu, reordered=%lu, buffered=%lu, freed=%lu", - stat->tcp_segs_input, stat->tcp_segs_consumed, stat->tcp_segs_timeout, stat->tcp_segs_retransmited, + SESSION_MANAGER_LOG_INFO("runtime[%p] => TCP segment: input=%lu, consumed=%lu, timeout=%lu, retransmited=%lu, overlapped=%lu, omitted_too_many=%lu, inorder=%lu, reordered=%lu, buffered=%lu, freed=%lu", + sess_mgr_rt, stat->tcp_segs_input, stat->tcp_segs_consumed, stat->tcp_segs_timeout, stat->tcp_segs_retransmited, stat->tcp_segs_overlapped, stat->tcp_segs_omitted_too_many, stat->tcp_segs_inorder, stat->tcp_segs_reordered, stat->tcp_segs_buffered, stat->tcp_segs_freed); } diff --git a/infra/session_manager/session_manager_runtime.h b/infra/session_manager/session_manager_runtime.h index 5218bcb..c72c959 100644 --- a/infra/session_manager/session_manager_runtime.h +++ b/infra/session_manager/session_manager_runtime.h @@ -8,6 +8,7 @@ extern "C" #include "tuple.h" #include "stellar/session.h" +#define SESSION_MANAGER_LOG_FATAL(format, ...) STELLAR_LOG_FATAL(__thread_local_logger, "session manager", format, ##__VA_ARGS__) #define SESSION_MANAGER_LOG_ERROR(format, ...) STELLAR_LOG_ERROR(__thread_local_logger, "session manager", format, ##__VA_ARGS__) #define SESSION_MANAGER_LOG_DEBUG(format, ...) STELLAR_LOG_DEBUG(__thread_local_logger, "session manager", format, ##__VA_ARGS__) #define SESSION_MANAGER_LOG_INFO(format, ...) STELLAR_LOG_INFO(__thread_local_logger, "session manager", format, ##__VA_ARGS__) diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index 3c972bd..1fdc838 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -1,6 +1,6 @@ #add_subdirectory(packet_inject) add_subdirectory(packet_tool) -#add_subdirectory(debug_plugin) +add_subdirectory(session_debugger) #add_subdirectory(lpi_plugin) #add_subdirectory(decoders/http) #add_subdirectory(decoders/socks) diff --git a/test/debug_plugin/CMakeLists.txt b/test/debug_plugin/CMakeLists.txt deleted file mode 100644 index 707044e..0000000 --- a/test/debug_plugin/CMakeLists.txt +++ /dev/null @@ -1,8 +0,0 @@ -# build libdebug_plugin.so -add_library(debug_plugin SHARED debug_plugin.c) -target_link_libraries(debug_plugin stellar_lib session_manager packet_manager) -target_include_directories(debug_plugin PUBLIC ${CMAKE_SOURCE_DIR}/include/) -target_include_directories(debug_plugin PUBLIC ${CMAKE_SOURCE_DIR}/infra) -set_target_properties(debug_plugin PROPERTIES LINK_FLAGS "-Wl,--version-script=${CMAKE_CURRENT_LIST_DIR}/version.map") - -file(COPY ./conf/ DESTINATION ./conf/) \ No newline at end of file diff --git a/test/debug_plugin/conf/spec.toml b/test/debug_plugin/conf/spec.toml deleted file mode 100644 index 08ecfbf..0000000 --- a/test/debug_plugin/conf/spec.toml +++ /dev/null @@ -1,4 +0,0 @@ -[[plugin]] -path = "./plugin/libdebug_plugin.so" -init = "debug_plugin_init" -exit = "debug_plugin_exit" diff --git a/test/debug_plugin/debug_plugin.c b/test/debug_plugin/debug_plugin.c deleted file mode 100644 index 63e89f9..0000000 --- a/test/debug_plugin/debug_plugin.c +++ /dev/null @@ -1,300 +0,0 @@ -#include -#include -#include -#include -#include - -#include "utils.h" -#include "packet_dump.h" -#include "session_internal.h" -#include "stellar/stellar_mq.h" -#include "stellar/stellar_exdata.h" - -#pragma GCC diagnostic ignored "-Wunused-parameter" - -static void debug_plugin_log(int fd, const char *module, const char *fmt, ...) -{ - static unsigned char weekday_str[7][4] = {"Sun", "Mon", "Tue", "Wed", "Thu", "Fri", "Sat"}; - static unsigned char month_str[12][4] = {"Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec"}; - - int nwrite; - char buf[4096 * 2] = {0}; - char *p = buf; - char *end = buf + sizeof(buf); - va_list args; - struct tm local; - - time_t t; - time(&t); - localtime_r(&t, &local); - - // add time - p += snprintf(p, end - p, "%s %s %d %02d:%02d:%02d %d ", - weekday_str[local.tm_wday], month_str[local.tm_mon], local.tm_mday, local.tm_hour, local.tm_min, local.tm_sec, local.tm_year + 1900); - // add tid - p += snprintf(p, end - p, "%lu ", pthread_self()); - // add module - p += snprintf(p, end - p, "(%s), ", module); - // add content - va_start(args, fmt); - p += vsnprintf(p, end - p, fmt, args); - va_end(args); - // add end of line - p += snprintf(p, end - p, "\n"); - - do - { - nwrite = write(fd, buf, p - buf); - } while (nwrite == -1 && errno == EINTR); -} - -struct plugin_ctx -{ - struct stellar *st; - int sess_exdata_idx; - int sess_plug_id; - int tcp_topic_id; - int udp_topic_id; - int tcp_stream_topic_id; - int fd; - int c2s_tcp_seg_hexdump_fd; - int s2c_tcp_seg_hexdump_fd; - pthread_spinlock_t lock; // for hexdump thread safe -}; - -struct session_exdata -{ - uint64_t c2s_rx_pkts; - uint64_t s2c_rx_pkts; - - uint64_t c2s_rx_bytes; - uint64_t s2c_rx_bytes; - - uint64_t c2s_rx_tcp_seg; - uint64_t s2c_rx_tcp_seg; - - uint64_t c2s_rx_tcp_bytes; - uint64_t s2c_rx_tcp_bytes; - - int c2s_tcp_seg_hexdump_fd; - int s2c_tcp_seg_hexdump_fd; -}; - -static void *on_sess_new(struct session *sess, void *plugin_ctx) -{ - char buff[4096]; - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - struct session_exdata *exdata = (struct session_exdata *)calloc(1, sizeof(struct session_exdata)); - - if (session_get_type(sess) == SESSION_TYPE_TCP) - { - memset(buff, 0, sizeof(buff)); - sprintf(buff, "./log/debug_plugin.log.c2s_segment_%s", session_get0_readable_addr(sess)); - ctx->c2s_tcp_seg_hexdump_fd = open(buff, O_WRONLY | O_APPEND | O_CREAT, 0644); - - memset(buff, 0, sizeof(buff)); - sprintf(buff, "./log/debug_plugin.log.s2c_segment_%s", session_get0_readable_addr(sess)); - ctx->s2c_tcp_seg_hexdump_fd = open(buff, O_WRONLY | O_APPEND | O_CREAT, 0644); - } - session_exdata_set(sess, ctx->sess_exdata_idx, exdata); - - memset(buff, 0, sizeof(buff)); - session_to_str(sess, 1, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "sess new: %s", buff); - - return NULL; -} - -static void on_sess_free(struct session *sess, void *sess_ctx, void *plugin_ctx) -{ - char buff[4096]; - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - struct session_exdata *exdata = (struct session_exdata *)session_exdata_get(sess, ctx->sess_exdata_idx); - - memset(buff, 0, sizeof(buff)); - session_to_str(sess, 0, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "sess free: %s", buff); - debug_plugin_log(ctx->fd, "debug plugin", "session %lu %s stat:\n" - "C2S rx packets: %6lu, C2S rx bytes: %6lu\n" - "S2C rx packets: %6lu, S2C rx bytes: %6lu\n" - "C2S rx TCP segments: %6lu, C2S rx TCP bytes: %6lu\n" - "S2C rx TCP segments: %6lu, S2C rx TCP bytes: %6lu\n", - session_get_id(sess), session_get0_readable_addr(sess), - exdata->c2s_rx_pkts, exdata->c2s_rx_bytes, - exdata->s2c_rx_pkts, exdata->s2c_rx_bytes, - exdata->c2s_rx_tcp_seg, exdata->c2s_rx_tcp_bytes, - exdata->s2c_rx_tcp_seg, exdata->s2c_rx_tcp_bytes); - if (exdata->c2s_tcp_seg_hexdump_fd > 0) - { - close(exdata->c2s_tcp_seg_hexdump_fd); - } - if (exdata->s2c_tcp_seg_hexdump_fd > 0) - { - close(exdata->s2c_tcp_seg_hexdump_fd); - } -} - -static void on_sess_udp_msg(struct session *sess, int topic_id, const void *msg, void *sess_ctx, void *plugin_ctx) -{ - if (msg == NULL) - { - return; - } - - char buff[4096]; - const struct packet *pkt = (const struct packet *)msg; - const struct timeval *tv = packet_get_timeval(pkt); - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - struct session_exdata *exdata = (struct session_exdata *)session_exdata_get(sess, ctx->sess_exdata_idx); - if (session_get_flow_type(sess) == FLOW_TYPE_C2S) - { - exdata->c2s_rx_pkts++; - exdata->c2s_rx_bytes += packet_get_raw_len(pkt); - } - else - { - exdata->s2c_rx_pkts++; - exdata->s2c_rx_bytes += packet_get_raw_len(pkt); - } - - memset(buff, 0, sizeof(buff)); - session_to_str(sess, 1, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "on UDP msg: %s", buff); - - memset(buff, 0, sizeof(buff)); - packet_dump_str(pkt, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "rx UDP packet (tv_sec: %lu, tv_usec: %lu): \n%s", tv->tv_sec, tv->tv_usec, buff); - - pthread_spin_lock(&ctx->lock); - packet_dump_hex(pkt, ctx->fd); - pthread_spin_unlock(&ctx->lock); -} - -static void on_sess_tcp_msg(struct session *sess, int topic_id, const void *msg, void *sess_ctx, void *plugin_ctx) -{ - if (msg == NULL) - { - return; - } - - char buff[4096]; - const struct packet *pkt = (const struct packet *)msg; - const struct timeval *tv = packet_get_timeval(pkt); - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - struct session_exdata *exdata = (struct session_exdata *)session_exdata_get(sess, ctx->sess_exdata_idx); - if (session_get_flow_type(sess) == FLOW_TYPE_C2S) - { - exdata->c2s_rx_pkts++; - exdata->c2s_rx_bytes += packet_get_raw_len(pkt); - } - else - { - exdata->s2c_rx_pkts++; - exdata->s2c_rx_bytes += packet_get_raw_len(pkt); - } - - memset(buff, 0, sizeof(buff)); - session_to_str(sess, 1, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "on TCP msg: %s", buff); - - memset(buff, 0, sizeof(buff)); - packet_dump_str(pkt, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "rx TCP packet (tv_sec: %lu, tv_usec: %lu): \n%s", tv->tv_sec, tv->tv_usec, buff); - - pthread_spin_lock(&ctx->lock); - packet_dump_hex(pkt, ctx->fd); - pthread_spin_unlock(&ctx->lock); -} - -static void on_sess_tcp_stream_msg(struct session *sess, int topic_id, const void *msg, void *sess_ctx, void *plugin_ctx) -{ - if (msg == NULL) - { - return; - } - - char buff[4096]; - const struct tcp_segment *seg = (const struct tcp_segment *)msg; - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - const char *data = tcp_segment_get_data(seg); - uint16_t len = tcp_segment_get_len(seg); - struct session_exdata *exdata = (struct session_exdata *)session_exdata_get(sess, ctx->sess_exdata_idx); - - memset(buff, 0, sizeof(buff)); - session_to_str(sess, 1, buff, sizeof(buff) - 1); - debug_plugin_log(ctx->fd, "debug plugin", "on TCP stream msg: %s", buff); - - pthread_spin_lock(&ctx->lock); - if (session_get_flow_type(sess) == FLOW_TYPE_C2S) - { - debug_plugin_log(ctx->fd, "debug plugin", "rx C2S TCP segment: len: %d, data: %p", len, data); - hexdump_to_fd(ctx->fd, exdata->c2s_rx_tcp_bytes, data, len); - hexdump_to_fd(ctx->c2s_tcp_seg_hexdump_fd, exdata->c2s_rx_tcp_bytes, data, len); - - exdata->c2s_rx_tcp_seg++; - exdata->c2s_rx_tcp_bytes += len; - } - else - { - debug_plugin_log(ctx->fd, "debug plugin", "rx S2C TCP segment: len: %d, data: %p", len, data); - hexdump_to_fd(ctx->fd, exdata->s2c_rx_tcp_bytes, data, len); - hexdump_to_fd(ctx->s2c_tcp_seg_hexdump_fd, exdata->s2c_rx_tcp_bytes, data, len); - - exdata->s2c_rx_tcp_seg++; - exdata->s2c_rx_tcp_bytes += len; - } - pthread_spin_unlock(&ctx->lock); -} - -/****************************************************************************** - * Plugin API - ******************************************************************************/ - -void *debug_plugin_init(struct stellar *st) -{ - struct plugin_ctx *ctx = (struct plugin_ctx *)calloc(1, sizeof(struct plugin_ctx)); - if (ctx == NULL) - { - return NULL; - } - - ctx->fd = open("./log/debug_plugin.log", O_WRONLY | O_APPEND | O_CREAT, 0644); - if (ctx->fd == -1) - { - printf("[debug plugin] open log file failed: %s\n", strerror(errno)); - free(ctx); - return NULL; - } - - pthread_spin_init(&ctx->lock, PTHREAD_PROCESS_PRIVATE); - - ctx->st = st; - ctx->sess_exdata_idx = stellar_exdata_new_index(st, "DEBUG_PLUGIN_SESS_EXDATA", stellar_exdata_free_default, NULL); - ctx->sess_plug_id = stellar_session_plugin_register(st, on_sess_new, on_sess_free, ctx); - ctx->udp_topic_id = stellar_mq_get_topic_id(st, TOPIC_UDP_INPUT); - ctx->tcp_topic_id = stellar_mq_get_topic_id(st, TOPIC_TCP_INPUT); - ctx->tcp_stream_topic_id = stellar_mq_get_topic_id(st, TOPIC_TCP_STREAM); - - stellar_session_mq_subscribe(st, ctx->udp_topic_id, on_sess_udp_msg, ctx->sess_plug_id); - stellar_session_mq_subscribe(st, ctx->tcp_topic_id, on_sess_tcp_msg, ctx->sess_plug_id); - stellar_session_mq_subscribe(st, ctx->tcp_stream_topic_id, on_sess_tcp_stream_msg, ctx->sess_plug_id); - - debug_plugin_log(ctx->fd, "debug plugin", "init"); - - return ctx; -} - -void debug_plugin_exit(void *plugin_ctx) -{ - struct plugin_ctx *ctx = (struct plugin_ctx *)plugin_ctx; - if (ctx) - { - debug_plugin_log(ctx->fd, "debug plugin", "exit"); - if (ctx->fd > 0) - { - close(ctx->fd); - } - pthread_spin_destroy(&ctx->lock); - free(ctx); - } -} \ No newline at end of file diff --git a/test/debug_plugin/version.map b/test/debug_plugin/version.map deleted file mode 100644 index 5e56b52..0000000 --- a/test/debug_plugin/version.map +++ /dev/null @@ -1,7 +0,0 @@ -DEBUG_PLUGIN { -global: - debug_plugin_init; - debug_plugin_exit; - -local: *; -}; \ No newline at end of file diff --git a/test/session_debugger/CMakeLists.txt b/test/session_debugger/CMakeLists.txt new file mode 100644 index 0000000..a8e6e79 --- /dev/null +++ b/test/session_debugger/CMakeLists.txt @@ -0,0 +1,8 @@ +# build libsession_debugger.so +add_library(session_debugger SHARED session_debugger.c) +target_link_libraries(session_debugger stellar_lib session_manager packet_manager) +target_include_directories(session_debugger PUBLIC ${CMAKE_SOURCE_DIR}/include/) +target_include_directories(session_debugger PUBLIC ${CMAKE_SOURCE_DIR}/infra) +set_target_properties(session_debugger PROPERTIES LINK_FLAGS "-Wl,--version-script=${CMAKE_CURRENT_LIST_DIR}/version.map") + +file(COPY spec.toml DESTINATION ./) \ No newline at end of file diff --git a/test/session_debugger/session_debugger.c b/test/session_debugger/session_debugger.c new file mode 100644 index 0000000..a41610c --- /dev/null +++ b/test/session_debugger/session_debugger.c @@ -0,0 +1,328 @@ +#include +#include +#include +#include +#include +#include +#include + +#include "utils.h" +#include "packet_dump.h" +#include "session_internal.h" + +#include "stellar/log.h" +#include "stellar/module_manager.h" +#include "stellar/session_manager.h" + +#pragma GCC diagnostic ignored "-Wunused-parameter" + +struct session_debugger +{ + struct logger *logger; + pthread_spinlock_t lock; // for hexdump thread safe + struct session_manager *sess_mgr; + int fd; + int sess_exdata_idx; +}; + +struct session_debugger_exdata +{ + struct session_debugger *dbg; + struct session *sess; + + uint64_t c2s_rx_pkts; + uint64_t s2c_rx_pkts; + + uint64_t c2s_rx_bytes; + uint64_t s2c_rx_bytes; + + uint64_t c2s_rx_tcp_seg; + uint64_t s2c_rx_tcp_seg; + + uint64_t c2s_rx_tcp_bytes; + uint64_t s2c_rx_tcp_bytes; + + int c2s_tcp_seg_hexdump_fd; + int s2c_tcp_seg_hexdump_fd; +}; + +static void session_debugger_log(int fd, const char *fmt, ...) +{ + static const char *module = "session_debugger"; + static unsigned char weekday_str[7][4] = {"Sun", "Mon", "Tue", "Wed", "Thu", "Fri", "Sat"}; + static unsigned char month_str[12][4] = {"Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec"}; + + int nwrite; + char buf[PATH_MAX * 2] = {0}; + char *p = buf; + char *end = buf + sizeof(buf); + va_list args; + struct tm local; + + time_t t; + time(&t); + localtime_r(&t, &local); + + p += snprintf(p, end - p, "%s %s %d %02d:%02d:%02d %d ", + weekday_str[local.tm_wday], month_str[local.tm_mon], local.tm_mday, local.tm_hour, local.tm_min, local.tm_sec, local.tm_year + 1900); + p += snprintf(p, end - p, "%lu ", pthread_self()); + p += snprintf(p, end - p, "(%s), ", module); + va_start(args, fmt); + p += vsnprintf(p, end - p, fmt, args); + va_end(args); + p += snprintf(p, end - p, "\n"); + + do + { + nwrite = write(fd, buf, p - buf); + } while (nwrite == -1 && errno == EINTR); +} + +static struct session_debugger_exdata *session_debugger_exdata_new(struct session_debugger *dbg, struct session *sess) +{ + char buff[PATH_MAX]; + struct session_debugger_exdata *exdata = (struct session_debugger_exdata *)calloc(1, sizeof(struct session_debugger_exdata)); + + exdata->dbg = dbg; + exdata->sess = sess; + if (session_get_type(sess) == SESSION_TYPE_TCP) + { + memset(buff, 0, sizeof(buff)); + sprintf(buff, "./log/session_debugger.%s_c2s.hexdump", session_get0_readable_addr(sess)); + exdata->c2s_tcp_seg_hexdump_fd = open(buff, O_WRONLY | O_APPEND | O_CREAT, 0644); + + memset(buff, 0, sizeof(buff)); + sprintf(buff, "./log/session_debugger.%s_s2c.hexdump", session_get0_readable_addr(sess)); + exdata->s2c_tcp_seg_hexdump_fd = open(buff, O_WRONLY | O_APPEND | O_CREAT, 0644); + } + + memset(buff, 0, sizeof(buff)); + session_to_str(sess, 1, buff, sizeof(buff) - 1); + session_debugger_log(dbg->fd, "sess new: %s", buff); + + return exdata; +} + +static void session_debugger_exdata_free(struct session_debugger_exdata *exdata) +{ + if (exdata) + { + char buff[PATH_MAX] = {0}; + session_to_str(exdata->sess, 0, buff, sizeof(buff) - 1); + session_debugger_log(exdata->dbg->fd, "sess free: %s", buff); + session_debugger_log(exdata->dbg->fd, "session %lu %s stat:\n" + "C2S rx packets: %6lu, C2S rx bytes: %6lu\n" + "S2C rx packets: %6lu, S2C rx bytes: %6lu\n" + "C2S rx TCP segments: %6lu, C2S rx TCP bytes: %6lu\n" + "S2C rx TCP segments: %6lu, S2C rx TCP bytes: %6lu\n", + session_get_id(exdata->sess), session_get0_readable_addr(exdata->sess), + exdata->c2s_rx_pkts, exdata->c2s_rx_bytes, + exdata->s2c_rx_pkts, exdata->s2c_rx_bytes, + exdata->c2s_rx_tcp_seg, exdata->c2s_rx_tcp_bytes, + exdata->s2c_rx_tcp_seg, exdata->s2c_rx_tcp_bytes); + + if (exdata->c2s_tcp_seg_hexdump_fd > 0) + { + close(exdata->c2s_tcp_seg_hexdump_fd); + } + if (exdata->s2c_tcp_seg_hexdump_fd > 0) + { + close(exdata->s2c_tcp_seg_hexdump_fd); + } + + free(exdata); + } +} + +static void session_debugger_exdata_free_callback(int idx, void *ex_ptr, void *arg) +{ + struct session_debugger *dbg = (struct session_debugger *)arg; + assert(idx == dbg->sess_exdata_idx); + + session_debugger_exdata_free((struct session_debugger_exdata *)ex_ptr); +} + +static void on_sess_msg(struct session *sess, struct packet *pkt, void *args) +{ + struct session_debugger *dbg = (struct session_debugger *)args; + + char buff[PATH_MAX]; + struct session_debugger_exdata *exdata = (struct session_debugger_exdata *)session_get_exdata(sess, dbg->sess_exdata_idx); + if (exdata == NULL) + { + exdata = session_debugger_exdata_new(dbg, sess); + session_set_exdata(sess, dbg->sess_exdata_idx, exdata); + } + + if (session_get_flow_type(sess) == FLOW_TYPE_C2S) + { + exdata->c2s_rx_pkts++; + exdata->c2s_rx_bytes += packet_get_raw_len(pkt); + } + else + { + exdata->s2c_rx_pkts++; + exdata->s2c_rx_bytes += packet_get_raw_len(pkt); + } + + memset(buff, 0, sizeof(buff)); + session_to_str(sess, 1, buff, sizeof(buff) - 1); + session_debugger_log(dbg->fd, "on %s msg: %s", session_type_to_str(session_get_type(sess)), buff); + + memset(buff, 0, sizeof(buff)); + packet_dump_str(pkt, buff, sizeof(buff) - 1); + session_debugger_log(dbg->fd, "rx %s packet\n%s", session_type_to_str(session_get_type(sess)), buff); + + pthread_spin_lock(&dbg->lock); + packet_dump_hex(pkt, dbg->fd); + pthread_spin_unlock(&dbg->lock); +} + +static void on_tcp_stream_msg(struct session *sess, const char *tcp_payload, uint32_t tcp_payload_len, void *args) +{ + struct session_debugger *dbg = (struct session_debugger *)args; + + char buff[PATH_MAX]; + struct session_debugger_exdata *exdata = (struct session_debugger_exdata *)session_get_exdata(sess, dbg->sess_exdata_idx); + + memset(buff, 0, sizeof(buff)); + session_to_str(sess, 1, buff, sizeof(buff) - 1); + session_debugger_log(dbg->fd, "on TCP stream msg: %s", buff); + + pthread_spin_lock(&dbg->lock); + if (session_get_flow_type(sess) == FLOW_TYPE_C2S) + { + session_debugger_log(dbg->fd, "rx C2S TCP segment: len: %d, data: %p", tcp_payload_len, tcp_payload); + hexdump_to_fd(dbg->fd, exdata->c2s_rx_tcp_bytes, tcp_payload, tcp_payload_len); + hexdump_to_fd(exdata->c2s_tcp_seg_hexdump_fd, exdata->c2s_rx_tcp_bytes, tcp_payload, tcp_payload_len); + + exdata->c2s_rx_tcp_seg++; + exdata->c2s_rx_tcp_bytes += tcp_payload_len; + } + else + { + session_debugger_log(dbg->fd, "rx S2C TCP segment: len: %d, data: %p", tcp_payload_len, tcp_payload); + hexdump_to_fd(dbg->fd, exdata->s2c_rx_tcp_bytes, tcp_payload, tcp_payload_len); + hexdump_to_fd(exdata->s2c_tcp_seg_hexdump_fd, exdata->s2c_rx_tcp_bytes, tcp_payload, tcp_payload_len); + + exdata->s2c_rx_tcp_seg++; + exdata->s2c_rx_tcp_bytes += tcp_payload_len; + } + pthread_spin_unlock(&dbg->lock); +} + +static void session_debugger_free(struct session_debugger *dbg) +{ + if (dbg) + { + if (dbg->fd > 0) + { + close(dbg->fd); + } + pthread_spin_destroy(&dbg->lock); + free(dbg); + } +} + +static struct session_debugger *session_debugger_new(struct session_manager *sess_mgr, struct logger *logger) +{ + struct session_debugger *dbg = (struct session_debugger *)calloc(1, sizeof(struct session_debugger)); + if (dbg == NULL) + { + session_debugger_log(STDERR_FILENO, "new failed\n"); + return NULL; + } + + pthread_spin_init(&dbg->lock, PTHREAD_PROCESS_PRIVATE); + + dbg->logger = logger; + dbg->sess_mgr = sess_mgr; + dbg->fd = open("./log/session_debugger.log", O_WRONLY | O_APPEND | O_CREAT, 0644); + if (dbg->fd == -1) + { + session_debugger_log(STDERR_FILENO, "open log file failed: %s\n", strerror(errno)); + goto error_out; + } + + dbg->sess_exdata_idx = session_manager_new_session_exdata_index(dbg->sess_mgr, "DEBUG_MODULE_SESS_EXDATA", session_debugger_exdata_free_callback, dbg); + if (dbg->sess_exdata_idx == -1) + { + session_debugger_log(STDERR_FILENO, "new session exdata index failed\n"); + goto error_out; + } + + if (session_manager_subscribe_tcp(sess_mgr, on_sess_msg, dbg) == -1) + { + session_debugger_log(STDERR_FILENO, "subscribe tcp failed\n"); + goto error_out; + } + if (session_manager_subscribe_udp(sess_mgr, on_sess_msg, dbg) == -1) + { + session_debugger_log(STDERR_FILENO, "subscribe udp failed\n"); + goto error_out; + } + if (session_manager_subscribe_control_packet(sess_mgr, on_sess_msg, dbg) == -1) + { + session_debugger_log(STDERR_FILENO, "subscribe control packet failed\n"); + goto error_out; + } + if (session_manager_subscribe_tcp_stream(sess_mgr, on_tcp_stream_msg, dbg) == -1) + { + session_debugger_log(STDERR_FILENO, "subscribe tcp stream failed\n"); + goto error_out; + } + + return dbg; + +error_out: + session_debugger_free(dbg); + return NULL; +} + +/****************************************************************************** + * Plugin API + ******************************************************************************/ + +struct stellar_module *session_debugger_on_init(struct stellar_module_manager *mod_mgr) +{ + assert(mod_mgr); + + struct stellar_module *sess_mgr_mod = stellar_module_manager_get_module(mod_mgr, SESSION_MANAGER_MODULE_NAME); + assert(sess_mgr_mod); + struct session_manager *sess_mgr = stellar_module_get_ctx(sess_mgr_mod); + assert(sess_mgr); + struct logger *logger = stellar_module_manager_get_logger(mod_mgr); + assert(logger); + + struct session_debugger *dbg = session_debugger_new(sess_mgr, logger); + if (dbg == NULL) + { + return NULL; + } + + struct stellar_module *dbg_mod = stellar_module_new("session_debugger", NULL); + if (dbg_mod == NULL) + { + session_debugger_free(dbg); + return NULL; + } + stellar_module_set_ctx(dbg_mod, dbg); + + STELLAR_LOG_FATAL(dbg->logger, "session_debugger", "session_debugger initialized") + + return dbg_mod; +} + +void session_debugger_on_exit(struct stellar_module_manager *mod_mgr, struct stellar_module *mod) +{ + if (mod) + { + struct session_debugger *dbg = stellar_module_get_ctx(mod); + if (dbg) + { + STELLAR_LOG_FATAL(dbg->logger, "session_debugger", "session_debugger exited") + session_debugger_free(dbg); + } + stellar_module_free(mod); + } +} \ No newline at end of file diff --git a/test/session_debugger/spec.toml b/test/session_debugger/spec.toml new file mode 100644 index 0000000..19a4a9b --- /dev/null +++ b/test/session_debugger/spec.toml @@ -0,0 +1,4 @@ +[[module]] +path = "./module/libsession_debugger.so" +init = "session_debugger_on_init" +exit = "session_debugger_on_exit" diff --git a/test/session_debugger/version.map b/test/session_debugger/version.map new file mode 100644 index 0000000..66edc94 --- /dev/null +++ b/test/session_debugger/version.map @@ -0,0 +1,7 @@ +LIBSESSION_DEBUGGER { +global: + session_debugger_on_init; + session_debugger_on_exit; + +local: *; +}; \ No newline at end of file