去除无用的debug日志; 增加对send_to_tfe失败的处理

This commit is contained in:
崔一鸣
2019-06-18 18:29:06 +08:00
parent 7e3ae597c4
commit 08c5a43054
3 changed files with 45 additions and 39 deletions

View File

@@ -40,6 +40,7 @@ enum stream_error{
STREAM_ERROR_IPV6HDR_PARSE_FAIL = -8,
STREAM_ERROR_DUP_STREAM = -9,
STREAM_ERROR_EXCEED_MTU = -10,
STREAM_ERROR_SENDTO_TFE_FAIL = -11,
};
struct http_project{
@@ -188,6 +189,8 @@ static char* stream_errmsg_get(enum stream_error _errno){
return (char*)"ipv6 header parse fail";
case STREAM_ERROR_EXCEED_MTU:
return (char*)"exceed mtu(1500)";
case STREAM_ERROR_SENDTO_TFE_FAIL:
return (char*)"sendto_tfe_fail";
default:
return (char*)"unknown error";
}
@@ -372,13 +375,13 @@ static void judge_pme_destroy(struct pme_info *pmeinfo, int caller){
void *logger = g_kni_handle->local_logger;
pthread_mutex_lock(&(pmeinfo->lock));
if(caller == CALLER_SAPP){
KNI_LOG_DEBUG(logger, "set sapp_release = 1, caller is %d, stream_trace_id is %s, thread id is %p",
caller, pmeinfo->stream_traceid, pthread_self());
//KNI_LOG_DEBUG(logger, "set sapp_release = 1, caller is %d, stream_trace_id is %s, thread id is %p",
// caller, pmeinfo->stream_traceid, pthread_self());
pmeinfo->sapp_release = 1;
}
if(caller == CALLER_TFE){
KNI_LOG_DEBUG(logger, "set tfe_release = 1, caller is %d, stream_trace_id is %s, thread id is %p",
caller, pmeinfo->stream_traceid, pthread_self());
//KNI_LOG_DEBUG(logger, "set tfe_release = 1, caller is %d, stream_trace_id is %s, thread id is %p",
// caller, pmeinfo->stream_traceid, pthread_self());
pmeinfo->tfe_release = 1;
}
if(pmeinfo->sapp_release == 1 && pmeinfo->tfe_release == 1){
@@ -389,7 +392,7 @@ static void judge_pme_destroy(struct pme_info *pmeinfo, int caller){
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_SENDLOG_FAIL], 0, FS_OP_ADD, 1);
}
else{
KNI_LOG_DEBUG(logger, "Succeed sendlog to kafka, stream traceid is %s", pmeinfo->stream_traceid);
KNI_LOG_INFO(logger, "Succeed sendlog to kafka, stream traceid is %s", pmeinfo->stream_traceid);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_SENDLOG_SUCC], 0, FS_OP_ADD, 1);
}
//only intercetp stream need del htable
@@ -404,8 +407,8 @@ static void judge_pme_destroy(struct pme_info *pmeinfo, int caller){
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_ID2PME_DEL_FAIL], 0, FS_OP_ADD, 1);
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, key is %s, key_size is %d",
"traceid2pme_htable", pmeinfo->stream_traceid, key_size);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, key is %s, key_size is %d",
// "traceid2pme_htable", pmeinfo->stream_traceid, key_size);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_ID2PME_DEL_SUCC], 0, FS_OP_ADD, 1);
}
//del keepalive_replay_htable
@@ -430,8 +433,8 @@ static void judge_pme_destroy(struct pme_info *pmeinfo, int caller){
"keepalive_replay_htable", stream_addr, ret);
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, stream addr is %s, dir is c2s",
"keepalive_replay_htable", stream_addr);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, stream addr is %s, dir is c2s",
// "keepalive_replay_htable", stream_addr);
}
//s2c
if(pmeinfo->addr_type == ADDR_TYPE_IPV6){
@@ -459,15 +462,15 @@ static void judge_pme_destroy(struct pme_info *pmeinfo, int caller){
"keepalive_replay_htable", stream_addr, ret);
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, stream addr is %s, dir is s2c",
"keepalive_replay_htable", stream_addr);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at del, table is %s, stream addr is %s, dir is s2c",
// "keepalive_replay_htable", stream_addr);
}
}
//free pme
pme_info_destroy(pmeinfo);
return;
}
KNI_LOG_DEBUG(logger, "can not destroy pmeinfo, sapp_release = %d, tfe_release = %d", pmeinfo->sapp_release, pmeinfo->tfe_release);
//KNI_LOG_DEBUG(logger, "can not destroy pmeinfo, sapp_release = %d, tfe_release = %d", pmeinfo->sapp_release, pmeinfo->tfe_release);
pthread_mutex_unlock(&(pmeinfo->lock));
}
else{
@@ -715,7 +718,7 @@ static int wrapped_kni_header_parse(const void *a_packet, struct pme_info *pmein
}
static char pending_opstate(const struct streaminfo *stream, struct pme_info *pmeinfo, const void *a_packet){
void *logger = g_kni_handle->local_logger;
//void *logger = g_kni_handle->local_logger;
struct pkt_info pktinfo;
int ret = wrapped_kni_header_parse(a_packet, pmeinfo, &pktinfo);
if(ret < 0){
@@ -723,7 +726,7 @@ static char pending_opstate(const struct streaminfo *stream, struct pme_info *pm
}
if(!pktinfo.tcphdr->syn){
//pending_opstate not syn, bypass and dropme
KNI_LOG_DEBUG(logger, "pending opstate: not syn, stream traceid is %s", pmeinfo->stream_traceid);
//KNI_LOG_DEBUG(logger, "pending opstate: not syn, stream traceid is %s", pmeinfo->stream_traceid);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_NO_SYN_EXP], 0, FS_OP_ADD, 1);
pmeinfo->error = STREAM_ERROR_PENDING_NO_SYN;
return APP_STATE_FAWPKT | APP_STATE_DROPME;
@@ -761,8 +764,8 @@ static int first_data_intercept(const struct streaminfo *stream, struct pme_info
return APP_STATE_FAWPKT | APP_STATE_DROPME;
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add, table is keepalive_replay_htable, "
"dir is c2s, key is %s, key_size is %d", stream_addr, key_size);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add, table is keepalive_replay_htable, "
// "dir is c2s, key is %s, key_size is %d", stream_addr, key_size);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_KEEPALIVE_REPLAY_ADD_SUCC], 0, FS_OP_ADD, 1);
}
//s2c
@@ -793,8 +796,8 @@ static int first_data_intercept(const struct streaminfo *stream, struct pme_info
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_KEEPALIVE_REPLAY_ADD_FAIL], 0, FS_OP_ADD, 1);
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add, table is keepalive_replay_htable, "
"dir is s2c, key is %s, key_size is %d", stream_addr, key_size);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add, table is keepalive_replay_htable, "
// "dir is s2c, key is %s, key_size is %d", stream_addr, key_size);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_KEEPALIVE_REPLAY_ADD_SUCC], 0, FS_OP_ADD, 1);
}
@@ -808,22 +811,26 @@ static int first_data_intercept(const struct streaminfo *stream, struct pme_info
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_ID2PME_ADD_FAIL], 0, FS_OP_ADD, 1);
}
else{
KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add,"
"table is traceid2pme_htable, key is %s", pmeinfo->stream_traceid);
//KNI_LOG_DEBUG(logger, "MESA_htable: Succeed at add,"
// "table is traceid2pme_htable, key is %s", pmeinfo->stream_traceid);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_ID2PME_ADD_SUCC], 0, FS_OP_ADD, 1);
}
//action = KNI_ACTION_INTERCEPT, sendto tfe
int len = 0;
char *buf = add_cmsg_to_packet(pmeinfo, pktinfo, &len);
ret = send_to_tfe(g_kni_handle->marsio_handle, buf, len, thread_seq, pmeinfo->tfe_id, pmeinfo->addr_type);
char *buff = add_cmsg_to_packet(pmeinfo, pktinfo, &len);
ret = send_to_tfe(g_kni_handle->marsio_handle, buff, len, thread_seq, pmeinfo->tfe_id, pmeinfo->addr_type);
if(ret < 0){
KNI_LOG_ERROR(logger, "Failed at send first packet to tfe%d, stream traceid is %s", pmeinfo->tfe_id, pmeinfo->stream_traceid);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_SENDTO_TFE_FAIL], 0, FS_OP_ADD, 1);
pmeinfo->error = STREAM_ERROR_SENDTO_TFE_FAIL;
FREE(&buff);
return APP_STATE_FAWPKT | APP_STATE_DROPME;
}
else{
KNI_LOG_DEBUG(logger, "Succeed at send first packet to tfe%d, stream traceid is %s", pmeinfo->tfe_id, pmeinfo->stream_traceid);
}
FREE(&buf);
FREE(&buff);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_INTCP_PKT], 0, FS_OP_ADD, 1);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_INTCP_STM], 0, FS_OP_ADD, 1);
return APP_STATE_DROPPKT | APP_STATE_GIVEME;
@@ -861,6 +868,7 @@ static char data_opstate(const struct streaminfo *stream, struct pme_info *pmein
ret = send_to_tfe(g_kni_handle->marsio_handle, (char*)a_packet, len, thread_seq, pmeinfo->tfe_id, pmeinfo->addr_type);
if(ret < 0){
KNI_LOG_ERROR(logger, "Failed at send continue packet to tfe%d, stream traceid is %s", pmeinfo->tfe_id, pmeinfo->stream_traceid);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_SENDTO_TFE_FAIL], 0, FS_OP_ADD, 1);
}
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_INTCP_PKT], 0, FS_OP_ADD, 1);
return APP_STATE_DROPPKT | APP_STATE_GIVEME;
@@ -896,7 +904,7 @@ static char data_opstate(const struct streaminfo *stream, struct pme_info *pmein
}
//not double dir, bypass and dropme
if(stream->dir != DIR_DOUBLE){
KNI_LOG_INFO(logger, "dir is %d, bypass, stream addr is %s", stream->dir, stream_addr);
//KNI_LOG_DEBUG(logger, "dir is %d, bypass, stream addr is %s", stream->dir, stream_addr);
pmeinfo->error = STREAM_ERROR_SINGLE_DIR;
return APP_STATE_FAWPKT | APP_STATE_DROPME;
}
@@ -907,7 +915,7 @@ static char data_opstate(const struct streaminfo *stream, struct pme_info *pmein
switch(pmeinfo->protocol){
//can not identify protocol from first data packet, bypass and dropme
case KNI_PROTOCOL_UNKNOWN:
KNI_LOG_INFO(logger, "Failed at protocol_identify, bypass and dropme, stream addr is %s\n",
KNI_LOG_DEBUG(logger, "Failed at protocol_identify, bypass and dropme, stream addr is %s\n",
pmeinfo->protocol, stream_addr);
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_UNKNOWN_STM], 0, FS_OP_ADD, 1);
pmeinfo->error = STREAM_ERROR_PROTOCOL_UNKNOWN;
@@ -928,7 +936,7 @@ static char data_opstate(const struct streaminfo *stream, struct pme_info *pmein
thread_seq, &(pmeinfo->policy_id), &(pmeinfo->maat_hit));
//policy scan log
char *action_str = kni_maat_action_trans(pmeinfo->action);
KNI_LOG_DEBUG(logger, "intercept_policy_scan: %s, %s, policy_id = %d, action = %d(%s), maat_hit = %d, stream traceid is %s",
KNI_LOG_INFO(logger, "intercept_policy_scan: %s, %s, policy_id = %d, action = %d(%s), maat_hit = %d, stream traceid is %s",
stream_addr, protocol_identify_res.domain, pmeinfo->policy_id, pmeinfo->action, action_str, pmeinfo->maat_hit, pmeinfo->stream_traceid);
//receive client hello, but no syn/ack, bypass and dropme
if(pmeinfo->client_tcpopt == NULL || pmeinfo->server_tcpopt == NULL){
@@ -970,7 +978,7 @@ static char close_opstate(const struct streaminfo *stream, struct pme_info *pmei
strnlen(pmeinfo->stream_traceid, sizeof(pmeinfo->stream_traceid)));
return APP_STATE_DROPPKT | APP_STATE_DROPME;
case KNI_ACTION_BYPASS:
KNI_LOG_DEBUG(logger, "action is bypass, set tfe_release = 1, stream_trace_id is %s", pmeinfo->stream_traceid);
//KNI_LOG_DEBUG(logger, "action is bypass, set tfe_release = 1, stream_trace_id is %s", pmeinfo->stream_traceid);
pmeinfo->tfe_release = 1;
return APP_STATE_FAWPKT | APP_STATE_DROPME;
//stream has only syn, ack. no data.
@@ -1196,6 +1204,7 @@ static long keepalive_replay_search_cb(void *data, const uchar *key, uint size,
int ret = send_to_tfe(marsio_handle, replay_packet, tot_len, g_iThreadNum + thread_seq, tfe_id, args->addr_type);
if(ret < 0){
KNI_LOG_ERROR(logger, "Failed at send keepalive replay packet to tfe");
FS_operate(g_kni_fs_handle->handle, g_kni_fs_handle->fields[KNI_FIELD_SENDTO_TFE_FAIL], 0, FS_OP_ADD, 1);
}
value->has_replayed = 1;
marsio_buff_free(marsio_handle->instance, &rx_buff, 1, 0, 0);
@@ -1412,7 +1421,7 @@ static void* thread_tfe_cmsg_receiver(void *args){
KNI_LOG_ERROR(logger, "Failed at recv udp data, errno is %d, %s", errno, strerror(errno));
continue;
}
KNI_LOG_DEBUG(logger, "recv udp data: recv_len is %d\n", recv_len);
//KNI_LOG_DEBUG(logger, "recv udp data: recv_len is %d\n", recv_len);
struct kni_cmsg *cmsg = NULL;
ret = kni_cmsg_deserialize((const unsigned char*)buff, recv_len, &cmsg);
if(ret < 0){
@@ -1632,6 +1641,7 @@ static struct kni_field_stat_handle * fs_init(const char *profile){
fs_handle->fields[KNI_FIELD_KEEPALIVE_REPLAY_ADD_FAIL] = FS_register(handle, FS_STYLE_FIELD, FS_CALC_CURRENT, "kaReplay_add_fail");
fs_handle->fields[KNI_FIELD_KEEPALIVE_REPLAY_ADD_SUCC] = FS_register(handle, FS_STYLE_FIELD, FS_CALC_CURRENT, "kaReplay_add_succ");
fs_handle->fields[KNI_FIELD_EXCEED_MTU] = FS_register(handle, FS_STYLE_FIELD, FS_CALC_CURRENT, "exceed_mtu");
fs_handle->fields[KNI_FIELD_SENDTO_TFE_FAIL] = FS_register(handle, FS_STYLE_FIELD, FS_CALC_CURRENT, "sendto_tfe_fail");
for(int i = 0; i < g_kni_handle->tfe_count; i++){
char tfe_status[KNI_SYMBOL_MAX] = "";
snprintf(tfe_status, sizeof(tfe_status), "tfe%d", i);
@@ -1725,7 +1735,7 @@ extern "C" int kni_init(){
goto error_out;
}
ret = MESA_load_profile_int_def(profile, section, "keepalive_replay_switch", &keepalive_replay_switch, 1);
KNI_LOG_INFO(local_logger, "MESA_prof_load, [%s]:\n log_path: %s\n log_level: %d\n tfe_count: %d\n"
KNI_LOG_ERROR(local_logger, "MESA_prof_load, [%s]:\n log_path: %s\n log_level: %d\n tfe_count: %d\n"
"tfe_data_recv_thread_num: %d\n local_eth: %s\n keepalive_replay_switch: %d",
section, log_path, log_level, tfe_count, tfe_data_recv_thread_num, local_eth, keepalive_replay_switch);
g_kni_handle = ALLOC(struct kni_handle, 1);