Your Environment

• Version: 1.8
• Affected Component: Access Gateway
• Affected Subcomponent: AMF
• Deployment Environment: bare-metal and VM

Describe the Issue

AGW is seeing a REG_REQ of type MOBILITY UPDATING REGISTRATION TYPE sometimes. But AGW is not sending any response back.
After this SERVICE_REQUEST message is received on the AGW, but no response is sent to this as well.
As a result UE stops working and there is continuous state of SERVICE_REQUEST and no response happening.

To Reproduce

While we are running overnight traffic, we see this issue sometimes. UE is in ACTIVE state as continuous traffic is going. Do not know what is the trigger, but once this is seen, everything stops.

Expected behavior

It is expected that AGW would respond back to REG_REQUEST and Service_REQ messages. It should either ACCEPT or REJCT it

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

019720 Thu Feb 16 14:44:43 2023 7FC670A90700 DEBUG MME-AP tasks/mme_app/mme_app_state_mana:0094 Inside get_state with read_from_db 0
019721 Thu Feb 16 14:45:11 2023 7FC669929700 DEBUG UTIL tasks/grpc_service/S1apServiceIm:0043 Received GetENBState GRPC request
019722 Thu Feb 16 14:45:21 2023 7FC6680A0700 DEBUG SCTP tasks/sctp/sctp_itti_messaging.c:0100 Ppid NGAP in sctp_itti_send_new_message_ind
019723 Thu Feb 16 14:45:21 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_SCTP] id:[113] name:[SCTP_DATA_IND]
019724 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 729.
019725 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0074 Entering ngap_amf_handle_initial_ue_message()
019726 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0080 Received NGAP INITIAL_UE_MESSAGE GNB_UE_NGAP_ID 27
019727 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0093 New Initial UE message received with gNB UE NGAP ID: 27
019728 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0195 NGAP_FIND_PROTOCOLIE_BY_ID: /home/radtonics/Documents/code/rt401_debug/rt-core/lte/gateway/c/core/oai/tasks/ngap/ngap_amf_nas_procedures.c 195: Optional ie is NULL
019729 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_itti_messagi:0097 Entering ngap_amf_itti_ngap_initial_ue_message()
019730 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_itti_messagi:0127 Leaving ngap_amf_itti_ngap_initial_ue_message()
019731 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0237 Leaving ngap_amf_handle_initial_ue_message() (rc=0)
019732 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_main.cpp :0063 Received msg from :[TASK_NGAP] id:[88] name:[NGAP_INITIAL_UE_MESSAGE]
019733 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0326 INITIAL UE Message: Valid amf_set_id and S-TMSI received
019734 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019735 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0233 Construct GUTI using S-TMSI received form UE and AMG set Id and pointerPLMN id from AMF Conf: 228d6900, 4 0
019736 Thu Feb 16 14:45:21 2023 7FC670279700 ERROR AMF-AP tasks/amf/amf_app_handler.cpp :0355 AMF_APP_INITAIL_UE_MESSAGE: gnb_ngap_id_key 70373039144985 has valid value
019737 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_msg.cpp :0049 [240650000100002] Sending UE Context Release Cmd to NGAP for (ue_id = 25)
UE Context Release Cause = (1)
019738 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_client_servicer.cp:0031 Sending msg to :[TASK_NGAP] id: [85]-[NGAP_UE_CONTEXT_RELEASE_COMMAND]
019739 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0446 UE context request received: 1

019740 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_client_servicer.cp:0031 Sending msg to :[TASK_NGAP] id: [136]-[AMF_APP_NGAP_AMF_UE_ID_NOTIFICATION]
019741 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0461 Sending NAS Establishment Indication to NAS for ue_id = (26)
019742 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0421 epd:7e, security_header_type:1, message_authentication_code:165a2890, sequence_number:19
019743 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0984 M5G_NAS_SECURITY_ALGORITHMS_5G_IA2 dir UPLINK count.seq_num 25 count 25
019744 Thu Feb 16 14:45:21 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0065 Byte length: 99, Zero bits: 0:
019746 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019745 Thu Feb 16 14:45:21 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0067 m: (99 bytes) 00 00 00 19 08 00 00 00 19 7e 00 41 12 00 0b f2 42 f0 56 50 01 01 22 8d 69 00 2e 04 f0 70 f0 70 71 00 40 7e 00 41 12 00 0b f2 42 f0 56 50 01 01 22 8d 69 00 10 01 03 2e 04 f0 70 f0 70 2f 02 01 01 52 42 f0 56 00 00 01 17 07 f0 70 c0 40 19 80 b0 40 02 02 00 50 02 02 00 18 01 01 74 00 00 90 53 01 01
019747 Thu Feb 16 14:45:21 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0068 Key: (16 bytes) b9 f9 59 f9 37 f2 b1 e9 ea c3 ed e7 51 c0 3c 0a
019748 Thu Feb 16 14:45:21 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_AMF_APP] id:[85] name:[NGAP_UE_CONTEXT_RELEASE_COMMAND]
019750 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 1604.
019749 Thu Feb 16 14:45:21 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0070 Message: (91 bytes) 19 7e 00 41 12 00 0b f2 42 f0 56 50 01 01 22 8d 69 00 2e 04 f0 70 f0 70 71 00 40 7e 00 41 12 00 0b f2 42 f0 56 50 01 01 22 8d 69 00 10 01 03 2e 04 f0 70 f0 70 2f 02 01 01 52 42 f0 56 00 00 01 17 07 f0 70 c0 40 19 80 b0 40 02 02 00 50 02 02 00 18 01 01 74 00 00 90 53 01 01
019751 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1173 Entering ngap_handle_ue_context_release_command()
019752 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1079 Entering ngap_amf_generate_ue_context_release_command()
019753 Thu Feb 16 14:45:21 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0079 Out: (16 bytes) 16 5a 28 90 48 29 e1 26 e0 2e c1 ae e9 78 9c ed
019754 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0057 Entering ngap_amf_encode_pdu()
019755 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :1005 M5G_NAS_SECURITY_ALGORITHMS_5G_IA2 returned MAC 16.5a.28.90(2418563606) for length 91direction 0, count 25
019756 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0088 Entering ngap_amf_encode_initiating()
019757 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0730 No decryption of message length 90according to security header type 0x01
019758 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0113 Leaving ngap_amf_encode_initiating() (rc=0)
019759 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0092 Decoding AMF Message Header
019760 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0078 Leaving ngap_amf_encode_pdu() (rc=0)
019761 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0097 EPD = 0x7E, SecurityHeader = 0x0, MessageType = 0x41
019763 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0048 Header Decoded successfully
019762 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1625 Entering ngap_amf_release_ue_context()
019764 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1627 [240650000100002] Releasing UE Context for UE id25
019766 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1644 [240650000100002] Removed NGAP UE 25
019765 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0049 EPD = 0x7E, SecurityHeader = 0x0, MessageType = 0x41
019767 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0153 Decoding AMF message : REG_REQUEST
019769 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0235 Removing UE state for IMSI 000000000000000
019768 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0189 [REG_REQUEST] Msg plain decode bytes[0-94]
7e 01 16 5a 28 90 19 7e 00 41 12 00 0b f2 42 f0
56 50 01 01 22 8d 69 00 2e 04 f0 70 f0 70 71 00
40 7e 00 41 12 00 0b f2 42 f0 56 50 01 01 22 8d
69 00 10 01 03 2e 04 f0 70 f0 70 2f 02 01 01 52
42 f0 56 00 00 01 17 07 f0 70 c0 40 19 80 b0 40
02 02 00 50 02 02 00 18 01 01 74 00 00 90 53 01
01

019771 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/nas5g_message.cpp :0195 Decoded msg(nas5g) id: [41]-name [REG_REQUEST]

019774 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_recv.cpp :0289 Received registration type MOBILITY UPDATING REGISTRATION TYPE
019775 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1648 Leaving ngap_amf_release_ue_context()
019776 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1161 Leaving ngap_amf_generate_ue_context_release_command() (rc=0)
019777 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1200 Leaving ngap_handle_ue_context_release_command() (rc=0)
019778 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019779 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0163 IMSI table to proto
019780 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019781 Thu Feb 16 14:45:21 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_AMF_APP] id:[136] name:[AMF_APP_NGAP_AMF_UE_ID_NOTIFICATION]
019782 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP include/state_manager.hpp :0156 Finished writing state
019783 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 4567.
019784 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0896 Entering ngap_handle_amf_ue_id_notification()
019785 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_main.cpp :0063 Received msg from :[TASK_NGAP] id:[86] name:[NGAP_UE_CONTEXT_RELEASE_COMPLETE]
019786 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0918 Associated sctp_assoc_id 5, gnb_ue_ngap_id 27, amf_ue_ngap_id 26:HASH_TABLE_OK
019788 Thu Feb 16 14:45:21 2023 7FC66B986700 TRACE AMF-AP tasks/ngap/ngap_amf_nas_procedur:0924 Leaving ngap_handle_amf_ue_id_notification()
019787 Thu Feb 16 14:45:21 2023 7FC670279700 WARNI AMF-AP tasks/amf/amf_app_ue_context.cpp:0363 amf_ue_ngap_id 25does not exist
019789 Thu Feb 16 14:45:21 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_handler.cpp :1404 Received UE context release complete message for ue_id: 25
019791 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019790 Thu Feb 16 14:45:21 2023 7FC670279700 ERROR AMF-AP tasks/amf/amf_app_handler.cpp :1410 UE context doesn't exist for ue_id 25
019792 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0316 State PLMN 240.65 to proto
019793 Thu Feb 16 14:45:21 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019794 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP include/state_manager.hpp :0208 Finished writing UE state for IMSI 240650000100002
019795 Thu Feb 16 14:45:21 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0163 IMSI table to proto
019796 Thu Feb 16 14:45:22 2023 7FC667868700 DEBUG SCTP tasks/sctp/sctp_itti_messaging.c:0100 Ppid NGAP in sctp_itti_send_new_message_ind
019797 Thu Feb 16 14:45:22 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_SCTP] id:[113] name:[SCTP_DATA_IND]
019798 Thu Feb 16 14:45:22 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 994.
019799 Thu Feb 16 14:45:22 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1213 Entering ngap_amf_handle_ue_context_release_complete()
019800 Thu Feb 16 14:45:22 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1233 UE Context Release commplete: Ng context cleared. Ignore message for ueid 25
019801 Thu Feb 16 14:45:22 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1238 Leaving ngap_amf_handle_ue_context_release_complete() (rc=0)
019802 Thu Feb 16 14:45:22 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019803 Thu Feb 16 14:45:29 2023 7FC6680A0700 DEBUG SCTP tasks/sctp/sctp_itti_messaging.c:0100 Ppid NGAP in sctp_itti_send_new_message_ind
019804 Thu Feb 16 14:45:29 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_SCTP] id:[113] name:[SCTP_DATA_IND]
019805 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 654.
019806 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0074 Entering ngap_amf_handle_initial_ue_message()
019807 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0080 Received NGAP INITIAL_UE_MESSAGE GNB_UE_NGAP_ID 28
019808 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0093 New Initial UE message received with gNB UE NGAP ID: 28
019809 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0195 NGAP_FIND_PROTOCOLIE_BY_ID: /home/radtonics/Documents/code/rt401_debug/rt-core/lte/gateway/c/core/oai/tasks/ngap/ngap_amf_nas_procedures.c 195: Optional ie is NULL
019810 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_itti_messagi:0097 Entering ngap_amf_itti_ngap_initial_ue_message()
019811 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_itti_messagi:0127 Leaving ngap_amf_itti_ngap_initial_ue_message()
019812 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0237 Leaving ngap_amf_handle_initial_ue_message() (rc=0)
019813 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_main.cpp :0063 Received msg from :[TASK_NGAP] id:[88] name:[NGAP_INITIAL_UE_MESSAGE]
019814 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0326 INITIAL UE Message: Valid amf_set_id and S-TMSI received
019815 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019816 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0233 Construct GUTI using S-TMSI received form UE and AMG set Id and pointerPLMN id from AMF Conf: 228d6900, 4 0
019817 Thu Feb 16 14:45:29 2023 7FC670279700 ERROR AMF-AP tasks/amf/amf_app_handler.cpp :0355 AMF_APP_INITAIL_UE_MESSAGE: gnb_ngap_id_key 70373039144987 has valid value
019818 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_msg.cpp :0049 [240650000100002] Sending UE Context Release Cmd to NGAP for (ue_id = 26)
UE Context Release Cause = (1)
019819 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_client_servicer.cp:0031 Sending msg to :[TASK_NGAP] id: [85]-[NGAP_UE_CONTEXT_RELEASE_COMMAND]
019820 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0446 UE context request received: 1

019821 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_client_servicer.cp:0031 Sending msg to :[TASK_NGAP] id: [136]-[AMF_APP_NGAP_AMF_UE_ID_NOTIFICATION]
019822 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :0461 Sending NAS Establishment Indication to NAS for ue_id = (27)
019823 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0421 epd:7e, security_header_type:1, message_authentication_code:cfdab90, sequence_number:1a
019824 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0984 M5G_NAS_SECURITY_ALGORITHMS_5G_IA2 dir UPLINK count.seq_num 26 count 26
019825 Thu Feb 16 14:45:29 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0065 Byte length: 46, Zero bits: 0:
019826 Thu Feb 16 14:45:29 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0067 m: (46 bytes) 00 00 00 1a 08 00 00 00 1a 7e 00 4c 11 00 07 f4 01 01 22 8d 69 00 71 00 15 7e 00 4c 11 00 07 f4 01 01 22 8d 69 00 40 02 02 00 50 02 02 00
019827 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019828 Thu Feb 16 14:45:29 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0068 Key: (16 bytes) b9 f9 59 f9 37 f2 b1 e9 ea c3 ed e7 51 c0 3c 0a
019829 Thu Feb 16 14:45:29 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0070 Message: (38 bytes) 1a 7e 00 4c 11 00 07 f4 01 01 22 8d 69 00 71 00 15 7e 00 4c 11 00 07 f4 01 01 22 8d 69 00 40 02 02 00 50 02 02 00
019830 Thu Feb 16 14:45:29 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_AMF_APP] id:[85] name:[NGAP_UE_CONTEXT_RELEASE_COMMAND]
019832 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 755.
019831 Thu Feb 16 14:45:29 2023 7FC670279700 TRACE NAS lib/secu/nas_stream_eia2.c :0079 Out: (16 bytes) 0c fd ab 90 be 12 a0 0a d1 6f 8e f5 33 bd 11 d2
019833 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1173 Entering ngap_handle_ue_context_release_command()
019834 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :1005 M5G_NAS_SECURITY_ALGORITHMS_5G_IA2 returned MAC c.fd.ab.90(2427190540) for length 38direction 0, count 26
019835 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1079 Entering ngap_amf_generate_ue_context_release_command()
019836 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0730 No decryption of message length 37according to security header type 0x01
019837 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0057 Entering ngap_amf_encode_pdu()
019838 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0092 Decoding AMF Message Header
019839 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0088 Entering ngap_amf_encode_initiating()
019840 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0097 EPD = 0x7E, SecurityHeader = 0x0, MessageType = 0x4C
019841 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0048 Header Decoded successfully
019843 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0049 EPD = 0x7E, SecurityHeader = 0x0, MessageType = 0x4C
019842 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0113 Leaving ngap_amf_encode_initiating() (rc=0)
019844 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS5G tasks/nas5g/src/AmfMessage.cpp :0153 Decoding AMF message : M5G_SERVICE_REQUEST
019845 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_encoder.c :0078 Leaving ngap_amf_encode_pdu() (rc=0)
019846 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/nas5g_message.cpp :0189 [M5G_SERVICE_REQUEST] Msg plain decode bytes[0-40]
7e 01 0c fd ab 90 1a 7e 00 4c 11 00 07 f4 01 01
22 8d 69 00 71 00 15 7e 00 4c 11 00 07 f4 01 01
22 8d 69 00 40 02 02 00 50 02 02 00
019847 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1625 Entering ngap_amf_release_ue_context()
019848 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/nas5g_message.cpp :0195 Decoded msg(nas5g) id: [4c]-name [M5G_SERVICE_REQUEST]
019849 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1627 [240650000100002] Releasing UE Context for UE id26
019850 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_recv.cpp :0056 Received TMSI in message : 228d6900
019851 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1644 [240650000100002] Removed NGAP UE 26
019852 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS-AM tasks/amf/amf_recv.cpp :0074 TMSI stored in AMF CONTEXT 228d6900
019853 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS-AM tasks/amf/amf_recv.cpp :0076 TMSI received 228d6900
019854 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0235 Removing UE state for IMSI 000000000000000
019855 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS-AM tasks/amf/amf_recv.cpp :0079 TMSI matched for UE ID 27 receved TMSI 228D6900 stored TMSI 228D6900

019859 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1648 Leaving ngap_amf_release_ue_context()
019861 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1161 Leaving ngap_amf_generate_ue_context_release_command() (rc=0)
019860 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS-AM tasks/amf/amf_recv.cpp :0113 Service request type is Data
019862 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1200 Leaving ngap_handle_ue_context_release_command() (rc=0)
019863 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG NAS-AM tasks/amf/amf_recv.cpp :0167 Sending session request to SMF on service request forimsi 240650000100002 sessionid 1
019864 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019865 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_smf_send.cpp :0871 Notification gRPC filled with IMSI 240650000100002 and ue_state_idle is set to true
019866 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019867 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0163 IMSI table to proto
019868 Thu Feb 16 14:45:29 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_AMF_APP] id:[136] name:[AMF_APP_NGAP_AMF_UE_ID_NOTIFICATION]
019869 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 3105.
019870 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0896 Entering ngap_handle_amf_ue_id_notification()
019871 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP include/state_manager.hpp :0156 Finished writing state
019872 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0918 Associated sctp_assoc_id 5, gnb_ue_ngap_id 28, amf_ue_ngap_id 27:HASH_TABLE_OK
019873 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE AMF-AP tasks/ngap/ngap_amf_nas_procedur:0924 Leaving ngap_handle_amf_ue_id_notification()
019874 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_main.cpp :0063 Received msg from :[TASK_NGAP] id:[86] name:[NGAP_UE_CONTEXT_RELEASE_COMPLETE]
019875 Thu Feb 16 14:45:29 2023 7FC670279700 WARNI AMF-AP tasks/amf/amf_app_ue_context.cpp:0363 amf_ue_ngap_id 26does not exist
019876 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019877 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_handler.cpp :1404 Received UE context release complete message for ue_id: 26
019878 Thu Feb 16 14:45:29 2023 7FC670279700 ERROR AMF-AP tasks/amf/amf_app_handler.cpp :1410 UE context doesn't exist for ue_id 26
019879 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0316 State PLMN 240.65 to proto
019880 Thu Feb 16 14:45:29 2023 7FC667868700 DEBUG SCTP tasks/sctp/sctp_itti_messaging.c:0100 Ppid NGAP in sctp_itti_send_new_message_ind
019882 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP include/state_manager.hpp :0208 Finished writing UE state for IMSI 240650000100002
019881 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP include/state_manager.hpp :0156 Finished writing state
019883 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_state_converte:0163 IMSI table to proto
019884 Thu Feb 16 14:45:29 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_SCTP] id:[113] name:[SCTP_DATA_IND]
019885 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 1013.
019886 Thu Feb 16 14:45:29 2023 7FC6602FA700 INFO UTIL tasks/grpc_service/AmfServiceImp:0066 Received GRPC SetSmNotificationContext request
019887 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP include/state_manager.hpp :0156 Finished writing state
019888 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1213 Entering ngap_amf_handle_ue_context_release_complete()
019889 Thu Feb 16 14:45:29 2023 7FC6602FA700 INFO UTIL tasks/grpc_service/amf_service_h:0042 Sending itti_n11_create_pdu_session_response to AMF
019890 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_handlers.c :1233 UE Context Release commplete: Ng context cleared. Ignore message for ueid 0
019891 Thu Feb 16 14:45:29 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_handlers.c :1238 Leaving ngap_amf_handle_ue_context_release_complete() (rc=0)
019892 Thu Feb 16 14:45:29 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_state_converter.:0226 Writing Ngap_Supported TAI list at index 0
019893 Thu Feb 16 14:45:29 2023 7FC670279700 INFO AMF-AP tasks/amf/amf_app_main.cpp :0063 Received msg from :[TASK_GRPC_SERVICE] id:[177] name:[N11_NOTIFICATION_RECEIVED]
019894 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :1569 IMSI is 240650000100002 240650000100002
019895 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :1629 Service Accept notification received
019896 Thu Feb 16 14:45:29 2023 7FC670279700 DEBUG AMF-AP tasks/amf/amf_app_handler.cpp :1632 default case nothing to do
019897 Thu Feb 16 14:45:40 2023 7FC6680A0700 DEBUG SCTP tasks/sctp/sctp_itti_messaging.c:0100 Ppid NGAP in sctp_itti_send_new_message_ind
019898 Thu Feb 16 14:45:40 2023 7FC66B986700 INFO NGAP tasks/ngap/ngap_amf.c :0084 Received msg from :[TASK_SCTP] id:[113] name:[SCTP_DATA_IND]
019899 Thu Feb 16 14:45:40 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf.c :0094 NGAP ZMQ latency: 543.
019900 Thu Feb 16 14:45:40 2023 7FC66B986700 TRACE NGAP tasks/ngap/ngap_amf_nas_procedur:0074 Entering ngap_amf_handle_initial_ue_message()
019901 Thu Feb 16 14:45:40 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0080 Received NGAP INITIAL_UE_MESSAGE GNB_UE_NGAP_ID 29
019902 Thu Feb 16 14:45:40 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0093 New Initial UE message received with gNB UE NGAP ID: 29
019903 Thu Feb 16 14:45:40 2023 7FC66B986700 DEBUG NGAP tasks/ngap/ngap_amf_nas_procedur:0195 NGAP_FIND_PROTOCOLIE_BY_ID: /home/radtonics/Documents/code/rt401_debug/rt-core/lte/gateway/c/core/oai/tasks/ngap/ngap_amf_nas_procedures.c 195: Optional ie is NULL