gfwleak/stellar-stellar
Archived
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Added session debugger module for debugging session messages

Browse Source
This commit is contained in:
luwenpeng
2024-09-29 16:50:25 +08:00
parent 9e954386fd
commit c5d7208c11
15 changed files with 370 additions and 340 deletions
Download Patch File Download Diff File Expand all files Collapse all files

6
infra/packet_manager/packet_manager.c
View File

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

9
infra/session_manager/session_manager.c
View File

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

22
infra/session_manager/session_manager_runtime.c
View File

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

1
infra/session_manager/session_manager_runtime.h
View File

@@ -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__)

2
test/CMakeLists.txt
View File

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

8
test/debug_plugin/CMakeLists.txt
View File

@@ -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/)

4
test/debug_plugin/conf/spec.toml
View File

@@ -1,4 +0,0 @@
[[plugin]]
path = "./plugin/libdebug_plugin.so"
init = "debug_plugin_init"
exit = "debug_plugin_exit"

300
test/debug_plugin/debug_plugin.c
View File

@@ -1,300 +0,0 @@
#include <fcntl.h>
#include <errno.h>
#include <unistd.h>
#include <stdarg.h>
#include <pthread.h>
#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);
}
}

7
test/debug_plugin/version.map
View File

@@ -1,7 +0,0 @@
DEBUG_PLUGIN {
global:
debug_plugin_init;
debug_plugin_exit;
local: *;
};

8
test/session_debugger/CMakeLists.txt Normal file
View File

@@ -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 ./)

328
test/session_debugger/session_debugger.c Normal file
View File

@@ -0,0 +1,328 @@
#include <fcntl.h>
#include <errno.h>
#include <unistd.h>
#include <stdarg.h>
#include <assert.h>
#include <limits.h>
#include <pthread.h>
#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);
}
}

4
test/session_debugger/spec.toml Normal file
View File

@@ -0,0 +1,4 @@
[[module]]
path = "./module/libsession_debugger.so"
init = "session_debugger_on_init"
exit = "session_debugger_on_exit"

7
test/session_debugger/version.map Normal file
View File

@@ -0,0 +1,7 @@
LIBSESSION_DEBUGGER {
global:
session_debugger_on_init;
session_debugger_on_exit;
local: *;
};