gNB not able to run using x300

[mubk00]

Issue Description

I wanted to give srsgNB a try. I am currently testing srsgNB (w/ USRP X300) and with OAI5GC. The problem I am having is, I am unable to create a radio session. I tried to look at the gNB logs, but it seems like there is nothing there.

I can reproduce the issue mentioned in #7, but changing the mentioned parameters did not help. If anyone knows what I may be doing wrong, please do let me know.

Available radio types: uhd. --== srsRAN gNB (commit 0523be699) ==-- [INFO] [UHD] linux; GNU C++ version 11.3.0; Boost_107400; UHD_4.2.0.HEAD-0 Making USRP object with args 'type=x300,master_clock_rate=184.32e6,send_frame_size=8000,recv_frame_size=8000' srsGNB ERROR: Unable to create radio session.

amf:
  addr: 192.168.70.132                # The address or hostname of the AMF.
  bind_addr: 192.168.70.129              # A local IP that the gNB binds to for traffic from the AMF.

rf_driver:
  device_driver: uhd                # The RF driver name.
  device_args: type=x300            # Optionally pass arguments to the selected RF driver.
  clock: gpsdo                      # Specify the clock source used by the RF.
  sync: gpsdo                       # Specify the sync source used by the RF.
  srate: 11.52                      # RF sample rate might need to be adjusted according to selected bandwidth.
  tx_gain: 20.5                       # Transmit gain of the RF might need to adjusted to the given situation.
  rx_gain: 50.0                       # Receive gain of the RF might need to adjusted to the given situation.

cell_cfg:
  dl_arfcn: 632628                  # ARFCN of the downlink carrier (center frequency).
  band: 78                          # The NR band.
  channel_bandwidth_MHz: 10         # Bandwith in MHz. Number of PRBs will be automatically derived.
  common_scs: 30                    # Subcarrier spacing in kHz used for data.
  plmn: "99970"                     # PLMN broadcasted by the gNB.
  tac: 1                            # Tracking area code (needs to match the core configuration).
  pci: 1                            # Physical cell ID.
log:
  filename: /tmp/gnb.log            # Path of the log file.
  all_level: warning                # Logging level applied to all layers.
pcap:
  mac_enable: true                 # Set to true to enable MAC-layer PCAPs.
  mac_filename: /tmp/gnb_mac.pcap   # Path where the MAC PCAP is stored.
  ngap_enable: true                # Set to true to enable NGAP PCAPs.
  ngap_filename: /tmp/gnb_ngap.pcap # Path where the NGAP PCAP is stored.

The output of _uhd_find_devices

[INFO] [UHD] linux; GNU C++ version 11.3.0; Boost_107400; UHD_4.2.0.HEAD-0
--------------------------------------------------
-- UHD Device 0
--------------------------------------------------
Device Address:
    serial: 3243FD3
    addr: 192.168.40.2
    fpga: HG
    name:
    product: X300
    type: x300

[mubk00]

I just would like to mention - The USRP detects fine, so that is most likely not the issue. I've previously tested it with other eNB and gNB solutions, and it appears to function perfectly.

[andrepuschmann]

Check the clock and sync fields. You're likely not having the GPSDO installed or it can't get the lock. But I agree we should produce a better log message if that's really the case.

[mubk00]

Check the clock and sync fields. You're likely not having the GPSDO installed or it can't get the lock. But I agree we should produce a better log message if that's really the case.

Thanks for the fast response! I changed the 'clock' and 'sync' to internal, and it seems to work fine now.

And, yes, I agree that having better logs makes it much easier to troubleshoot, but I understand that the project is still in its early stages, so hopefully this will improve in the future :)

[mubk00]

Just a comment after re-trying. I wasn't seeing any sort of notification e.g: late packet, underflow, or even overflow message upon running.

Making USRP object with args 'type=x300,master_clock_rate=184.32e6,send_frame_size=8000,recv_frame_size=8000'
[WARNING] [0/Radio#0] Attempting to set tick rate to 0. Skipping.
Cell pci=1, bw=10 MHz, dl_arfcn=632628 (n78), dl_freq=3489.42 MHz, dl_ssb_arfcn=632640, ul_freq=3489.42 MHz
==== gNodeB started ===

However, after a while, when I stopped the gNB, this is what I got in the logs:

2023-03-06T18:12:37.469162 [RF ] [W] Radio realtime event: Type=start-of-burst Source=tx Timestamp=38108857 2023-03-06T18:14:10.834193 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:14:10.834195 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:16:31.679617 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:16:31.679620 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:23:38.586253 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:23:38.586257 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:25:22.584407 [RF ] [W] Radio realtime event: Type=end-of-burst Source=tx Timestamp=na 2023-03-06T18:25:22.585217 [ALL ] [E] Cannot push anymore tasks into the radio worker queue. maximum size is 2048

Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 seems to indicate a synchronization issue with the message received by the gNB which is not synced with the current timing. And the last message appears to suggest the queue's limit size for the worker task has reached its maximum size.

I would assume the clock is causing the problem here (at least for the first problem). Do you have any idea what the problem is?

[mubk00]

Just a quick update: I was able to resolve the issue that was previously mentioned. I no longer find any issues in the logs file. Thanks.

Nonetheless, I'm experiencing a second issue with SCTP (the payload protocol identifier is not specified in SCTP), which was also mentioned in issue #21. I'm unsure whether I should create a new issue or if I should stick with this one to make it simpler for others who may be experiencing the same issue. Please let me know.

EDIT: I'll move to #21

[2023-03-07T09:17:36.068790] [AMF] [sctp   ] [debug] SCTP Association Change event received
[2023-03-07T09:17:36.068810] [AMF] [sctp   ] [debug] Add new association with id (17812)
[2023-03-07T09:17:36.068823] [AMF] [sctp   ] [info ] ----------------------
[2023-03-07T09:17:36.068825] [AMF] [sctp   ] [info ] Local addresses:
[2023-03-07T09:17:36.068830] [AMF] [sctp   ] [info ]     - IPv4 Addr: 192.168.70.132
[2023-03-07T09:17:36.068833] [AMF] [sctp   ] [info ] ----------------------
[2023-03-07T09:17:36.068838] [AMF] [sctp   ] [info ] Peer addresses:
[2023-03-07T09:17:36.068840] [AMF] [sctp   ] [info ]     - IPv4 Addr: 192.168.70.129
[2023-03-07T09:17:36.068848] [AMF] [sctp   ] [info ] ----------------------
[2023-03-07T09:17:36.068850] [AMF] [ngap   ] [debug] Ready to handle new NGAP SCTP association request (id 17812)
[2023-03-07T09:17:36.068853] [AMF] [ngap   ] [debug] Create a new gNB context with assoc_id (17812)
[2023-03-07T09:17:36.070346] [AMF] [sctp   ] [error] Received data from peer with unsolicited PPID (0), 
expecting (60)
[2023-03-07T09:17:47.159755] [AMF] [amf_app] [info ]
[2023-03-07T09:17:47.159770] [AMF] [amf_app] [info ] |--------------------------------------------------------------                                                                         --------------------------------------------------|
[2023-03-07T09:17:47.159773] [AMF] [amf_app] [info ] |----------------------------------------------------gNBs' info                                                                         rmation-------------------------------------------|
[2023-03-07T09:17:47.159774] [AMF] [amf_app] [info ] |    Index    |      Status      |       Global ID       |                                                                                gNB Name       |               PLMN             |
[2023-03-07T09:17:47.159775] [AMF] [amf_app] [info ] |      -      |          -       |           -           |                                                                                    -          |               -                |

[asheeshtripathi]

Just a comment after re-trying. I wasn't seeing any sort of notification e.g: late packet, underflow, or even overflow message upon running.

Making USRP object with args 'type=x300,master_clock_rate=184.32e6,send_frame_size=8000,recv_frame_size=8000'
[WARNING] [0/Radio#0] Attempting to set tick rate to 0. Skipping.
Cell pci=1, bw=10 MHz, dl_arfcn=632628 (n78), dl_freq=3489.42 MHz, dl_ssb_arfcn=632640, ul_freq=3489.42 MHz
==== gNodeB started ===

However, after a while, when I stopped the gNB, this is what I got in the logs:

2023-03-06T18:12:37.469162 [RF ] [W] Radio realtime event: Type=start-of-burst Source=tx Timestamp=38108857 2023-03-06T18:14:10.834193 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:14:10.834195 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:16:31.679617 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:16:31.679620 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:23:38.586253 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:23:38.586257 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:25:22.584407 [RF ] [W] Radio realtime event: Type=end-of-burst Source=tx Timestamp=na 2023-03-06T18:25:22.585217 [ALL ] [E] Cannot push anymore tasks into the radio worker queue. maximum size is 2048

Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 seems to indicate a synchronization issue with the message received by the gNB which is not synced with the current timing. And the last message appears to suggest the queue's limit size for the worker task has reached its maximum size.

I would assume the clock is causing the problem here (at least for the first problem). Do you have any idea what the problem is?

How you resolved the log issue: I also see same in the gNb logs with x310: The clock and sync is set 'internal'

[ismagom]

Just a comment after re-trying. I wasn't seeing any sort of notification e.g: late packet, underflow, or even overflow message upon running.

Making USRP object with args 'type=x300,master_clock_rate=184.32e6,send_frame_size=8000,recv_frame_size=8000'
[WARNING] [0/Radio#0] Attempting to set tick rate to 0. Skipping.
Cell pci=1, bw=10 MHz, dl_arfcn=632628 (n78), dl_freq=3489.42 MHz, dl_ssb_arfcn=632640, ul_freq=3489.42 MHz
==== gNodeB started ===

However, after a while, when I stopped the gNB, this is what I got in the logs:

2023-03-06T18:12:37.469162 [RF ] [W] Radio realtime event: Type=start-of-burst Source=tx Timestamp=38108857 2023-03-06T18:14:10.834193 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:14:10.834195 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 120.14 while message corresponds to 120.13 2023-03-06T18:16:31.679617 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:16:31.679620 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 893.5 while message corresponds to 893.4 2023-03-06T18:23:38.586253 [FAPI ] [W] [ 0.0] Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:23:38.586257 [FAPI ] [W] [ 0.0] Received UL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 2023-03-06T18:25:22.584407 [RF ] [W] Radio realtime event: Type=end-of-burst Source=tx Timestamp=na 2023-03-06T18:25:22.585217 [ALL ] [E] Cannot push anymore tasks into the radio worker queue. maximum size is 2048

Received DL_TTI.request message out of time. Current slot is 575.18 while message corresponds to 575.17 seems to indicate a synchronization issue with the message received by the gNB which is not synced with the current timing. And the last message appears to suggest the queue's limit size for the worker task has reached its maximum size. I would assume the clock is causing the problem here (at least for the first problem). Do you have any idea what the problem is?

How you resolved the log issue: I also see same in the gNb logs with x310: The clock and sync is set 'internal'

HI @asheeshtripathi , I replied you in the other thread you opened. These messages are caused by real-time failures.

[Bhuvaneshnetcon]

hi @andrepuschmann , Here I am trying to connect open5gs core and UHD ettus usrp b210 sdr by srsran with my real UE. Am also facing this thing Late: 108; Underflow: 39; Overflow: 10. How can I rectify it. Kindly help me. Even I receive real time failure in RF ,FAPI, low-phy in gnb.log using srsran and time differs between srsran installed machine and gnb.log file in srsran.