From 08c5a43054d863dd64abeb3affa2adf030578a19 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E5=B4=94=E4=B8=80=E9=B8=A3?= Date: Tue, 18 Jun 2019 18:29:06 +0800 Subject: [PATCH] =?UTF-8?q?=E5=8E=BB=E9=99=A4=E6=97=A0=E7=94=A8=E7=9A=84de?= =?UTF-8?q?bug=E6=97=A5=E5=BF=97;=20=E5=A2=9E=E5=8A=A0=E5=AF=B9send=5Fto?= =?UTF-8?q?=5Ftfe=E5=A4=B1=E8=B4=A5=E7=9A=84=E5=A4=84=E7=90=86?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- common/include/kni_utils.h | 14 +++----- entry/src/kni_entry.cpp | 68 ++++++++++++++++++++--------------- entry/src/kni_send_logger.cpp | 2 +- 3 files changed, 45 insertions(+), 39 deletions(-) diff --git a/common/include/kni_utils.h b/common/include/kni_utils.h index bd2f447..756b0a5 100644 --- a/common/include/kni_utils.h +++ b/common/include/kni_utils.h @@ -37,21 +37,15 @@ #define KNI_LOG_ERROR(handler, fmt, ...) \ do { \ - char location[KNI_PATH_MAX]; \ - snprintf(location, KNI_PATH_MAX, "%s: line %d", __FILE__, __LINE__); \ - MESA_handle_runtime_log(handler, RLOG_LV_FATAL, location, fmt, ##__VA_ARGS__); } while(0) + MESA_handle_runtime_log(handler, RLOG_LV_FATAL, "kni", fmt, ##__VA_ARGS__); } while(0) #define KNI_LOG_INFO(handler, fmt, ...) \ do { \ - char location[KNI_PATH_MAX]; \ - snprintf(location, KNI_PATH_MAX, "%s: line %d", __FILE__, __LINE__); \ - MESA_handle_runtime_log(handler, RLOG_LV_INFO, location, fmt, ##__VA_ARGS__); } while(0) + MESA_handle_runtime_log(handler, RLOG_LV_INFO, "kni", fmt, ##__VA_ARGS__); } while(0) #define KNI_LOG_DEBUG(handler, fmt, ...) \ do { \ - char location[KNI_PATH_MAX]; \ - snprintf(location, KNI_PATH_MAX, "%s: line %d", __FILE__, __LINE__); \ - MESA_handle_runtime_log(handler, RLOG_LV_DEBUG, location, fmt, ##__VA_ARGS__); } while(0) + MESA_handle_runtime_log(handler, RLOG_LV_DEBUG, "kni", fmt, ##__VA_ARGS__); } while(0) //default tcp opt @@ -97,6 +91,8 @@ enum kni_field{ KNI_FIELD_KEEPALIVE_REPLAY_ADD_SUCC, KNI_FIELD_KEEPALIVE_REPLAY_ADD_FAIL, KNI_FIELD_EXCEED_MTU, + KNI_FIELD_SENDTO_TFE_FAIL, + //KNI_FIELD_TFE_STATUS_BASE must be last KNI_FIELD_TFE_STATUS_BASE, }; diff --git a/entry/src/kni_entry.cpp b/entry/src/kni_entry.cpp index 79845ef..13e116e 100644 --- a/entry/src/kni_entry.cpp +++ b/entry/src/kni_entry.cpp @@ -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); diff --git a/entry/src/kni_send_logger.cpp b/entry/src/kni_send_logger.cpp index 3ad647c..b43e2eb 100644 --- a/entry/src/kni_send_logger.cpp +++ b/entry/src/kni_send_logger.cpp @@ -99,7 +99,7 @@ struct kni_send_logger* kni_send_logger_init(const char *profile, void *local_lo KNI_LOG_ERROR(local_logger, "MESA_prof_load: kafka_brokerlist not set, profile is %s, section is %s", profile, section); goto error_out; } - KNI_LOG_INFO(local_logger, "MESA_prof_load, [%s]:\n switch: %d\n kafka_topic: %s\n, kafka_brokerlist: %s", + KNI_LOG_ERROR(local_logger, "MESA_prof_load, [%s]:\n switch: %d\n kafka_topic: %s\n, kafka_brokerlist: %s", section, sendlog_switch, kafka_topic, kafka_brokerlist); handle = ALLOC(struct kni_send_logger, 1); handle->local_logger = local_logger;