[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

[huahuaLover]

I also face the same question. If there is a solution? @linouxis9