From 0dd2ad6557e28d6c47bbf578243db1733790eff9 Mon Sep 17 00:00:00 2001 From: Sukchan Lee Date: Tue, 27 Feb 2024 21:16:50 +0900 Subject: [PATCH] [MME] Added log messages to find memory problem --- lib/sctp/ogs-sctp.c | 12 ++---- src/mme/emm-handler.c | 8 ++-- src/mme/emm-sm.c | 2 +- src/mme/esm-handler.c | 6 +-- src/mme/esm-sm.c | 2 +- src/mme/mme-context.c | 6 +-- src/mme/mme-context.h | 77 +++++++++++++++++---------------------- src/mme/mme-gtp-path.c | 2 + src/mme/mme-s11-build.c | 5 +++ src/mme/mme-s11-handler.c | 13 +++++-- src/mme/mme-sm.c | 2 +- src/mme/s1ap-handler.c | 14 ++++--- 12 files changed, 74 insertions(+), 75 deletions(-) diff --git a/lib/sctp/ogs-sctp.c b/lib/sctp/ogs-sctp.c index 4cd46989d..c91d144d8 100644 --- a/lib/sctp/ogs-sctp.c +++ b/lib/sctp/ogs-sctp.c @@ -43,14 +43,10 @@ int ogs_sctp_recvdata(ogs_sock_t *sock, void *msg, size_t len, } else if (flags & MSG_EOR) { break; } else { - if (ogs_socket_errno != OGS_EAGAIN) { - ogs_fatal("ogs_sctp_recvmsg(%d) failed(%d:%s-0x%x)", - size, errno, strerror(errno), flags); - ogs_assert_if_reached(); - } else { - ogs_error("ogs_sctp_recvmsg(%d) failed(%d:%s-0x%x)", - size, errno, strerror(errno), flags); - } + ogs_fatal("ogs_sctp_recvmsg(%d) failed(%d:%s-0x%x)", + size, errno, strerror(errno), flags); + ogs_fatal("Probably MME might be crashed"); + ogs_assert_if_reached(); } } while(1); diff --git a/src/mme/emm-handler.c b/src/mme/emm-handler.c index 82059c814..7fbaecb90 100644 --- a/src/mme/emm-handler.c +++ b/src/mme/emm-handler.c @@ -54,9 +54,9 @@ int emm_handle_attach_request(mme_ue_t *mme_ue, char imsi_bcd[OGS_MAX_IMSI_BCD_LEN+1]; - MME_UE_LIST_CHECK; - ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); + enb_ue = enb_ue_cycle(mme_ue->enb_ue); ogs_assert(enb_ue); @@ -270,9 +270,9 @@ int emm_handle_attach_complete( struct tm gmt, local; ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_info(" IMSI[%s]", mme_ue->imsi_bcd); - MME_UE_LIST_CHECK; ogs_gettimeofday(&tv); ogs_gmtime(tv.tv_sec, &gmt); @@ -823,7 +823,7 @@ int emm_handle_security_mode_complete(mme_ue_t *mme_ue, ogs_nas_mobile_identity_t *imeisv = &security_mode_complete->imeisv; ogs_assert(mme_ue); - MME_UE_LIST_CHECK; + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); if (security_mode_complete->presencemask & OGS_NAS_EPS_SECURITY_MODE_COMMAND_IMEISV_REQUEST_PRESENT) { diff --git a/src/mme/emm-sm.c b/src/mme/emm-sm.c index 29e737e94..55d51ce9b 100644 --- a/src/mme/emm-sm.c +++ b/src/mme/emm-sm.c @@ -933,6 +933,7 @@ void emm_state_authentication(ogs_fsm_t *s, mme_event_t *e) mme_ue = e->mme_ue; ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); switch (e->id) { case OGS_FSM_ENTRY_SIG: @@ -954,7 +955,6 @@ void emm_state_authentication(ogs_fsm_t *s, mme_event_t *e) authentication_response_parameter; ogs_debug("Authentication response"); - MME_UE_LIST_CHECK; ogs_debug(" IMSI[%s]", mme_ue->imsi_bcd); CLEAR_MME_UE_TIMER(mme_ue->t3460); diff --git a/src/mme/esm-handler.c b/src/mme/esm-handler.c index e8b34f26e..0f5bf377f 100644 --- a/src/mme/esm-handler.c +++ b/src/mme/esm-handler.c @@ -36,13 +36,12 @@ int esm_handle_pdn_connectivity_request(mme_bearer_t *bearer, mme_sess_t *sess = NULL; uint8_t security_protected_required = 0; - MME_UE_LIST_CHECK; - ogs_assert(bearer); sess = bearer->sess; ogs_assert(sess); mme_ue = sess->mme_ue; ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_assert(req); @@ -182,11 +181,10 @@ int esm_handle_information_response(mme_sess_t *sess, ogs_assert(sess); mme_ue = sess->mme_ue; ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_assert(rsp); - MME_UE_LIST_CHECK; - if (rsp->presencemask & OGS_NAS_EPS_ESM_INFORMATION_RESPONSE_ACCESS_POINT_NAME_PRESENT) { sess->session = mme_session_find_by_apn( diff --git a/src/mme/esm-sm.c b/src/mme/esm-sm.c index 3312159c7..75353d594 100644 --- a/src/mme/esm-sm.c +++ b/src/mme/esm-sm.c @@ -89,6 +89,7 @@ void esm_state_inactive(ogs_fsm_t *s, mme_event_t *e) ogs_assert(sess); mme_ue = sess->mme_ue; ogs_assert(mme_ue); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); switch (e->id) { case OGS_FSM_ENTRY_SIG: @@ -183,7 +184,6 @@ void esm_state_inactive(ogs_fsm_t *s, mme_event_t *e) break; case OGS_NAS_EPS_ACTIVATE_DEFAULT_EPS_BEARER_CONTEXT_ACCEPT: ogs_debug("Activate default EPS bearer context accept"); - MME_UE_LIST_CHECK; ogs_debug(" IMSI[%s] PTI[%d] EBI[%d]", mme_ue->imsi_bcd, sess->pti, bearer->ebi); /* Check if Initial Context Setup Response or diff --git a/src/mme/mme-context.c b/src/mme/mme-context.c index 7e059d913..b612997ad 100644 --- a/src/mme/mme-context.c +++ b/src/mme/mme-context.c @@ -4394,7 +4394,7 @@ mme_bearer_t *mme_bearer_find_or_add_by_message( sess->mme_ue ? sess->mme_ue->imsi_bcd : "Unknown", sess->mme_ue); } - MME_UE_LIST_CHECK; + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); } if (!sess) { @@ -4408,7 +4408,7 @@ mme_bearer_t *mme_bearer_find_or_add_by_message( ogs_debug("[%s:%p]", sess->mme_ue ? sess->mme_ue->imsi_bcd : "Unknown", sess->mme_ue); - MME_UE_LIST_CHECK; + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); } else { sess->pti = pti; ogs_debug("[%s:%p]", mme_ue->imsi_bcd, mme_ue); @@ -4418,7 +4418,7 @@ mme_bearer_t *mme_bearer_find_or_add_by_message( ogs_debug("[%s:%p]", sess->mme_ue ? sess->mme_ue->imsi_bcd : "Unknown", sess->mme_ue); - MME_UE_LIST_CHECK; + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); } } else { diff --git a/src/mme/mme-context.h b/src/mme/mme-context.h index 11606364d..dcfb8f1ae 100644 --- a/src/mme/mme-context.h +++ b/src/mme/mme-context.h @@ -148,52 +148,43 @@ typedef struct mme_context_s { #define MME_UE_CHECK(level, __mME) \ do { \ - ogs_log_message(level, 0, "IMSI [%s] NAS-EPS Type[%d]", \ - (__mME) ? (__mME)->imsi_bcd : "No MME_UE", \ - (__mME) ? (__mME)->nas_eps.type : 0); \ - ogs_log_message(level, 0, "mme_ue[%p:%p]", \ + sgw_ue_t *__sGW = (((mme_ue_t *)__mME)->sgw_ue); \ + mme_sess_t *__sESS = NULL; \ + mme_bearer_t *__bEARER = NULL; \ + \ + ogs_log_message(level, 0, "MME-UE Context Memory[%p:%p]", \ (__mME), mme_ue_cycle((__mME))); \ + ogs_log_message(level, 0, "SGW-UE Context Memory[%p:%p]", \ + (__sGW), sgw_ue_cycle((__sGW))); \ + ogs_log_message(level, 0, \ + "IMSI [%s] NAS-EPS Type[%d]", \ + (__mME) ? ((mme_ue_t *)__mME)->imsi_bcd : "No MME_UE", \ + (__mME) ? ((mme_ue_t *)__mME)->nas_eps.type : 0); \ + ogs_log_message(level, 0, \ + "MME_S11_TEID[%d] SGW_S11_TEID[%d]", \ + (__mME) ? ((mme_ue_t *)__mME)->mme_s11_teid : 0, \ + (__sGW) ? (__sGW)->sgw_s11_teid : 0); \ + if (!mme_ue_cycle(__mME)) { \ + ogs_log_message(level, 0, \ + "MME-UE Context has already been removed"); \ + break; \ + } \ + ogs_list_for_each(&((mme_ue_t *)__mME)->sess_list, (__sESS)) { \ + ogs_log_message(level, 0, "SESS(%p) [%s:%d]", (__sESS), \ + (__sESS)->session ? (__sESS)->session->name : "Unknown", \ + (__sESS)->pti); \ + ogs_list_for_each(&(__sESS)->bearer_list, (__bEARER)) { \ + ogs_log_message(level, 0, \ + "BEARER(%p) [%d] ENB_S1U_TEID[%d] SGW_S1U_TEID[%d]", \ + (__bEARER), (__bEARER)->ebi, \ + (__bEARER)->enb_s1u_teid, (__bEARER)->sgw_s1u_teid); \ + ogs_assert((__bEARER)->sess == (__sESS)); \ + ogs_assert((__bEARER)->mme_ue == (__mME)); \ + } \ + ogs_assert((__sESS)->mme_ue == (__mME)); \ + } \ } while(0) -#define MME_UE_LIST_CHECK \ - if (ogs_log_get_domain_level(OGS_LOG_DOMAIN) >= OGS_LOG_TRACE) { \ - mme_ue_t *mme_ue = NULL; \ - sgw_ue_t *sgw_ue = NULL; \ - enb_ue_t *enb_ue = NULL; \ - mme_sess_t *sess = NULL; \ - mme_bearer_t *bearer = NULL; \ - ogs_list_for_each(&mme_self()->mme_ue_list, mme_ue) { \ - ogs_trace("MME_UE(%p:%p) [%s] MME_S11_TEID[%d]", \ - mme_ue, mme_ue_cycle(mme_ue), \ - mme_ue->imsi_bcd, mme_ue->mme_s11_teid); \ - if (mme_ue->sgw_ue) { \ - sgw_ue = mme_ue->sgw_ue; \ - ogs_trace("SGW_UE(%p) MME_UE(%p) SGW_S11_TEID[%d]", \ - sgw_ue, mme_ue, sgw_ue->sgw_s11_teid); \ - } \ - if (mme_ue->enb_ue) { \ - enb_ue = mme_ue->enb_ue; \ - ogs_trace("ENB_UE(%p) MME_UE(%p) " \ - "[ENB_UE_S1AP_ID:%d MME_UE_S1AP_ID:%d]", \ - enb_ue, enb_ue->mme_ue, \ - enb_ue->enb_ue_s1ap_id, enb_ue->mme_ue_s1ap_id); \ - } \ - ogs_list_for_each(&mme_ue->sess_list, sess) { \ - ogs_trace("SESS(%p) [%s:%d]", sess, \ - sess->session ? sess->session->name : "Unknown", \ - sess->pti); \ - ogs_assert(sess->mme_ue == mme_ue); \ - ogs_list_for_each(&sess->bearer_list, bearer) { \ - ogs_trace("BEARER(%p) [%d] " \ - "ENB_S1U_TEID[%d] SGW_S1U_TEID[%d]", \ - bearer, bearer->ebi, \ - bearer->enb_s1u_teid, bearer->sgw_s1u_teid); \ - ogs_assert(bearer->sess == sess); \ - ogs_assert(bearer->mme_ue == mme_ue); \ - } \ - } \ - } \ - } ogs_list_t mme_ue_list; ogs_hash_t *enb_addr_hash; /* hash table for ENB Address */ diff --git a/src/mme/mme-gtp-path.c b/src/mme/mme-gtp-path.c index 9a9b0b0a4..7d9e8f3f3 100644 --- a/src/mme/mme-gtp-path.c +++ b/src/mme/mme-gtp-path.c @@ -347,6 +347,7 @@ int mme_gtp_send_delete_session_request( } xact->delete_action = action; xact->local_teid = mme_ue->gn.mme_gn_teid; + ogs_debug("delete_session_request - xact:%p, sess:%p", xact, sess); rv = ogs_gtp_xact_commit(xact); ogs_expect(rv == OGS_OK); @@ -364,6 +365,7 @@ void mme_gtp_send_delete_all_sessions(mme_ue_t *mme_ue, int action) ogs_assert(sgw_ue); ogs_assert(action); + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_list_for_each_safe(&mme_ue->sess_list, next_sess, sess) { if (MME_HAVE_SGW_S1U_PATH(sess)) { mme_gtp_send_delete_session_request(sgw_ue, sess, action); diff --git a/src/mme/mme-s11-build.c b/src/mme/mme-s11-build.c index 731eaa1e7..2101130ad 100644 --- a/src/mme/mme-s11-build.c +++ b/src/mme/mme-s11-build.c @@ -479,14 +479,19 @@ ogs_pkbuf_t *mme_s11_build_delete_session_request( mme_bearer_t *bearer = NULL; mme_ue_t *mme_ue = NULL; + sgw_ue_t *sgw_ue = NULL; ogs_assert(sess); mme_ue = sess->mme_ue; ogs_assert(mme_ue); + sgw_ue = mme_ue->sgw_ue; + ogs_assert(sgw_ue); bearer = mme_default_bearer_in_sess(sess); ogs_assert(bearer); ogs_debug("Delete Session Request"); + ogs_debug(" MME_S11_TEID[%d] SGW_S11_TEID[%d]", + mme_ue->mme_s11_teid, sgw_ue->sgw_s11_teid); memset(>p_message, 0, sizeof(ogs_gtp2_message_t)); diff --git a/src/mme/mme-s11-handler.c b/src/mme/mme-s11-handler.c index 7e50f2df5..04b448da0 100644 --- a/src/mme/mme-s11-handler.c +++ b/src/mme/mme-s11-handler.c @@ -103,7 +103,6 @@ void mme_s11_handle_create_session_response( ogs_assert(rsp); ogs_debug("Create Session Response"); - MME_UE_LIST_CHECK; /******************** * Check Transaction @@ -112,6 +111,8 @@ void mme_s11_handle_create_session_response( create_action = xact->create_action; sess = xact->data; ogs_assert(sess); + + MME_UE_CHECK(OGS_LOG_DEBUG, sess->mme_ue); mme_ue = mme_ue_cycle(sess->mme_ue); rv = ogs_gtp_xact_commit(xact); @@ -480,13 +481,14 @@ void mme_s11_handle_modify_bearer_response( ogs_assert(rsp); ogs_debug("Modify Bearer Response"); - MME_UE_LIST_CHECK; /******************** * Check Transaction ********************/ ogs_assert(xact); modify_action = xact->modify_action; + + MME_UE_CHECK(OGS_LOG_DEBUG, xact->data); mme_ue = mme_ue_cycle(xact->data); rv = ogs_gtp_xact_commit(xact); @@ -592,7 +594,6 @@ void mme_s11_handle_delete_session_response( ogs_assert(rsp); ogs_debug("Delete Session Response"); - MME_UE_LIST_CHECK; /******************** * Check Transaction @@ -602,6 +603,9 @@ void mme_s11_handle_delete_session_response( ogs_assert(action); sess = xact->data; ogs_assert(sess); + + ogs_debug("delete_session_response - xact:%p, sess:%p", xact, sess); + MME_UE_CHECK(OGS_LOG_DEBUG, sess->mme_ue); mme_ue = mme_ue_cycle(sess->mme_ue); rv = ogs_gtp_xact_commit(xact); @@ -1244,7 +1248,6 @@ void mme_s11_handle_release_access_bearers_response( ogs_assert(rsp); ogs_debug("Release Access Bearers Response"); - MME_UE_LIST_CHECK; /******************** * Check Transaction @@ -1252,6 +1255,8 @@ void mme_s11_handle_release_access_bearers_response( ogs_assert(xact); action = xact->release_action; ogs_assert(action); + + MME_UE_CHECK(OGS_LOG_DEBUG, xact->data); mme_ue = mme_ue_cycle(xact->data); rv = ogs_gtp_xact_commit(xact); diff --git a/src/mme/mme-sm.c b/src/mme/mme-sm.c index b01d91174..dc5b101b3 100644 --- a/src/mme/mme-sm.c +++ b/src/mme/mme-sm.c @@ -255,7 +255,6 @@ void mme_state_operational(ogs_fsm_t *s, mme_event_t *e) mme_ue = mme_ue_find_by_message(&nas_message); if (!mme_ue) { mme_ue = mme_ue_add(enb_ue); - MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); if (mme_ue == NULL) { r = s1ap_send_ue_context_release_command(enb_ue, S1AP_Cause_PR_misc, @@ -267,6 +266,7 @@ void mme_state_operational(ogs_fsm_t *s, mme_event_t *e) return; } + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_assert(ECM_IDLE(mme_ue)); } else { /* Here, if the MME_UE Context is found, diff --git a/src/mme/s1ap-handler.c b/src/mme/s1ap-handler.c index c5cc7ef08..8f2147563 100644 --- a/src/mme/s1ap-handler.c +++ b/src/mme/s1ap-handler.c @@ -404,7 +404,6 @@ void s1ap_handle_initial_ue_message(mme_enb_t *enb, ogs_s1ap_message_t *message) ogs_assert(InitialUEMessage); ogs_info("InitialUEMessage"); - MME_UE_LIST_CHECK; for (i = 0; i < InitialUEMessage->protocolIEs.list.count; i++) { ie = InitialUEMessage->protocolIEs.list.array[i]; @@ -486,6 +485,7 @@ void s1ap_handle_initial_ue_message(mme_enb_t *enb, ogs_s1ap_message_t *message) ogs_info("Unknown UE by S_TMSI[G:%d,C:%d,M_TMSI:0x%x]", nas_guti.mme_gid, nas_guti.mme_code, nas_guti.m_tmsi); } else { + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_info(" S_TMSI[G:%d,C:%d,M_TMSI:0x%x] IMSI:[%s]", mme_ue->current.guti.mme_gid, mme_ue->current.guti.mme_code, @@ -524,13 +524,15 @@ void s1ap_handle_initial_ue_message(mme_enb_t *enb, ogs_s1ap_message_t *message) } else { ogs_error("Known UE ENB_UE_S1AP_ID[%d] [%p:%p]", (int)*ENB_UE_S1AP_ID, enb_ue, enb_ue->mme_ue); - if (enb_ue->mme_ue) + if (enb_ue->mme_ue) { + MME_UE_CHECK(OGS_LOG_DEBUG, enb_ue->mme_ue); ogs_error(" S_TMSI[G:%d,C:%d,M_TMSI:0x%x] IMSI:[%s]", enb_ue->mme_ue->current.guti.mme_gid, enb_ue->mme_ue->current.guti.mme_code, enb_ue->mme_ue->current.guti.m_tmsi, MME_UE_HAVE_IMSI(enb_ue->mme_ue) ? enb_ue->mme_ue->imsi_bcd : "Unknown"); + } } if (!NAS_PDU) { @@ -625,7 +627,6 @@ void s1ap_handle_uplink_nas_transport( ogs_assert(UplinkNASTransport); ogs_debug("UplinkNASTransport"); - MME_UE_LIST_CHECK; for (i = 0; i < UplinkNASTransport->protocolIEs.list.count; i++) { ie = UplinkNASTransport->protocolIEs.list.array[i]; @@ -768,6 +769,7 @@ void s1ap_handle_uplink_nas_transport( if (enb_ue->mme_ue) { mme_ue_t *mme_ue = enb_ue->mme_ue; + MME_UE_CHECK(OGS_LOG_DEBUG, enb_ue->mme_ue); memcpy(&mme_ue->tai, &enb_ue->saved.tai, sizeof(ogs_eps_tai_t)); memcpy(&mme_ue->e_cgi, &enb_ue->saved.e_cgi, sizeof(ogs_e_cgi_t)); mme_ue->ue_location_timestamp = ogs_time_now(); @@ -808,7 +810,6 @@ void s1ap_handle_ue_capability_info_indication( ogs_assert(UECapabilityInfoIndication); ogs_debug("UECapabilityInfoIndication"); - MME_UE_LIST_CHECK; for (i = 0; i < UECapabilityInfoIndication->protocolIEs.list.count; i++) { ie = UECapabilityInfoIndication->protocolIEs.list.array[i]; @@ -874,6 +875,7 @@ void s1ap_handle_ue_capability_info_indication( if (enb_ue->mme_ue) { ogs_assert(UERadioCapability); + MME_UE_CHECK(OGS_LOG_DEBUG, enb_ue->mme_ue); OGS_ASN_STORE_DATA(&enb_ue->mme_ue->ueRadioCapability, UERadioCapability); } @@ -907,7 +909,6 @@ void s1ap_handle_initial_context_setup_response( ogs_assert(InitialContextSetupResponse); ogs_debug("InitialContextSetupResponse"); - MME_UE_LIST_CHECK; for (i = 0; i < InitialContextSetupResponse->protocolIEs.list.count; i++) { ie = InitialContextSetupResponse->protocolIEs.list.array[i]; @@ -978,6 +979,7 @@ void s1ap_handle_initial_context_setup_response( return; } + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); if (E_RABSetupListCtxtSURes) { int uli_presence = 0; @@ -2062,7 +2064,6 @@ void s1ap_handle_e_rab_modification_indication( ogs_assert(E_RABModificationIndication); ogs_info("E_RABModificationIndication"); - MME_UE_LIST_CHECK; for (i = 0; i < E_RABModificationIndication->protocolIEs.list.count; i++) { ie = E_RABModificationIndication->protocolIEs.list.array[i]; @@ -2142,6 +2143,7 @@ void s1ap_handle_e_rab_modification_indication( return; } + MME_UE_CHECK(OGS_LOG_DEBUG, mme_ue); ogs_list_init(&mme_ue->bearer_to_modify_list); for (i = 0; i < E_RABToBeModifiedListBearerModInd->list.count; i++) {