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.

Sign up for GitHub

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

Jump to bottom

"Received RRC Release" at UE in ZMQ mode(already set inactivity_timer: 7200) #860

Open
liumr3 opened this issue Oct 14, 2024 · 11 comments
Open

"Received RRC Release" at UE in ZMQ mode(already set inactivity_timer: 7200) #860

liumr3 opened this issue Oct 14, 2024 · 11 comments

Comments

@liumr3
Copy link

liumr3 commented Oct 14, 2024 •
edited
Loading

Issue Description

following the turorials https://docs.srsran.com/projects/project/en/latest/tutorials/source/srsUE/source/index.html, I test the ZMQ mode. I run

sudo gnb -c gnb_zmq.yaml

it shows like this:

--== srsRAN gNB (commit e73b46182) ==--

The PRACH detector will not meet the performance requirements with the configuration {Format 0, ZCZ 0, SCS 1.25kHz, Rx ports 1}.
Lower PHY in executor blocking mode.
Available radio types: zmq.
Cell pci=1, bw=20 MHz, 1T1R, dl_arfcn=368500 (n3), dl_freq=1842.5 MHz, dl_ssb_arfcn=368410, ul_freq=1747.5 MHz

N2: Connection to AMF on 10.53.1.2:38412 completed
==== gNB started ===
Type <h> to view help

then i run

sudo ip netns add ue1

everything is ok

then i run

sudo srsue ue_rf.conf

it shows like this:

Active RF plugins: libsrsran_rf_zmq.so
Inactive RF plugins: 
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://127.0.0.1:2001,rx_port=tcp://127.0.0.1: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://127.0.0.1:2000
CH0 tx_port=tcp://127.0.0.1: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=1134
Random Access Complete.     c-rnti=0x4601, ta=0
RRC Connected
Received RRC Release

the received RRC Release, I have already set the cu_cp: inactivity_timer: 7200 in gnb_zmq.yaml

Setup Details

CPU: Intel Core i9-13900H
Ubuntu: 22.04
srsran commit: e73b461
srs4g commit: srsran/srsRAN_4G@ec29b0c

Expected Behavior

the right show maybe like this:

Attaching UE...
Random Access Transmission: prach_occasion=0, preamble_index=0, ra-rnti=0x39, tti=2094
Random Access Complete.     c-rnti=0x4602, ta=0
RRC Connected
PDU Session Establishment successful. IP: 10.45.1.2
RRC NR reconfiguration successful.

Actual Behaviour

Attaching UE...
Random Access Transmission: prach_occasion=0, preamble_index=0, ra-rnti=0x39, tti=1134
Random Access Complete.     c-rnti=0x4601, ta=0
RRC Connected
Received RRC Release
@pgawlowicz
Copy link
Collaborator

could you send your log files (gnb, srsue and core network)?

@liumr3
Copy link
Author

liumr3 commented Oct 14, 2024

could you send your log files (gnb, srsue and core network)?

2024-10-14T08:08:59.822377 [PHY1-NR] [I] [ 5242] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5246
2024-10-14T08:08:59.843419 [PHY1-NR] [I] [ 5262] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5266
2024-10-14T08:08:59.864463 [PHY1-NR] [I] [ 5282] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5286
2024-10-14T08:08:59.885558 [PHY1-NR] [I] [ 5302] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5306
2024-10-14T08:08:59.906740 [PHY1-NR] [I] [ 5322] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5326
2024-10-14T08:08:59.928309 [PHY1-NR] [I] [ 5342] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5346
2024-10-14T08:08:59.949557 [PHY1-NR] [I] [ 5362] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5366
2024-10-14T08:08:59.970892 [PHY1-NR] [I] [ 5382] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5386
2024-10-14T08:08:59.992069 [PHY1-NR] [I] [ 5402] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5406
2024-10-14T08:09:00.013168 [PHY1-NR] [I] [ 5422] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5426
2024-10-14T08:09:00.034322 [PHY1-NR] [I] [ 5442] PUCCH: cc=0, f=2 prb=2:1 symb=4:2 rnti=0x4601 cqi=15 , tti_tx=5446

this is srsue log

2024-10-14T08:11:39.797868 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=4usec latency_hist=[999, 1, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:40.855333 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=3usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:41.925007 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=5usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:42.987781 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=6usec latency_hist=[997, 2, 0, 1, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:44.047635 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=4usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:45.131254 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=7usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:46.207354 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=8usec latency_hist=[990, 9, 1, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:47.266207 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=4usec latency_hist=[998, 2, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:48.322127 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=3usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:49.378135 [METRICS ] [I] Cell Scheduler Metrics: error_indications=0 mean_latency=4usec latency_hist=[1000, 0, 0, 0, 0, 0, 0, 0, 0, 0]
2024-10-14T08:11:50.439255 [METRICS ] [I] Cell Scheduler Metrics: error_imingrui

this is gnb log

@liumr3
Copy link
Author

liumr3 commented Oct 14, 2024 •
edited
Loading

could you send your log files (gnb, srsue and core network)?

this is open5gs amf log,i don't use docker to run open5gs ,i use sudo apt-get install open5gs

10/14 14:39:36.642: [app] INFO: File Logging: '/var/log/open5gs/amf.log' (../lib/app/ogs-init.c:136)
10/14 14:39:36.644: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.200:7777] (../lib/sbi/context.c:474)
10/14 14:39:36.644: [metrics] INFO: metrics_server() [http://10.53.1.2]:9090 (../lib/metrics/prometheus/context.c:299)
10/14 14:39:36.644: [sbi] INFO: NF Service [namf-comm] (../lib/sbi/context.c:1829)
10/14 14:39:36.644: [sbi] INFO: nghttp2_server() [http://10.53.1.2]:38412 (../lib/sbi/nghttp2-server.c:424)
10/14 14:39:36.644: [amf] INFO: ngap_server() [10.53.1.2]:38412 (../src/amf/ngap-sctp.c:61)
10/14 14:39:36.644: [sctp] INFO: AMF initialize...done (../src/amf/app.c:33)
10/14 14:39:36.646: [sbi] INFO: [148c3558-89f7-41ef-8c85-cbee34a40cc8] NF registered [Heartbeat:10s] (../lib/sbi/nf-sm.c:208)
10/14 14:39:36.648: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.648: [sbi] INFO: [148ccba8-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.647420+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.648: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.648: [sbi] INFO: [148cd38c-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.647585+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.648: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.648: [sbi] INFO: [148cd8aa-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.647718+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.648: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.648: [sbi] INFO: [148cdc42-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.647803+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.649: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.649: [sbi] INFO: [148cde4a-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.647855+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.649: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.649: [sbi] INFO: [148ce674-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.648063+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:39:36.649: [sbi] INFO: NF EndPoint(addr) setup [127.0.0.10:7777] (../lib/sbi/nnrf-handler.c:949)
10/14 14:39:36.649: [sbi] INFO: [148cee62-89f7-41ef-99f3-4b8c2509ba53] Subscription created until 2024-10-15T14:39:36.648267+08:00 [duration:86400000000,validity:86400.000000,patch:43200.000000] (../lib/sbi/nnrf-handler.c:868)
10/14 14:41:41.102: [amf] INFO: gNB-N2 accepted[10.53.1.1]:37039 in ng-path module (../src/amf/ngap-sctp.c:113)
10/14 14:41:41.103: [amf] INFO: gNB-N2 accepted[10.53.1.1] in master_sm module (../src/amf/amf-sm.c:796)
10/14 14:41:41.106: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1238)
10/14 14:41:41.106: [amf] INFO: gNB-N2[10.53.1.1] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:842)
10/14 14:43:03.548: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:435)
10/14 14:43:03.548: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2694)
10/14 14:43:03.548: [amf] INFO:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] TAC[7] CellID[0x66c000] (../src/amf/ngap-handler.c:596)
10/14 14:43:03.548: [amf] INFO: [suci-0-001-01-0000-0-0-0123456780] Unknown UE by SUCI (../src/amf/context.c:1861)
10/14 14:43:03.548: [amf] INFO: [Added] Number of AMF-UEs is now 1 (../src/amf/context.c:1638)
10/14 14:43:03.549: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1220)
10/14 14:43:03.549: [gmm] INFO: [suci-0-001-01-0000-0-0-0123456780]    SUCI (../src/amf/gmm-handler.c:174)
10/14 14:43:03.550: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/14 14:43:03.550: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)
10/14 14:43:03.717: [amf] INFO: UE Context Release [Action:3] (../src/amf/ngap-handler.c:1726)
10/14 14:43:03.717: [amf] INFO:     RAN_UE_NGAP_ID[0] AMF_UE_NGAP_ID[1] (../src/amf/ngap-handler.c:1727)
10/14 14:43:03.717: [amf] INFO:     SUCI[suci-0-001-01-0000-0-0-0123456780] (../src/amf/ngap-handler.c:1731)
10/14 14:43:03.717: [amf] INFO: [Removed] Number of gNB-UEs is now 0 (../src/amf/context.c:2701)
10/14 14:43:03.717: [amf] INFO: [Removed] Number of AMF-UEs is now 0 (../src/amf/context.c:1735)

@pgawlowicz
Copy link
Collaborator

so the core network rejects the UE:

10/14 14:43:03.548: [amf] INFO: [suci-0-001-01-0000-0-0-0123456780] Unknown UE by SUCI (../src/amf/context.c:1861)
...
10/14 14:43:03.550: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/14 14:43:03.550: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)
10/14 14:43:03.717: [amf] INFO: UE Context Release [Action:3] (../src/amf/ngap-handler.c:1726)

Did you add the UE details to the subscriber database?

@liumr3
Copy link
Author

liumr3 commented Oct 15, 2024

so the core network rejects the UE:

10/14 14:43:03.548: [amf] INFO: [suci-0-001-01-0000-0-0-0123456780] Unknown UE by SUCI (../src/amf/context.c:1861)
...
10/14 14:43:03.550: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/14 14:43:03.550: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)
10/14 14:43:03.717: [amf] INFO: UE Context Release [Action:3] (../src/amf/ngap-handler.c:1726)

Did you add the UE details to the subscriber database?

I add UE details to the subscriber database:

open5gs> db.subsribers.find()
[
  {
    _id: ObjectId('670ddfaa939dcf943bfe6911'),
    imsi: '001010123456780',
    key: '00112233445566778899aabbccddeeff',
    opc: '63BFA50EE6523365FF14C1F45F88737D',
    sqn: 0,
    pdn: [ { apn: 'srsran', qos: { qci: 9 } } ]
  }
]

nonthing changed

@pgawlowicz
Copy link
Collaborator

could you share your config and log files?

@liumr3
Copy link
Author

liumr3 commented Oct 15, 2024 •
edited
Loading

could you share your config and log files?
ue.log
gnb.log
gnb_zmq.txt
ue_zmq.txt
amf.txt
amf.log

截图 2024-10-15 19-29-45
截图 2024-10-15 19-29-38
截图 2024-10-15 19-29-31
截图 2024-10-15 19-28-57

@pgawlowicz
Copy link
Collaborator

Could you try to set Authentication Management Field (AMF) to 8000.
Could you assign IPv4 address like here?
image

@liumr3
Copy link
Author

liumr3 commented Oct 16, 2024

Could you try to set Authentication Management Field (AMF) to 8000. Could you assign IPv4 address like here? image
i do it as your follows, unfornately, the problems still alive
截图 2024-10-16 10-15-11
amf.log

@pgawlowicz
Copy link
Collaborator

There is some issue in communication between amf and gmm:

10/16 09:47:15.081: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1220)
10/16 09:47:15.081: [gmm] INFO: [suci-0-001-01-0000-0-0-0123456780]    SUCI (../src/amf/gmm-handler.c:174)
10/16 09:47:15.083: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/16 09:47:15.083: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)

Could you try with the dockerized open5gs version?

@liumr3
Copy link
Author

liumr3 commented Oct 17, 2024

There is some issue in communication between amf and gmm:

10/16 09:47:15.081: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1220)
10/16 09:47:15.081: [gmm] INFO: [suci-0-001-01-0000-0-0-0123456780]    SUCI (../src/amf/gmm-handler.c:174)
10/16 09:47:15.083: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/16 09:47:15.083: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)

Could you try with the dockerized open5gs version?

I found the problem in amf.yaml is

10/18 01:09:05.633: [gmm] ERROR: [suci-0-001-01-0000-0-0-0123456780] HTTP response error [400] (../src/amf/gmm-sm.c:1800)
10/18 01:09:05.633: [amf] WARNING: [suci-0-001-01-0000-0-0-0123456780] Registration reject [95] (../src/amf/nas-path.c:211)

and I check the difference your subscribe and me, I don't know how can you get the IMEISV=012345670000101, it's different from the imei = 353490069873319 in UE_ZMQ.conf, and your SQN=64 i also don't have.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@pgawlowicz @liumr3