[BUG] Free5GC NGAP handover failure issue.

[sp-l6]

Hello everyone, when I was testing NGAP handover using Free5GC and PacketRusher, I encountered some issues, possibly due to compatibility problems with Free5GC v3.3.0. Or could it be an issue with my configuration? How can I resolve this? I'm very anxious, thank you.The PacketRusher logs are as follows: sudo ./packetrusher multi-ue -n 1 -ngh 13000 --tunnel -dedicatedGnb IINFO[0000] Selecting 172.20.10.10 for host 172.20.10.10 as AMF's IP address INFO[0000] Selecting 172.20.10.8 for host 172.20.10.8 as gNodeB's N3/Data IP address INFO[0000] Selecting 172.20.10.8 for host 172.20.10.8 as gNodeB's N2/Control IP address INFO[0000] Loaded config at: /home/lsp/PacketRusher/config/config.yml INFO[0000] PacketRusher version 1.0.1
INFO[0000] ---------------------------------------
INFO[0000] [TESTER] Starting test function: Testing registration of multiple UEs INFO[0000] [TESTER][UE] Number of UEs: 1
INFO[0000] [TESTER][GNB] gNodeB control interface IP/Port: 172.20.10.8/9487~ INFO[0000] [TESTER][GNB] gNodeB data interface IP/Port: 172.20.10.8/2152 INFO[0000] [TESTER][AMF] AMF IP/Port: 172.20.10.10/38412 INFO[0000] ---------------------------------------
WARN[0000] [TESTER] We are increasing the number of gNodeB to two for handover test cases. Make you sure you fill the requirements for having two gNodeBs. INFO[0000] [GNB] SCTP/NGAP service is running
INFO[0000] [GNB] Initiating NG Setup Request
INFO[0000] [GNB] SCTP/NGAP service is running
INFO[0000] [GNB] Initiating NG Setup Request
INFO[0000] [GNB][SCTP] Receive message in 0 stream
INFO[0000] [GNB][NGAP] Receive NG Setup Response
INFO[0000] [GNB][AMF] AMF Name: AMF
INFO[0000] [GNB][AMF] State of AMF: Active
INFO[0000] [GNB][AMF] Capacity of AMF: 255
INFO[0000] [GNB][AMF] PLMNs Identities Supported by AMF -- mcc: 208 mnc:93 INFO[0000] [GNB][AMF] List of AMF slices Supported by AMF -- sst:01 sd:010203 INFO[0000] [GNB][AMF] List of AMF slices Supported by AMF -- sst:01 sd:112233 INFO[0000] [GNB][SCTP] Receive message in 0 stream
INFO[0000] [GNB][NGAP] Receive NG Setup Response
INFO[0000] [GNB][AMF] AMF Name: AMF
INFO[0000] [GNB][AMF] State of AMF: Active
INFO[0000] [GNB][AMF] Capacity of AMF: 255
INFO[0000] [GNB][AMF] PLMNs Identities Supported by AMF -- mcc: 208 mnc:93 INFO[0000] [GNB][AMF] List of AMF slices Supported by AMF -- sst:01 sd:010203 INFO[0000] [GNB][AMF] List of AMF slices Supported by AMF -- sst:01 sd:112233 INFO[0001] [TESTER] TESTING REGISTRATION USING IMSI 0000000003 UE INFO[0001] [GNB] Received incoming connection from new UE INFO[0001] [UE] Initiating Registration
INFO[0001] [UE] Switched from state 0 to state 1
INFO[0001] [GNB][SCTP] Receive message in 0 stream
INFO[0001] [GNB][NGAP] Receive Downlink NAS Transport
INFO[0001] [UE][NAS] Message without security header
INFO[0001] [UE][NAS] Receive Authentication Request
INFO[0001] [UE][NAS][MAC] Authenticity of the authentication request message: OK INFO[0001] [UE][NAS][SQN] SQN of the authentication request message: VALID INFO[0001] [UE][NAS] Send authentication response
INFO[0001] [UE] Switched from state 1 to state 2
INFO[0001] [GNB][SCTP] Receive message in 0 stream
INFO[0001] [GNB][NGAP] Receive Downlink NAS Transport
INFO[0001] [UE][NAS] Message with security header
INFO[0001] [UE][NAS] Message with integrity and with NEW 5G NAS SECURITY CONTEXT INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] Receive Security Mode Command
INFO[0001] [UE][NAS] Type of ciphering algorithm is 5G-EA0 INFO[0001] [UE][NAS] Type of integrity protection algorithm is 128-5G-IA2 INFO[0001] [GNB][SCTP] Receive message in 0 stream
INFO[0001] [GNB][NGAP] Receive Initial Context Setup Request INFO[0001] [GNB][UE] UE Context was created with successful INFO[0001] [GNB][UE] UE RAN ID 1
INFO[0001] [GNB][UE] UE AMF ID 1
INFO[0001] [GNB][UE] UE Mobility Restrict --Plmn-- Mcc: 208 Mnc: 93 INFO[0001] [GNB][UE] UE Masked Imeisv: 1110000000ffff00 INFO[0001] [GNB][UE] Allowed Nssai-- Sst: [01 01] Sd: [010203 112233] INFO[0001] [GNB][NGAP][AMF] Send Initial Context Setup Response. INFO[0001] [UE][NAS] Message with security header
INFO[0001] [UE][NAS] Message with integrity and ciphered INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] Receive Registration Accept
INFO[0001] [UE][NAS] UE 5G GUTI: &{119 11 [242 2 248 57 202 254 0 0 0 0 1]} INFO[0001] [GNB] Initiating Initial Context Setup Response INFO[0001] [GNB][NGAP] No PDU Session to set up in InitialContextSetupResponse. INFO[0001] [UE] Switched from state 2 to state 3
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [GNB][SCTP] Receive message in 0 stream
INFO[0001] [GNB][NGAP] Receive PDU Session Resource Setup Request INFO[0001] [GNB][NGAP][UE] PDU Session was created with successful. INFO[0001] [GNB][NGAP][UE] PDU Session Id: 1
INFO[0001] [GNB][NGAP][UE] NSSAI Selected --- sst: NSSAI was not selected sd: NSSAI was not selected INFO[0001] [GNB][NGAP][UE] PDU Session Type: ipv4
INFO[0001] [GNB][NGAP][UE] QOS Flow Identifier: 1
INFO[0001] [GNB][NGAP][UE] Uplink Teid: 1
INFO[0001] [GNB][NGAP][UE] Downlink Teid: 1
INFO[0001] [GNB][NGAP][UE] Non-Dynamic-5QI: 9
INFO[0001] [GNB][NGAP][UE] Priority Level ARP: 8
INFO[0001] [GNB][NGAP][UE] UPF Address: 172.20.10.10 :2152 INFO[0001] [GNB] Initiating PDU Session Resource Setup Response INFO[0001] [UE][NAS] Message with security header
INFO[0001] [UE][NAS] Message with integrity and ciphered INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] Receive DL NAS Transport
INFO[0001] [UE][NAS] Receiving PDU Session Establishment Accept INFO[0001] [UE][NAS] PDU session QoS RULES: [1 0 6 49 49 1 1 255 1] INFO[0001] [UE][NAS] PDU session DNN: internet
INFO[0001] [UE][NAS] PDU session NSSAI -- sst: 1 sd: 112233 INFO[0001] [UE][NAS] PDU address received: 10.61.0.1
INFO[0002] [UE][GTP] Interface val0000000003 has successfully been configured for UE 10.61.0.1 INFO[0002] [UE][GTP] You can do traffic for this UE using VRF vrf0000000003, eg: INFO[0002] [UE][GTP] sudo ip vrf exec vrf0000000003 iperf3 -c IPERF_SERVER -p PORT -t 9000 INFO[0014] [GNB] Initiating NGAP UE Handover
INFO[0014] [GNB][SCTP] Receive message in 0 stream
INFO[0014] [GNB][NGAP] Receive Handover Request
INFO[0014] [GNB] Initiating Handover Request Acknowledge INFO[0014] [GNB][SCTP] Receive message in 0 stream
WARN[0014] [GNB][NGAP] Received unknown NGAP message 0xc

The error log section in Free5GC is as follows (only capturing the handover part):

2024-09-26T22:31:36.132442898-07:00 [INFO][AMF][Ngap][ran_addr:172.20.10.9:9488] Handle HandoverRequired 2024-09-26T22:31:36.133710889-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:1,AU:1(3GPP)][ran_addr:172.20.10.9:9488] Handle HandoverRequired (RAN UE NGAP ID: 1) 2024-09-26T22:31:36.134560616-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:1,AU:1(3GPP)][ran_addr:172.20.10.9:9488] Send HandoverRequiredTransfer to SMF 2024-09-26T22:31:36.136731230-07:00 [INFO][SMF][PduSess] Receive Update SM Context Request 2024-09-26T22:31:36.138325292-07:00 [WARN][SMF][PduSess][pdu_session_id:1][supi:imsi-208930000000003] Unexpected state, expect: [Active], actual:[ModificationPending] 2024-09-26T22:31:36.139217316-07:00 [INFO][SMF][PduSess] Direct Forwarding Path Unavailable 2024-09-26T22:31:36.141537916-07:00 [INFO][SMF][GIN] | 200 | 127.0.0.1 | POST | /nsmf-pdusession/v1/sm-contexts/urn:uuid:d4198a5a-c6dd-49de-a819-8f478262bae4/modify | 2024-09-26T22:31:36.143185274-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:1,AU:1(3GPP)][ran_addr:172.20.10.9:9488] Send Handover Request 2024-09-26T22:31:36.143340361-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:4294967295,AU:2(3GPP)][ran_addr:172.20.10.8:9487] New RanUe [RanUeNgapID:4294967295][AmfUeNgapID:2] 2024-09-26T22:31:36.157083279-07:00 [INFO][AMF][Ngap][ran_addr:172.20.10.8:9487] Handle HandoverRequestAcknowledge 2024-09-26T22:31:36.157483045-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:4294967295,AU:2(3GPP)][ran_addr:172.20.10.8:9487] Handle HandoverRequestAcknowledge (RAN UE NGAP ID: 4294967295) 2024-09-26T22:31:36.157557938-07:00 [INFO][AMF][Ngap][amf_ue_ngap_id:RU:4294967295,AU:2(3GPP)][ran_addr:172.20.10.8:9487] Send HandoverRequestAcknowledgeTransfer to SMF 2024-09-26T22:31:36.161705582-07:00 [INFO][SMF][PduSess] Receive Update SM Context Request 2024-09-26T22:31:36.164497041-07:00 [ERRO][SMF][PduSess][pdu_session_id:1][supi:imsi-208930000000003] Handle HandoverRequestAcknowledgeTransfer failed: DL Forwarding Info not provision 2024-09-26T22:31:36.165925918-07:00 [ERRO][SMF][GIN] panic: runtime error: invalid memory address or nil pointer dereference

Additionally, I noticed a warning message during session establishment in the SMF：[WARN][SMF][PduSess] No Create URR

[sp-l6]

If the handover is not executed and I run the command sudo ./packetrusher ue, there is also a warning [WARN][SMF][PduSess] No Create URR, but this does not affect the establishment of the PDU session and user plane.

[linouxis9]

Hi @sp-l6,

Thanks for the report! I'll take a look. It's probably indeed a bug in PacketRusher. However, I would recommend you to also open a bug on Free5GC's SMF (if the panic is reproducible on main) as even if PacketRusher is doing something wrong, it should not make SMF panic (even if the panic is caught by Gin).

Meanwhile if it also works for you, you may use Xn Handover!

Thanks and cheers! Valentin

[sp-l6]

@linouxis9 Thank you! The XN handover is usable. Next, I will verify whether integrating Free5GC and UERANSIM will result in this panic, as I believe it can help resolve the issue.

[sp-l6]

Hello, do you have any new research findings? @linouxis9