Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unable to connect UE to Open5GS core network, AMF sends Registration Reject #939

Closed
PsArzzz opened this issue Nov 17, 2024 · 3 comments
Closed

Comments

@PsArzzz
Copy link

PsArzzz commented Nov 17, 2024

Issue Description

I am using Open5GS as the core network and srsRAN to set up the gNodeB and UE, with ZeroMQ for communication between the gNodeB and UE. The UE successfully connects to the gNodeB but fails to register with the core network. After sending a Registration Request to the AMF, the request is rejected with a Registration Reject message. Eventually, the UE logs show "Received RRC Release." How can I resolve this and successfully connect the UE to the core network?

Setup Details

The setup consists of four virtual machines, each running Ubuntu 22.04. The details are as follows:

1、Open5GS Control Plane (5GC C-Plane): IP Address: 192.168.83.131
2、Open5GS User Plane (5GC U-Plane): IP Address: 192.168.83.130
3、srsRAN Project ZMQ RAN (gNodeB): IP Address: 192.168.83.136
4、srsRAN 4G ZMQ UE (NR-UE): IP Address: 192.168.83.137

Expected Behavior

The UE should be able to register successfully with the core network, with the AMF accepting the Registration Request.

Actual Behaviour

1、The following output appears on the srsUE terminal:
a@a:~/srsRAN_4G/build/srsue$ sudo ./src/srsue ue_zmq.conf

Reading configuration file ue_zmq.conf...

Built in Release mode using commit ec29b0c1f on branch master.

Opening 1 channels in RF device=zmq with args=tx_port=tcp://192.168.83.137:2001,rx_port=tcp://192.168.83.136:2000,base_srate=23.04e6
Supported RF device list: zmq file
CHx base_srate=23.04e6
Current sample rate is 1.92 MHz with a base rate of 23.04 MHz (x12 decimation)
CH0 rx_port=tcp://192.168.83.136:2000
CH0 tx_port=tcp://192.168.83.137:2001
Current sample rate is 23.04 MHz with a base rate of 23.04 MHz (x1 decimation)
Current sample rate is 23.04 MHz with a base rate of 23.04 MHz (x1 decimation)
Waiting PHY to initialize ... done!
Attaching UE...
Random Access Transmission: prach_occasion=0, preamble_index=0, ra-rnti=0x39, tti=334
Random Access Complete.     c-rnti=0x4601, ta=0
RRC Connected
Received RRC Release

2、Logs from UE:
ue.log

3、Logs from gNB:
gnb.log

4、Logs from AMF:

11/17 20:24:46.731: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_CLIENT (../src/amf/amf-sm.c:81)
11/17 20:24:46.731: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_CLIENT (../lib/sbi/nf-sm.c:198)
11/17 20:24:56.731: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_TIMER (../src/amf/amf-sm.c:81)
11/17 20:24:56.731: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_TIMER (../lib/sbi/nf-sm.c:198)
[{"op":"replace","path":"/nfStatus","value":"REGISTERED"},{"op":"replace","path":"/load","value":0}]11/17 20:24:56.731: [sbi] DEBUG: [PATCH] http://127.0.0.200:7777/nnrf-nfm/v1/nf-instances/edad8896-a4dc-41ef-8084-0bf0484790fe (../lib/sbi/client.c:728)
11/17 20:24:56.731: [sbi] DEBUG: SENDING...[100] (../lib/sbi/client.c:497)
11/17 20:24:56.731: [sbi] DEBUG: [{"op":"replace","path":"/nfStatus","value":"REGISTERED"},{"op":"replace","path":"/load","value":0}] (../lib/sbi/client.c:499)
11/17 20:24:56.736: [sbi] DEBUG: [204:PATCH] http://127.0.0.200:7777/nnrf-nfm/v1/nf-instances/edad8896-a4dc-41ef-8084-0bf0484790fe (../lib/sbi/client.c:675)
11/17 20:24:56.736: [sbi] DEBUG: RECEIVED[0] (../lib/sbi/client.c:686)
11/17 20:24:56.736: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_CLIENT (../src/amf/amf-sm.c:81)
11/17 20:24:56.736: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_CLIENT (../lib/sbi/nf-sm.c:198)
11/17 20:25:00.230: [amf] INFO: gNB-N2 accepted[192.168.83.136]:34425 in ng-path module (../src/amf/ngap-sctp.c:113)
11/17 20:25:00.230: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:81)
11/17 20:25:00.230: [amf] INFO: gNB-N2 accepted[192.168.83.136] in master_sm module (../src/amf/amf-sm.c:796)
11/17 20:25:00.244: [amf] DEBUG: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28)
11/17 20:25:00.244: [amf] DEBUG: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55)
11/17 20:25:00.244: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1238)
11/17 20:25:00.244: [amf] DEBUG: SCTP_ASSOC_CHANGE:[T:32769, F:0x0, S:0, I/O:10/30] (../src/amf/ngap-sctp.c:152)
11/17 20:25:00.244: [amf] DEBUG: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161)
11/17 20:25:00.244: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:81)
11/17 20:25:00.244: [amf] INFO: gNB-N2[192.168.83.136] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:842)
11/17 20:25:00.244: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:81)
11/17 20:25:00.245: [amf] DEBUG: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55)
11/17 20:25:00.245: [amf] DEBUG: NGSetupRequest (../src/amf/ngap-handler.c:144)
11/17 20:25:00.245: [amf] DEBUG:     IP[192.168.83.136] GNB_ID[0x19b] (../src/amf/ngap-handler.c:195)
11/17 20:25:00.245: [amf] DEBUG:     PLMN_ID[MCC:1 MNC:1] (../src/amf/ngap-handler.c:199)
11/17 20:25:00.245: [amf] DEBUG:     PagingDRX[3] (../src/amf/ngap-handler.c:203)
11/17 20:25:00.245: [amf] DEBUG:     TAC[1] (../src/amf/ngap-handler.c:237)
11/17 20:25:00.245: [amf] DEBUG:     PLMN_ID[MCC:1 MNC:1] (../src/amf/ngap-handler.c:277)
11/17 20:25:00.245: [amf] DEBUG:     S_NSSAI[SST:1 SD:0x1] (../src/amf/ngap-handler.c:330)
11/17 20:25:00.245: [amf] DEBUG:     TAC[1] (../src/amf/ngap-handler.c:70)
11/17 20:25:00.245: [amf] DEBUG:     PLMN_ID[MCC:1 MNC:1] (../src/amf/ngap-handler.c:71)
11/17 20:25:00.245: [amf] DEBUG:     SERVED_TAI_INDEX[0] (../src/amf/ngap-handler.c:76)
11/17 20:25:00.245: [amf] DEBUG:     PLMN_ID[MCC:1 MNC:1] (../src/amf/ngap-handler.c:98)
11/17 20:25:00.245: [amf] DEBUG:     S_NSSAI[SST:1 SD:0x1] (../src/amf/ngap-handler.c:103)
11/17 20:25:00.245: [amf] DEBUG: NG-Setup response (../src/amf/ngap-path.c:299)
11/17 20:25:00.245: [amf] DEBUG: NGSetupResponse (../src/amf/ngap-build.c:36)
11/17 20:25:00.245: [amf] DEBUG:     IP[192.168.83.136] RAN_ID[411] (../src/amf/ngap-path.c:64)
11/17 20:25:04.106: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:81)
11/17 20:25:04.107: [amf] DEBUG: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55)
11/17 20:25:04.107: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:435)
11/17 20:25:04.107: [amf] DEBUG:     IP[192.168.83.136] RAN_ID[411] (../src/amf/ngap-handler.c:461)
11/17 20:25:04.107: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2694)
11/17 20:25:04.107: [amf] INFO:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] TAC[1] CellID[0x66c000] (../src/amf/ngap-handler.c:596)
11/17 20:25:04.107: [amf] DEBUG: amf_state_operational(): AMF_EVENT_5GMM_MESSAGE (../src/amf/amf-sm.c:81)
11/17 20:25:04.107: [nas] TRACE: [NAS] Decode REGISTRATION_REQUEST
 (../lib/nas/5gs/decoder.c:84)
11/17 20:25:04.107: [nas] TRACE:   5GS_REGISTRATION_TYPE -  (../lib/nas/5gs/ies.c:2965)
0000: 79                                    y
11/17 20:25:04.107: [nas] TRACE:   5GS_MOBILE_IDENTITY -  (../lib/nas/5gs/ies.c:1972)
0000: 0100f110 00000000 00000000 10         .............
11/17 20:25:04.107: [nas] TRACE:   UE_SECURITY_CAPABILITY -  (../lib/nas/5gs/ies.c:2700)
0000: 02f070                                ..p
11/17 20:25:04.107: [nas] TRACE:   NSSAI -  (../lib/nas/5gs/ies.c:1810)
0000: 05040100 0001                         ......
11/17 20:25:04.107: [amf] INFO: [suci-0-001-01-0000-0-0-0000000001] Unknown UE by SUCI (../src/amf/context.c:1861)
11/17 20:25:04.107: [gmm] DEBUG: gmm_state_initial(): ENTRY (../src/amf/gmm-sm.c:51)
11/17 20:25:04.107: [gmm] DEBUG: gmm_state_de_registered(): ENTRY (../src/amf/gmm-sm.c:75)
11/17 20:25:04.107: [amf] INFO: [Added] Number of AMF-UEs is now 1 (../src/amf/context.c:1638)
11/17 20:25:04.107: [gmm] DEBUG: gmm_state_de_registered(): AMF_EVENT_5GMM_MESSAGE (../src/amf/gmm-sm.c:75)
11/17 20:25:04.107: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1220)
11/17 20:25:04.107: [gmm] ERROR: Non cleartext IEs is included [0xc] (../src/amf/gmm-handler.c:116)
11/17 20:25:04.107: [gmm] ERROR: Unknown reg_type[0] (../src/amf/gmm-sm.c:1239)
11/17 20:25:04.107: [gmm] ERROR: gmm_handle_registration_request() failed [95] (../src/amf/gmm-sm.c:1243)
11/17 20:25:04.107: [amf] ERROR: Unknown reg_type[0] (../src/amf/nas-path.c:207)
11/17 20:25:04.107: [amf] WARNING: [(null)] Registration reject [95] (../src/amf/nas-path.c:211)
11/17 20:25:04.107: [nas] TRACE: [NAS] Encode REGISTRATION_REJECT (../lib/nas/5gs/encoder.c:1009)
11/17 20:25:04.107: [nas] TRACE:   5GMM_CAUSE -  (../lib/nas/5gs/ies.c:955)
0000: 5f                                    _
11/17 20:25:04.107: [amf] DEBUG: DownlinkNASTransport (../src/amf/ngap-build.c:320)
11/17 20:25:04.107: [amf] DEBUG:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] (../src/amf/ngap-build.c:363)
11/17 20:25:04.107: [amf] DEBUG:     IP[192.168.83.136] RAN_ID[411] (../src/amf/ngap-path.c:64)
11/17 20:25:04.107: [gmm] DEBUG: gmm_state_de_registered(): EXIT (../src/amf/gmm-sm.c:75)
11/17 20:25:04.108: [gmm] DEBUG: gmm_state_exception(): ENTRY (../src/amf/gmm-sm.c:2499)
11/17 20:25:04.108: [amf] DEBUG: UEContextReleaseCommand (../src/amf/ngap-path.c:392)
11/17 20:25:04.108: [amf] DEBUG:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] (../src/amf/ngap-path.c:393)
11/17 20:25:04.108: [amf] DEBUG:     Group[3] Cause[0] Action[3] Duration[0] (../src/amf/ngap-path.c:400)
11/17 20:25:04.108: [amf] DEBUG: UEContextReleaseCommand (../src/amf/ngap-build.c:1223)
11/17 20:25:04.108: [amf] DEBUG:     IP[192.168.83.136] RAN_ID[411] (../src/amf/ngap-path.c:64)
11/17 20:25:04.108: [amf] DEBUG:     SUPI[(null)] (../src/amf/ngap-path.c:433)
11/17 20:25:04.792: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:81)
11/17 20:25:04.792: [amf] DEBUG: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55)
11/17 20:25:04.792: [amf] DEBUG: UEContextReleaseComplete (../src/amf/ngap-handler.c:1664)
11/17 20:25:04.792: [amf] DEBUG:     IP[192.168.83.136] RAN_ID[411] (../src/amf/ngap-handler.c:1680)
11/17 20:25:04.792: [amf] INFO: UE Context Release [Action:3] (../src/amf/ngap-handler.c:1726)
11/17 20:25:04.792: [amf] INFO:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] (../src/amf/ngap-handler.c:1727)
11/17 20:25:04.792: [amf] INFO:     SUCI[Unknown] (../src/amf/ngap-handler.c:1731)
11/17 20:25:04.792: [amf] DEBUG:     Action: UE context remove (../src/amf/ngap-handler.c:1791)
11/17 20:25:04.792: [amf] INFO: [Removed] Number of gNB-UEs is now 0 (../src/amf/context.c:2701)
11/17 20:25:04.792: [gmm] DEBUG: gmm_state_exception(): EXIT (../src/amf/gmm-sm.c:2499)
11/17 20:25:04.792: [gmm] DEBUG: gmm_state_final(): EXIT (../src/amf/gmm-sm.c:60)
11/17 20:25:04.792: [amf] INFO: [Removed] Number of AMF-UEs is now 0 (../src/amf/context.c:1735)
11/17 20:25:06.733: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_TIMER (../src/amf/amf-sm.c:81)
11/17 20:25:06.733: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_TIMER (../lib/sbi/nf-sm.c:198)
[{"op":"replace","path":"/nfStatus","value":"REGISTERED"},{"op":"replace","path":"/load","value":0}]11/17 20:25:06.733: [sbi] DEBUG: [PATCH] http://127.0.0.200:7777/nnrf-nfm/v1/nf-instances/edad8896-a4dc-41ef-8084-0bf0484790fe (../lib/sbi/client.c:728)
11/17 20:25:06.734: [sbi] DEBUG: SENDING...[100] (../lib/sbi/client.c:497)
11/17 20:25:06.734: [sbi] DEBUG: [{"op":"replace","path":"/nfStatus","value":"REGISTERED"},{"op":"replace","path":"/load","value":0}] (../lib/sbi/client.c:499)
11/17 20:25:06.735: [sbi] DEBUG: [204:PATCH] http://127.0.0.200:7777/nnrf-nfm/v1/nf-instances/edad8896-a4dc-41ef-8084-0bf0484790fe (../lib/sbi/client.c:675)
11/17 20:25:06.735: [sbi] DEBUG: RECEIVED[0] (../lib/sbi/client.c:686)
11/17 20:25:06.735: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_CLIENT (../src/amf/amf-sm.c:81)
11/17 20:25:06.735: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_CLIENT (../lib/sbi/nf-sm.c:198)
11/17 20:25:13.332: [amf] DEBUG: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:188)
11/17 20:25:13.335: [amf] DEBUG: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:81)
11/17 20:25:13.335: [amf] INFO: gNB-N2[192.168.83.136] connection refused!!! (../src/amf/amf-sm.c:855)
11/17 20:25:13.335: [amf] DEBUG: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55)
11/17 20:25:13.335: [amf] DEBUG: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37)
11/17 20:25:13.335: [amf] INFO: [Removed] Number of gNBs is now 0 (../src/amf/context.c:1265)
11/17 20:25:16.739: [amf] DEBUG: amf_state_operational(): OGS_EVENT_NAME_SBI_TIMER (../src/amf/amf-sm.c:81)
11/17 20:25:16.739: [sbi] DEBUG: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_TIMER (../lib/sbi/nf-sm.c:198)

Configuration Files:
5、amf.yaml(On Open5GS 5GC C-Plane)
amf_yaml.txt

6、nrf.yaml(On Open5GS 5GC C-Plane)
nrf_yaml.txt

7、smf.yaml(On Open5GS 5GC C-Plane)
smf_yaml.txt

8、upf.yaml(On Open5GS 5GC U-Plane)
upf_yaml.txt

9、gnb_zmq.yaml
gnb_zmq_yaml.txt

10、ue_zmq.conf
ue_zmq_conf.txt

Steps to reproduce the problem

1、Start the Open5GS core network on VMs with IP addresses 192.168.83.131 and 192.168.83.130.
2、Start the srsRAN gNodeB on VM3 and ensure it connects to the AMF.
3、Start the srsRAN UE on VM4 and attempt to register with the network.

Additional Information

BTW, how can I use Wireshark to capture RRC messages?

@PsArzzz
Copy link
Author

PsArzzz commented Nov 17, 2024

The gNB and UE times do not match the system time of the AMF, but they occur simultaneously.
This is the message captured on the AMF.
registration request:

Plain NAS 5GS Message
    Extended protocol discriminator: 5G mobility management messages (126)
    0000 .... = Spare Half Octet: 0
    .... 0000 = Security header type: Plain NAS message, not security protected (0)
    Message type: Registration request (0x41)
    5GS registration type
        .... 1... = Follow-On Request bit (FOR): Follow-on request pending
        .... .001 = 5GS registration type: initial registration (1)
    NAS key set identifier
        0... .... = Type of security context flag (TSC): Native security context (for KSIAMF)
        .111 .... = NAS key set identifier: 7
    5GS mobile identity
        Length: 13
        0... .... = Spare: 0
        .000 .... = SUPI format: IMSI (0)
        .... 0... = Spare: 0
        .... .001 = Type of identity: SUCI (1)
        Mobile Country Code (MCC): Unknown (1)
        Mobile Network Code (MNC): Unknown (01)
        Routing indicator: 0000
        .... 0000 = Protection scheme Id: NULL scheme (0)
        Home network public key identifier: 0
        MSIN: 0000000001
    UE security capability
        Element ID: 0x2e
        Length: 2
        1... .... = 5G-EA0: Supported
        .1.. .... = 128-5G-EA1: Supported
        ..1. .... = 128-5G-EA2: Supported
        ...1 .... = 128-5G-EA3: Supported
        .... 0... = 5G-EA4: Not supported
        .... .0.. = 5G-EA5: Not supported
        .... ..0. = 5G-EA6: Not supported
        .... ...0 = 5G-EA7: Not supported
        0... .... = 5G-IA0: Not supported
        .1.. .... = 128-5G-IA1: Supported
        ..1. .... = 128-5G-IA2: Supported
        ...1 .... = 128-5G-IA3: Supported
        .... 0... = 5G-IA4: Not supported
        .... .0.. = 5G-IA5: Not supported
        .... ..0. = 5G-IA6: Not supported
        .... ...0 = 5G-IA7: Not supported
    NSSAI - Requested NSSAI
        Element ID: 0x2f
        Length: 5
        S-NSSAI 1
            Length: 4
            Slice/service type (SST): eMBB (1)
            Slice differentiator (SD): 1

registration reject:

Item 2: id-NAS-PDU
    ProtocolIE-Field
        id: id-NAS-PDU (38)
        criticality: reject (0)
        value
            NAS-PDU: 7e00445f
                Non-Access-Stratum 5GS (NAS)PDU
                    Plain NAS 5GS Message
                        Extended protocol discriminator: 5G mobility management messages (126)
                        0000 .... = Spare Half Octet: 0
                        .... 0000 = Security header type: Plain NAS message, not security protected (0)
                        Message type: Registration reject (0x44)
                        5GMM cause
                            5GMM cause: Semantically incorrect message (95)

@pgawlowicz
Copy link
Collaborator

please try with this patch:
srsran/srsRAN_4G#1214

@PsArzzz
Copy link
Author

PsArzzz commented Nov 18, 2024

Thank you very much for your response. After removing all the slicing configurations, the UE successfully connected to the core network.

@PsArzzz PsArzzz closed this as completed Nov 18, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants