search

openaicellular / oaic

Core software for Open AI Cellular
https://openaicellular.github.io/oaic/
GNU General Public License v3.0
63 stars 21 forks source link

'Error reading from SCTP socket' and 'unknown E2-like cmd' when running Developing a custom xApp in Python section #149

Open thusithathilina opened 4 months ago

thusithathilina commented 4 months ago

I'm trying to run the "Developing a custom xApp in Python" section as mentioned in the https://openaicellular.github.io/oaic/xapp_python.html#connecting-to-srsran. However, I'mr receiving the following error log when starting the eNb.

---  Software Radio Systems LTE eNodeB  ---

Couldn't open , trying /root/.config/srsran/enb.conf
Reading configuration file /root/.config/srsran/enb.conf...
Couldn't open sib.conf, trying /root/.config/srsran/sib.conf
Couldn't open rr.conf, trying /root/.config/srsran/rr.conf
Couldn't open rb.conf, trying /root/.config/srsran/rb.conf
2024-05-16T01:06:18.510855 [ENB    ] [I] Using binary srsenb/src/srsenb with arguments: --ric.agent.log_level=debug --log.filename=stdout --ric.agent.remote_ipv4_addr=118.138.245.218 --ric.agent.remote_port=30864 --ric.agent.local_ipv4_addr=118.138.245.218 --ric.agent.local_port=38071 --scheduler.pusch_mcs=28

Built in RelWithDebInfo mode using commit 384d343 on branch HEAD.

2024-05-16T01:06:18.897350 [ENB    ] [I] Built in RelWithDebInfo mode using commit 384d343 on branch HEAD.
2024-05-16T01:06:18.899703 [ENB    ] [I] Using sync queue size of one for ZMQ based radio.
2024-05-16T01:06:19.090452 [COMN   ] [D] [    0] Setting RTO_INFO options on SCTP socket. Association 0, Initial RTO 3000, Minimum RTO 1000, Maximum RTO 6000
2024-05-16T01:06:19.090454 [COMN   ] [D] [    0] Setting SCTP_INITMSG options on SCTP socket. Max attempts 3, Max init attempts timeout 5000
2024-05-16T01:06:19.090469 [COMN   ] [D] [    0] Successfully bound to address 127.0.1.1:0
2024-05-16T01:06:19.090609 [COMN   ] [D] [    0] RxSockets: socket fd=5 has been registered.
2024-05-16T01:06:19.090670 [COMN   ] [D] [    0] Successfully bound to address 127.0.1.1:2152
2024-05-16T01:06:19.090672 [COMN   ] [D] [    0] RxSockets: socket fd=6 has been registered.
Opening 2 channels in RF device=zmq with args=fail_on_disconnect=true,tx_port0=tcp://*:2000,rx_port0=tcp://localhost:2001,tx_port1=tcp://*:2100,rx_port1=tcp://localhost:2101,id=enb,base_srate=23.04e6
Available RF device list: UHD  zmq
CHx base_srate=23.04e6
CHx id=enb
Current sample rate is 1.92 MHz with a base rate of 23.04 MHz (x12 decimation)
CH0 rx_port=tcp://localhost:2001
CH0 tx_port=tcp://*:2000
CH0 fail_on_disconnect=true
CH1 rx_port=tcp://localhost:2101
CH1 tx_port=tcp://*:2100
Current sample rate is 11.52 MHz with a base rate of 23.04 MHz (x2 decimation)
Current sample rate is 11.52 MHz with a base rate of 23.04 MHz (x2 decimation)
Setting frequency: DL=2680.0 Mhz, UL=2560.0 MHz for cc_idx=0 nof_prb=50
2024-05-16T01:06:20.484378 [RIC    ] [D] [    0] log_level = debug
2024-05-16T01:06:20.484383 [E2SM   ] [I] [    0] kpm: building function list
Setting frequency: DL=1842.5 Mhz, UL=1747.5 MHz for cc_idx=1 nof_prb=52
2024-05-16T01:06:20.486756 [RIC    ] [I] [    0] added model ORAN-E2SM-KPM
2024-05-16T01:06:20.486771 [RIC    ] [I] [    0] added model ORAN-E2SM-gNB-NRT
2024-05-16T01:06:20.486772 [RIC    ] [D] [    0] model ORAN-E2SM-KPM function ORAN-E2SM-KPM (function_id 0) enabled and registered
2024-05-16T01:06:20.486772 [RIC    ] [D] [    0] model ORAN-E2SM-gNB-NRT function ORAN-E2SM-gNB-NRT (function_id 1) enabled and registered
2024-05-16T01:06:20.486773 [RIC    ] [D] [    0] RIC state -> INITIALIZED

==== eNodeB started ===
Type <t> to view trace
2024-05-16T01:06:20.491051 [COMN   ] [D] [    0] Setting RTO_INFO options on SCTP socket. Association 0, Initial RTO 3000, Minimum RTO 1000, Maximum RTO 6000
2024-05-16T01:06:20.491053 [COMN   ] [D] [    0] Setting SCTP_INITMSG options on SCTP socket. Max attempts 3, Max init attempts timeout 5000
2024-05-16T01:06:20.491065 [COMN   ] [D] [    0] Successfully bound to address 118.138.245.218:38071
2024-05-16T01:06:20.493820 [COMN   ] [D] [    0] RxSockets: socket fd=20 has been registered.
2024-05-16T01:06:20.493821 [RIC    ] [D] [    0] RIC state -> CONNECTED
2024-05-16T01:06:20.493822 [RIC    ] [I] [    0] connected to RIC on 118.138.245.218
2024-05-16T01:06:20.493823 [RIC    ] [I] [    0] E2-like interface enabled, skipping setup request
2024-05-16T01:06:20.493823 [RIC    ] [D] [    0] RIC state -> ESTABLISHED
2024-05-16T01:06:20.496557 [RIC    ] [I] [    0] received e2-like message: E2-like request at 01:06:20
2024-05-16T01:06:20.496588 [RIC    ] [I] [    0] wrote e2-like message to agent_cmd.bin
2024-05-16T01:06:20.496596 [RIC    ] [I] [    0] Timestamp: 1715821580.4960001
2024-05-16T01:07:25.074975 [RIC    ] [E] [    0] Error reading from SCTP socket: Connection timed out
2024-05-16T01:07:25.075113 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075127 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075128 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075129 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075129 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075130 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075131 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075132 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075133 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075134 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075134 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075135 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075136 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075136 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075137 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075138 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075138 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075139 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075140 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075140 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075141 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075141 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075142 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075143 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075143 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075144 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075144 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075145 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075146 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075146 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075147 [RIC    ] [E] [    0] failed to send 16384 bytes
2024-05-16T01:07:25.075148 [RIC    ] [I] [    0] sent I/Q buffer
2024-05-16T01:07:25.075162 [RIC    ] [D] [    0] received sctp event 32770; ignoring

Additionally, when I try to connect the UE it keeps prints the following log message on the eNB console unknown E2-like cmd received: E

nathanstep55 commented 4 months ago

Hi, have you tried to look at the logs for the xApp's Kubernetes pod? Based on this log, it seems that srsRAN was able to successfully connect to the xApp and send the initial request, but the SCTP socket timed out afterwards, hinting that either a problem with the network occurred or the xApp crashed.

Unknown E2-like command: E refers to the initial E2-like request which is sent from the xApp to nodeB (the command is the first character of the message). Since no control messages are sent afterwards, it is stuck on the initial request.

Refer to the following command to get the pod logs for the xApp (replace with the name of your xApp’s pod): sudo kubectl logs -n ricxapp <podname>

2timesfer commented 4 months ago

Hi, have you tried to look at the logs for the xApp's Kubernetes pod? Based on this log, it seems that srsRAN was able to successfully connect to the xApp and send the initial request, but the SCTP socket timed out afterwards, hinting that either a problem with the network occurred or the xApp crashed.

Unknown E2-like command: E refers to the initial E2-like request which is sent from the xApp to nodeB (the command is the first character of the message). Since no control messages are sent afterwards, it is stuck on the initial request.

Refer to the following command to get the pod logs for the xApp (replace with the name of your xApp’s pod): sudo kubectl logs -n ricxapp <podname>

I also get the same error. The logs from ricxapp says only: sudo kubectl logs -n ricxapp ricxapp-ric-app-ml [INFO] E2-like enabled, connecting using SCTP on hostIP [INFO] Server started [INFO] Connected by ('hostIP', xappPORT) [INFO] Sent E2-like request [INFO] Receiving I/Q data...

thusithathilina commented 4 months ago

I was able to overcome the connection timeout by redeploying the xapp. However, I guess that shouldn't be the proper fix. But still it shows the unknown E2-like cmd received: E message.