search

HewlettPackard / PacketRusher

High performance 5G UE/gNB Simulator and CP/UP load tester.
Apache License 2.0
100 stars 21 forks source link

[BUG] PDU Session Establishment Reject for PDU Session ID 1, 5GSM Cause: Service option temporarily out of order #34

Closed infinitydon closed 7 months ago

infinitydon commented 7 months ago

Describe the bug UE is not able to create successful PDU session

To Reproduce Using Open5gs as the core, create a roaming scenario, configs can found in https://github.com/HewlettPackard/PacketRusher/issues/32

Expected behavior Successful PDU session creation

Screenshots Packet Rusher logs:

ubuntu@packetRusher:~/rusher-raoming-1$ sudo ./packetrusher ue
INFO[0000] PacketRusher version 1.0.1
INFO[0000] ---------------------------------------
INFO[0000] [TESTER] Starting test function: Testing an ue attached with configuration
INFO[0000] [TESTER][UE] Number of UEs: 1
INFO[0000] [TESTER][UE] disableTunnel is false
INFO[0000] [TESTER][GNB] Control interface IP/Port: 192.168.200.2/9487
INFO[0000] [TESTER][GNB] Data interface IP/Port: 192.168.200.2/2152
INFO[0000] [TESTER][AMF] AMF IP/Port: 192.168.200.1/38412
INFO[0000] ---------------------------------------
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: open5gs-amf0
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: 001 mnc:01
INFO[0000] [GNB][AMF] List of AMF slices Supported by AMF -- sst:01 sd:000001
INFO[0001] [TESTER] TESTING REGISTRATION USING IMSI 0000000001 UE
INFO[0001] [UE] Initiating Registration
INFO[0001] [UE] Switched from state 0 to state 1
INFO[0001] [GNB][SCTP] Receive message in 1 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 1 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 1 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 6
INFO[0001] [GNB][UE] UE Mobility Restrict --Plmn-- Mcc: not informed Mnc: not informed
INFO[0001] [GNB][UE] UE Masked Imeisv: 1110000000ffff00
INFO[0001] [GNB][UE] Allowed Nssai-- Sst: [01] Sd: [000001]
INFO[0001] [GNB][NAS][UE] Send Registration Accept.
INFO[0001] [GNB][NGAP][AMF] Send Initial Context Setup Response.
INFO[0001] [GNB] Initiating 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 MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive Registration Accept
INFO[0001] [UE][NAS] UE 5G GUTI: [192 0 6 79]
INFO[0001] [UE] Switched from state 2 to state 3
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [GNB][SCTP] Receive message in 1 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 ciphered
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive Configuration Update Command
INFO[0001] [UE][NAS] imsi-999700000000001 was succesfully registered
INFO[0001] [GNB][SCTP] Receive message in 1 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 ciphered
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive DL NAS Transport
ERRO[0001] [UE][NAS] Receiving PDU Session Establishment Reject
ERRO[0001] [UE][NAS] PDU Session Establishment Reject for PDU Session ID 1, 5GSM Cause: Service option temporarily out of order. Please share pcap with packetrusher@hpe.com.
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [GNB][SCTP] Receive message in 1 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 ciphered
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive DL NAS Transport
ERRO[0001] [UE][NAS] Receiving PDU Session Establishment Reject
ERRO[0001] [UE][NAS] PDU Session Establishment Reject for PDU Session ID 1, 5GSM Cause: Service option temporarily out of order. Please share pcap with packetrusher@hpe.com.
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [GNB][SCTP] Receive message in 1 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 ciphered
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive DL NAS Transport
ERRO[0001] [UE][NAS] Receiving PDU Session Establishment Reject
ERRO[0001] [UE][NAS] PDU Session Establishment Reject for PDU Session ID 1, 5GSM Cause: Service option temporarily out of order. Please share pcap with packetrusher@hpe.com.
INFO[0001] [UE] Initiating New PDU Session
INFO[0001] [GNB][SCTP] Receive message in 1 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 ciphered
INFO[0001] [UE][NAS] successful NAS MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive DL NAS Transport
ERRO[0001] [UE][NAS] Receiving PDU Session Establishment Reject

AMF logs:

12/04 15:00:59.043: [amf] INFO: gNB-N2 accepted[192.168.200.2]:9487 in ng-path module (../src/amf/ngap-sctp.c:113)
12/04 15:00:59.043: [amf] INFO: gNB-N2 accepted[192.168.200.2] in master_sm module (../src/amf/amf-sm.c:741)
12/04 15:00:59.043: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1227)
12/04 15:00:59.043: [amf] INFO: gNB-N2[192.168.200.2] max_num_of_ostreams : 2 (../src/amf/amf-sm.c:780)
12/04 15:01:00.046: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:401)
12/04 15:01:00.046: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2546)
12/04 15:01:00.046: [amf] INFO:     RAN_UE_NGAP_ID[1] AMF_UE_NGAP_ID[6] TAC[1] CellID[0x1] (../src/amf/ngap-handler.c:562)
12/04 15:01:00.046: [amf] INFO: [suci-0-999-70-4567-0-0-0000000001] known UE by SUCI (../src/amf/context.c:1829)
12/04 15:01:00.046: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1165)
12/04 15:01:00.046: [gmm] INFO: [suci-0-999-70-4567-0-0-0000000001]    SUCI (../src/amf/gmm-handler.c:166)
12/04 15:01:00.096: [nas] WARNING: Spec warning : bcd[16] = 0x0, 0x30 (../lib/nas/common/conv.c:48)
12/04 15:01:00.316: [gmm] INFO: [imsi-999700000000001] Registration complete (../src/amf/gmm-sm.c:2146)
12/04 15:01:00.316: [amf] INFO: [imsi-999700000000001] Configuration update command (../src/amf/nas-path.c:612)
12/04 15:01:00.316: [gmm] INFO:     UTC [2023-12-04T15:01:00] Timezone[0]/DST[0] (../src/amf/gmm-build.c:559)
12/04 15:01:00.316: [gmm] INFO:     LOCAL [2023-12-04T15:01:00] Timezone[0]/DST[0] (../src/amf/gmm-build.c:564)
12/04 15:01:00.316: [gmm] INFO: UE SUPI[imsi-999700000000001] DNN[internet] S_NSSAI[SST:1 SD:0x1] smContextRef [NULL] (../src/amf/gmm-handler.c:1241)
12/04 15:01:00.316: [gmm] INFO: SMF Instance [bdeea232-92b5-41ee-b7ef-e14c5210b7e0] (../src/amf/gmm-handler.c:1280)
12/04 15:01:00.319: [smf] INFO: [Added] Number of SMF-UEs is now 1 (../src/smf/context.c:1019)
12/04 15:01:00.319: [smf] INFO: [Added] Number of SMF-Sessions is now 1 (../src/smf/context.c:3068)
12/04 15:01:00.325: [sbi] INFO: [UDM] (SCP-discover) NF registered [97942e20-91f4-41ee-9d87-d7f7e88b520f:1] (../lib/sbi/path.c:211)
12/04 15:01:00.330: [sbi] INFO: [PCF] (SCP-discover) NF registered [81e36fa4-91ff-41ee-8698-0bf418efb12f:1] (../lib/sbi/path.c:211)
12/04 15:01:00.330: [smf] ERROR: [imsi-999700000000001:1] HTTP response error [404] (../src/smf/gsm-sm.c:519)
12/04 15:01:00.331: [amf] ERROR: [1:0] PDU session establishment reject (../src/amf/namf-handler.c:466)
12/04 15:01:00.331: [amf] WARNING: [suci-0-999-70-4567-0-0-0000000001] DL NAS transport (../src/amf/nas-path.c:1014)
12/04 15:01:00.331: [amf] INFO: [Removed] Number of AMF-Sessions is now 0 (../src/amf/context.c:2574)

Architecture (please complete the following information):

Pcap: packet-rusher-o5gs-roaming-1.zip

Additional context Also the number of retries from pack-rusher seems to be too much, it practically flooded the logs of the Open5gs core components when it encountered this issue, I think this should be reduced to a few seconds retry mechanism.

Also I think the Discussion feature of your github repo should be enable so as to deal with other issues that are not related to bugs or feature (this is just a suggestion)

linouxis9 commented 7 months ago

Hi @infinitydon! Thank for your report once again :-) I can reproduce your issue, but I think this time, the issue might be on open5gs' side not yet handling well slices when doing roaming, or an open5gs' configuration issue, rather than a PacketRusher's issue.

I was able to make it work by not using ssd in the open5gs's amf configuration:

  plmn_support:
    - plmn_id:
        mcc: 001
        mnc: 01
      s_nssai:
        - sst: 1

and setting inside PacketRusher:

gnodeb:
...
  slicesupportlist:
    sst: "01"
    sd: "ffffff"
...
ue:
...
  snssai:
    sst: 01
    sd: "ffffff"

sd being set as ffffff equals to no sd, I'll improve configuration that if sd is not set then "ffffff" will be automatically set. Could you confirm that it work in your environment when not using Slice Differentiator?

Also the number of retries from pack-rusher seems to be too much, it practically flooded the logs of the Open5gs core components when it encountered this issue, I think this should be reduced to a few seconds retry mechanism.

I completely agree, will work on that, thanks!

Also I think the Discussion feature of your github repo should be enable so as to deal with other issues that are not related to bugs or feature (this is just a suggestion)

Will do as well :-)

Thanks a lot for using PacketRusher!

infinitydon commented 7 months ago

@linouxis9 - I just tried that but now getting the following error in packet-rusher:

INFO[0001] [UE][NAS] Receive DL NAS Transport
INFO[0001] [UE][NAS] Receiving PDU Session Establishment Accept
FATA[0002] [UE][DATA] Unable to create VRF for UEoperation not supported
linouxis9 commented 7 months ago

@linouxis9 - I just tried that but now getting the following error in packet-rusher:

INFO[0001] [UE][NAS] Receive DL NAS Transport
INFO[0001] [UE][NAS] Receiving PDU Session Establishment Accept
FATA[0002] [UE][DATA] Unable to create VRF for UEoperation not supported
sudo modprobe vrf

And then re-try again. Make sure your kernel supports vrf as well (on Ubuntu, you should use the generic kernel). Will add to the installation guide, thanks!

infinitydon commented 7 months ago

Looks like VRF is not included in my kernel

ubuntu@packetRusher:~/rusher-raoming-1$ sudo modprobe vrf
modprobe: FATAL: Module vrf not found in directory /lib/modules/5.4.0-167-generic
ubuntu@packetRusher:~/rusher-raoming-1$

ubuntu@packetRusher:~/rusher-raoming-1$ uname -r
5.4.0-167-generic

Which kernel version are you using with Ubuntu 20.04

linouxis9 commented 7 months ago

Looks like VRF is not included in my kernel

ubuntu@packetRusher:~/rusher-raoming-1$ sudo modprobe vrf
modprobe: FATAL: Module vrf not found in directory /lib/modules/5.4.0-167-generic
ubuntu@packetRusher:~/rusher-raoming-1$

ubuntu@packetRusher:~/rusher-raoming-1$ uname -r
5.4.0-167-generic

Which kernel version are you using with Ubuntu 20.04

Can you try to install HWE kernel?

sudo apt install --install-recommends linux-generic-hwe-20.04
infinitydon commented 7 months ago

The following command fixed the VRF module:

sudo apt-get install linux-modules-extra-$(uname -r)

I already used the above command before seeing your comment, not sure if the command you suggested will fix it.

PDU session is now okay..

INFO[0001] [UE][NAS] imsi-999700000000001 was succesfully registered
INFO[0001] [GNB][SCTP] Receive message in 1 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: 14980
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: 192.168.200.1 :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 MAC verification
INFO[0001] [UE][NAS] successful NAS CIPHERING
INFO[0001] [UE][NAS] Receive DL NAS Transport
INFO[0001] [UE][NAS] Receiving PDU Session Establishment Accept
INFO[0002] [UE][GTP] Interface val0000000001 has successfully been configured for UE 10.45.0.108
INFO[0002] [UE][GTP] You can do traffic for this UE using VRF vrf0000000001, eg:
INFO[0002] [UE][GTP] sudo ip vrf exec vrf0000000001 iperf3 -c IPERF_SERVER -p PORT -t 9000
ubuntu@packetRusher:~$ ip a
...
...
4: val0000000001: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1464 qdisc noqueue master vrf0000000001 state UNKNOWN group default qlen 1000
    link/none
    inet 10.45.0.108/32 scope global val0000000001
       valid_lft forever preferred_lft forever
    inet6 fe80::245c:d6b5:9cb9:19c/64 scope link stable-privacy
       valid_lft forever preferred_lft forever
5: vrf0000000001: <NOARP,MASTER,UP,LOWER_UP> mtu 65575 qdisc noqueue state UP group default
    link/ether 92:fe:f9:59:ef:64 brd ff:ff:ff:ff:ff:ff

ubuntu@packetRusher:~$ sudo ip vrf exec vrf0000000001 ping 10.45.0.1 -c 3
PING 10.45.0.1 (10.45.0.1) 56(84) bytes of data.
64 bytes from 10.45.0.1: icmp_seq=1 ttl=64 time=0.635 ms
64 bytes from 10.45.0.1: icmp_seq=2 ttl=64 time=0.724 ms
64 bytes from 10.45.0.1: icmp_seq=3 ttl=64 time=0.766 ms

Thanks for your support, much appreciated!

linouxis9 commented 7 months ago

Glad that I could help! I'll update the installation guide and implement your suggestions. Thanks :-)

s5uishida commented 7 months ago

Hi @linouxis9 @infinitydon

The following was not required when installing PacketRusher on Ubuntu 22.04.

apt-get install linux-modules-extra-$(uname -r)

My OS is as follows. gtp5g kernel module also worked.

Linux pr10 5.15.0-89-lowlatency #99-Ubuntu SMP PREEMPT Thu Nov 2 15:27:06 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

FYI.

linouxis9 commented 7 months ago

Hi @s5uishida, Thanks for the information! PacketRusher seems indeed to work on Ubuntu 22.04. However, I do seem to have issues with gtp5g when using an even more recent kernel (6.5.0 for example).

yoursunny commented 7 months ago

I do seem to have issues with gtp5g when using an even more recent kernel (6.5.0 for example).

Ubuntu 22.04 GA kernel is 5.15. gtp5g is working so far.

Ubuntu 22.04 HWE kernel is 6.2. gtp5g does not support 6.2 kernel. https://forum.free5gc.org/t/upf-est-createfar-error-invalid-argument/2111/2?u=yoursunny

Thus, we must resist the urge of installing HWE kernel.