root@nrtricpoc:~/RAN/riaB/sdran-in-a-box# make test-user-plane
Helm values.yaml file: /root/RAN/riaB/sdran-in-a-box//sdran-in-a-box-values-master-stable.yaml
HEAD is now at 9f79ab8 Fix the default SRIOV resource name for UPF user plane interfaces
HEAD is now at b3659f4 Bumping chart versions (#1131)
*** T1: Internal network test: ping 192.168.250.1 (Internal router IP) ***
PING 192.168.250.1 (192.168.250.1) from 172.250.255.254 oaitun_ue1: 56(84) bytes of data.
--- 192.168.250.1 ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2036ms
*** T2: Internet connectivity test: ping to 8.8.8.8 ***
PING 8.8.8.8 (8.8.8.8) from 172.250.255.254 oaitun_ue1: 56(84) bytes of data.
--- 8.8.8.8 ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2029ms
*** T3: DNS test: ping to google.com ***
PING google.com (172.217.15.110) from 172.250.255.254 oaitun_ue1: 56(84) bytes of data.
--- google.com ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2054ms
mk/test-cases.mk:8: recipe for target 'test-user-plane' failed
make: *** [test-user-plane] Error 1
root@nrtricpoc:~/RAN/riaB/sdran-in-a-box# kubectl get pods -A
NAMESPACE NAME READY STATUS RESTARTS AGE
default router 1/1 Running 0 8m55s
kube-system atomix-controller-6989fbdbf-kwf4t 1/1 Running 0 8m2s
kube-system atomix-raft-storage-controller-746fbdb557-pt2bz 1/1 Running 0 7m45s
kube-system calico-kube-controllers-59466bfc9b-j5nzv 1/1 Running 0 11m
kube-system calico-node-65dgh 1/1 Running 0 11m
kube-system coredns-bbb7d66cd-6d9td 1/1 Running 0 11m
kube-system dns-autoscaler-6f895b87bc-w7cmt 1/1 Running 0 11m
kube-system kube-apiserver-node1 1/1 Running 0 12m
kube-system kube-controller-manager-node1 1/1 Running 1 12m
kube-system kube-multus-ds-amd64-kdfzh 1/1 Running 0 11m
kube-system kube-proxy-d2srx 1/1 Running 0 11m
kube-system kube-scheduler-node1 1/1 Running 1 12m
kube-system nodelocaldns-5jtg4 1/1 Running 0 11m
kube-system onos-operator-app-78f8f6b998-dpg5w 1/1 Running 0 7m32s
kube-system onos-operator-topo-7dc455b468-pxp24 1/1 Running 0 7m32s
riab cassandra-0 1/1 Running 0 7m7s
riab hss-0 1/1 Running 0 7m8s
riab mme-0 4/4 Running 0 7m8s
riab oai-enb-cu-0 1/1 Running 0 5m
riab oai-enb-du-0 1/1 Running 1 3m48s
riab oai-ue-0 1/1 Running 0 2m36s
riab onos-a1t-77954946fc-4pcnb 2/2 Running 0 6m3s
riab onos-cli-64988df4d9-kvhlv 1/1 Running 0 6m3s
riab onos-config-5cf5d77449-87hhf 4/4 Running 0 6m3s
riab onos-consensus-store-0 1/1 Running 0 6m2s
riab onos-e2t-5b9c6df69-7bjkn 3/3 Running 0 6m3s
riab onos-kpimon-5b6f976bf9-x8vr2 2/2 Running 0 6m3s
riab onos-rsm-6c9d759466-hlnhn 2/2 Running 0 6m3s
riab onos-topo-56df7985d6-ltkl6 3/3 Running 0 6m3s
riab onos-uenib-6c8c644f54-v8j27 3/3 Running 0 6m3s
riab pcrf-0 1/1 Running 0 7m7s
riab spgwc-0 2/2 Running 0 7m7s
riab upf-0 4/4 Running 0 6m21s
root@nrtricpoc:~/RAN/riaB/sdran-in-a-box# make test-kpimon
Helm values.yaml file: /root/RAN/riaB/sdran-in-a-box//sdran-in-a-box-values-master-stable.yaml
HEAD is now at 9f79ab8 Fix the default SRIOV resource name for UPF user plane interfaces
HEAD is now at b3659f4 Bumping chart versions (#1131)
*** Get KPIMON result through CLI ***
Node ID Cell Object ID Cell Global ID Time RRC.ConnEstabAtt.sum RRC.ConnEstabSucc.sum RRC.ConnMax RRC.ConnMean RRC.ConnReEstabAtt.sum
e2:4/e00/2/64 1 e0000 06:37:53.0 2 1 2 1 0
root@nrtricpoc:~/RAN/riaB/sdran-in-a-box# make test-rsm-dataplane
Helm values.yaml file: /root/RAN/riaB/sdran-in-a-box//sdran-in-a-box-values-master-stable.yaml
HEAD is now at 9f79ab8 Fix the default SRIOV resource name for UPF user plane interfaces
HEAD is now at b3659f4 Bumping chart versions (#1131)
*** Test downlink traffic (UDP) ***
sudo apt install -y iperf3
Reading package lists... Done
Building dependency tree
Reading state information... Done
iperf3 is already the newest version (3.1.3-1).
The following packages were automatically installed and are no longer required:
python-argcomplete python-ipaddr
Use 'sudo apt autoremove' to remove them.
0 upgraded, 0 newly installed, 0 to remove and 22 not upgraded.
kubectl exec -it router -- apt install -y iperf3
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following extra packages will be installed:
libiperf0
The following NEW packages will be installed:
iperf3 libiperf0
0 upgraded, 2 newly installed, 0 to remove and 80 not upgraded.
Need to get 56.7 kB of archives.
After this operation, 236 kB of additional disk space will be used.
Get:1 http://archive.ubuntu.com/ubuntu/ trusty-backports/universe libiperf0 amd64 3.0.7-1~ubuntu14.04.1 [48.7 kB]
Get:2 http://archive.ubuntu.com/ubuntu/ trusty-backports/universe iperf3 amd64 3.0.7-1~ubuntu14.04.1 [7966 B]
Fetched 56.7 kB in 0s (347 kB/s)
Selecting previously unselected package libiperf0.
(Reading database ... 17318 files and directories currently installed.)
Preparing to unpack .../libiperf0_3.0.7-1~ubuntu14.04.1_amd64.deb ...
Unpacking libiperf0 (3.0.7-1~ubuntu14.04.1) ...
Selecting previously unselected package iperf3.
Preparing to unpack .../iperf3_3.0.7-1~ubuntu14.04.1_amd64.deb ...
Unpacking iperf3 (3.0.7-1~ubuntu14.04.1) ...
Setting up libiperf0 (3.0.7-1~ubuntu14.04.1) ...
Setting up iperf3 (3.0.7-1~ubuntu14.04.1) ...
Processing triggers for libc-bin (2.19-0ubuntu6.13) ...
iperf3 -s -B $(ip a show oaitun_ue1 | grep inet | grep -v inet6 | awk '{print $2}' | awk -F '/' '{print $1}') -p 5001 > /dev/null &
kubectl exec -it router -- iperf3 -u -c $(ip a show oaitun_ue1 | grep inet | grep -v inet6 | awk '{print $2}' | awk -F '/' '{print $1}') -p 5001 -b 20M -l 1450 -O 2 -t 12 --get-server-output
iperf3: error - unable to connect to server: Connection timed out
command terminated with exit code 1
mk/test-cases.mk:44: recipe for target 'test-rsm-dataplane' failed
make: *** [test-rsm-dataplane] Error 1
root@nrtricpoc:~/RAN/riaB/sdran-in-a-box# kubectl logs -f oai-enb-du-0 -n riab --previous
+ ENODEB=1
+ /opt/oai/bin/lte-softmodem -O /opt/oai/share/du.conf
[LOADER] library libNB_IoT.so is not loaded: libNB_IoT.so: cannot open shared object file: No such file or directory
[CONFIG] get parameters from libconfig /opt/oai/share/du.conf , debug flags: 0x00000000
[CONFIG] function config_libconfig_init returned 0
[CONFIG] config module libconfig loaded
[LIBCONFIG] config: 1/1 parameters successfully set, (1 to default value)
# /dev/cpu_dma_latency set to 0us
[LIBCONFIG] log_config: 3/3 parameters successfully set, (1 to default value)
[LIBCONFIG] log_config: 53/53 parameters successfully set, (48 to default value)
[LIBCONFIG] log_config: 53/53 parameters successfully set, (53 to default value)
[LIBCONFIG] log_config: 15/15 parameters successfully set, (15 to default value)
[LIBCONFIG] log_config: 15/15 parameters successfully set, (15 to default value)
log init done
Reading in command-line options
[LIBCONFIG] (root): 23/23 parameters successfully set, (19 to default value)
[LIBCONFIG] (root): 5/5 parameters successfully set, (4 to default value)
Getting ENBSParams
[LIBCONFIG] (root): 3/3 parameters successfully set, (1 to default value)
[LIBCONFIG] list L1s not found in config file /opt/oai/share/du.conf
[LIBCONFIG] list RUs not found in config file /opt/oai/share/du.conf
[LIBCONFIG] THREAD_STRUCT.[0]: 2/2 parameters successfully set, (0 to default value)
[CONFIG] parallel_conf is set to 2
[LIBCONFIG] THREAD_STRUCT.[0]: 2/2 parameters successfully set, (0 to default value)
[CONFIG] worker_conf is set to 1
Configuration: nb_rrc_inst 1, nb_L1_inst 0, nb_ru 0
[LIBCONFIG] loader: 2/2 parameters successfully set, (2 to default value)
[LIBCONFIG] loader.NB_IoT: 2/2 parameters successfully set, (1 to default value)
nb_nbiot_rrc_inst 0, nb_nbiot_L1_inst 0, nb_nbiot_macrlc_inst 0
[LIBCONFIG] TTracer: 4/4 parameters successfully set, (4 to default value)
configuring for RAU/RRU
CPU Freq is 2.095130
ITTI init, useMME: 1
[TMR] Starting itti queue: TASK_UNKNOWN as task 0
[TMR] Starting itti queue: TASK_TIMER as task 1
[TMR] Starting itti queue: TASK_L2L1 as task 2
[TMR] Starting itti queue: TASK_BM as task 3
[TMR] Starting itti queue: TASK_PHY_ENB as task 4
[TMR] Starting itti queue: TASK_MAC_ENB as task 5
[TMR] Starting itti queue: TASK_RLC_ENB as task 6
[TMR] Starting itti queue: TASK_RRC_ENB_NB_IoT as task 7
[TMR] Starting itti queue: TASK_PDCP_ENB as task 8
[TMR] Starting itti queue: TASK_DATA_FORWARDING as task 9
[TMR] Starting itti queue: TASK_END_MARKER as task 10
[TMR] Starting itti queue: TASK_RRC_ENB as task 11
[TMR] Starting itti queue: TASK_RRC_GNB as task 12
[TMR] Starting itti queue: TASK_RAL_ENB as task 13
[TMR] Starting itti queue: TASK_S1AP as task 14
[TMR] Starting itti queue: TASK_X2AP as task 15
[TMR] Starting itti queue: TASK_M2AP_ENB as task 16
[TMR] Starting itti queue: TASK_M2AP_MCE as task 17
[TMR] Starting itti queue: TASK_M3AP as task 18
[TMR] Starting itti queue: TASK_M3AP_MME as task 19
[TMR] Starting itti queue: TASK_M3AP_MCE as task 20
[TMR] Starting itti queue: TASK_SCTP as task 21
[TMR] Starting itti queue: TASK_ENB_APP as task 22
[TMR] Starting itti queue: TASK_GNB_APP as task 23
[TMR] Starting itti queue: TASK_MCE_APP as task 24
[TMR] Starting itti queue: TASK_MME_APP as task 25
[TMR] Starting itti queue: TASK_FLEXRAN_AGENT as task 26
[TMR] Starting itti queue: TASK_PHY_UE as task 27
[TMR] Starting itti queue: TASK_MAC_UE as task 28
[TMR] Starting itti queue: TASK_RLC_UE as task 29
[TMR] Starting itti queue: TASK_PDCP_UE as task 30
[TMR] Starting itti queue: TASK_RRC_UE as task 31
[TMR] Starting itti queue: TASK_NAS_UE as task 32
[TMR] Starting itti queue: TASK_RAL_UE as task 33
[TMR] Starting itti queue: TASK_MSC as task 34
[TMR] Starting itti queue: TASK_GTPV1_U as task 35
[TMR] Starting itti queue: TASK_UDP as task 36
[TMR] Starting itti queue: TASK_CU_F1 as task 37
[TMR] Starting itti queue: TASK_DU_F1 as task 38
[TMR] Starting itti queue: TASK_RIC_AGENT as task 39
[TMR] Starting itti queue: TASK_RIC_AGENT_DU as task 40
[LIBCONFIG] opt: 3/3 parameters successfully set, (3 to default value)
[OPT] OPT disabled
reported resolution = 1 ns
[HW] Version: Branch: develop-onf Abrev. Hash: 0227937 Date: Thu Mar 17 22:47:36 2022 +0900
Runtime table
[PHY] RC.eNB = 0x39d9720
[LIBCONFIG] list L1s not found in config file /opt/oai/share/du.conf
[PHY] No L1s configuration found[PHY] RC.eNB[0] = 0x39d97f0
[PHY] RC.eNB[0][0] = 0x7f2876577010
[PHY] read_config_and_init() RC.nb_L1_inst: 0
[LIBCONFIG] MACRLCs.[0]: 21/21 parameters successfully set, (4 to default value)
[LIBCONFIG] MACRLCs.[0]: 21/21 parameters successfully set, (4 to default value)
[MAC] [MAIN] Init function start:nb_macrlc_inst=1
[PDCP] PDCP layer has been initialized
Configuring F1 interfaces for MACRLC
[ENB_APP] **************** vnf_port:50001
[ENB_APP] nfapi running mode: VNF
3780.485580: 0x04: 2031998784: [VNF] configure_nfapi_vnf() vnf.p7_vnfs[0].config:0x39faf60 VNF ADDRESS:10.0.0.7:50001
3780.485599: 0x04: 2031998784: [VNF] Creating VNF NFAPI start thread configure_nfapi_vnf
3780.510921: 0x04: 2031998784: [VNF] Created VNF NFAPI start thread configure_nfapi_vnf
[ENB_APP] **************** RETURNED FROM configure_nfapi_vnf() vnf_port:50001
[ENB_APP] sched mode = default 0 [default]
[ENB_APP] using default scheduler DL algo 'round_robin_dl'
[MAC] read_config_and_init() RC.nb_macrlc_inst: 1
[LIBCONFIG] (root): 3/3 parameters successfully set, (1 to default value)
[LIBCONFIG] eNBs.[0]: 20/20 parameters successfully set, (11 to default value)
[RRC] Instance 0: Southbound Transport local_mac enb_id:3584
[RRC] Setting node_type to ngran_eNB_DU gNB_CU_name[0] eNB-Eurecom-DU my_addr:192.168.200.22
[LIBCONFIG] eNBs.[0].plmn_list.[0]: 3/3 parameters successfully set, (0 to default value)
[RRC] num component carriers 1
[RRC] enb_config::RCconfig_RRC() parameter number: 0, total number of parameters: 78, ccspath: eNBs.[0].component_carriers.[0]
[LIBCONFIG] eNBs.[0].component_carriers.[0]: 78/78 parameters successfully set, (62 to default value)
[RRC] Node type 6
[LIBCONFIG] (root): 3/3 parameters successfully set, (1 to default value)
[LIBCONFIG] NETWORK_CONTROLLER: 6/6 parameters successfully set, (0 to default value)
[LIBCONFIG] eNBs.[0].RIC: 3/3 parameters successfully set, (0 to default value)
[RIC_AGENT] NODE[6] enabled for NB 0
[FLEXRAN_AGENT] FlexRAN Agent for eNB 0 is DISABLED
[ENB_APP] Creating ENB_APP eNB Task
[TMR] Created Posix thread TASK_ENB_APP
[RRC] Creating RRC eNB Task
[ENB_APP] ngran_eNB_DU: Allocating ITTI message for F1AP_SETUP_REQ
[LIBCONFIG] (root): 3/3 parameters successfully set, (1 to default value)
[TMR] Created Posix thread TASK_RRC_ENB
[LIBCONFIG] eNBs.[0]: 20/20 parameters successfully set, (11 to default value)
[RRC] Entering main loop of RRC message task
[LIBCONFIG] eNBs.[0].plmn_list.[0]: 3/3 parameters successfully set, (0 to default value)
[ENB_APP] F1AP: gNB_DU_id[0] 3584
[ENB_APP] F1AP: gNB_DU_name[0] eNB-Eurecom-DU
[ENB_APP] F1AP: tac[0] 1
[ENB_APP] F1AP: mcc[0] 208
[ENB_APP] F1AP: mnc[0] 1
[ENB_APP] F1AP: mnc_digit_length[0] 2
[ENB_APP] F1AP: nr_cellid[0] 12345678
[ENB_APP] F1AP: CU_ip4_address in DU 192.168.200.21
[ENB_APP] FIAP: CU_ip4_address in DU 0x7f28700008e9, strlen 14
[ENB_APP] F1AP: DU_ip4_address in DU 192.168.200.22
[ENB_APP] FIAP: DU_ip4_address in DU 0x7f2870000929, strlen 14
[LIBCONFIG] eNBs.[0].SCTP: 2/2 parameters successfully set, (0 to default value)
[ENB_APP] ngran_eNB_DU: Waiting for basic cell configuration
[SCTP] Starting SCTP layer
[TMR] Created Posix thread TASK_SCTP
[TMR] Created Posix thread TASK_DU_F1
[MAC] Creating MAC eNB Task
[TMR] Created Posix thread TASK_MAC_ENB
[MAC] Creating DU RIC Agent Task
[TMR] Created Posix thread TASK_RIC_AGENT_DU
[RRC] [eNB 0] Received RRC_CONFIGURATION_REQ : 0x3a0ca20
[RRC] [FRAME 00000][eNB][MOD 00][RNTI 0] Init...
[MAC] Starting main loop of MAC message task
[RIC_AGENT] starting DU E2 agent task
[F1AP] Starting F1AP at DU
3780.513014: 0x04: 1981171456: [VNF] VNF NFAPI thread - nfapi_vnf_start()vnf_start_thread
[NFAPI_VNF] VNF Setting the SCTP_INITMSG
[RRC] [FRAME 00000][eNB][MOD 00][RNTI 0] Checking release
[RRC] [FRAME 00000][eNB][MOD 00][RNTI 0] Rel14 RRC detected, MBMS flag 0
[RRC] [eNB 0] Node type 6
[RRC] configuration->schedulingInfoSIB1_BR_r13[CC_id] 0
[RRC] Configuring MIB (N_RB_DL 25,phich_Resource 0,phich_Duration 0)
[RRC] [MIB] systemBandwidth 2, phich_duration 0, phich_resource 0, sfn 0
[RRC] [MIB] schedulingInfoSIB1 0
[RIC_AGENT] _______
[RRC] [eNB] handover active state is 0
[RRC] [eNB] eMBMS active state is 0
[RRC] [FRAME 00000][eNB][MOD 00][RNTI 0] ENB:OPENAIR RRC IN....
ORAN-E2SM-RSM
1.3.6.1.4.1.53148.1.1.2.102
RAN Slicing
0
4
4
4
[RIC_AGENT] _______
[RIC_AGENT] ------ RAN SLICING FUNC DEF ENC Len:71-------
[ENB_APP] ngran_DU: Configuring Cell 0 for FDD
[ENB_APP] [eNB 0] eNB_app_register via F1AP for instance 0
[LIBCONFIG] eNBs.[0]: 1/1 parameters successfully set, (1 to default value)
[LIBCONFIG] gNBs.[0]: 1/1 parameters successfully set, (1 to default value)
[F1AP] DU Task Received F1AP_SETUP_REQ
[LIBCONFIG] eNBs.[0]: 1/1 parameters successfully set, (1 to default value)
[SCTP] sctp_bindx SCTP_BINDX_ADD_ADDR socket bound to : 192.168.200.22
[SCTP] Converted ipv4 address 192.168.200.21 to network type
[SCTP] connectx assoc_id 36 in progress..., used 1 addresses
[SCTP] Inserted new descriptor for sd 88 in list, nb elements 1, assoc_id 36
[SCTP] Found data for descriptor 88
[SCTP] Received notification for sd 88, type 32769
[SCTP] Client association changed: 0
[SCTP] ----------------------
[SCTP] Peer addresses:
[SCTP] - [192.168.200.21]
[SCTP] ----------------------
[SCTP] ----------------------
[SCTP] SCTP Status:
[SCTP] assoc id .....: 36
[SCTP] state ........: 4
[SCTP] instrms ......: 2
[SCTP] outstrms .....: 2
[SCTP] fragmentation : 65484
[SCTP] pending data .: 0
[SCTP] unack data ...: 0
[SCTP] rwnd .........: 106496
[SCTP] peer info :
[SCTP] state ....: 2
[SCTP] cwnd .....: 131064
[SCTP] srtt .....: 0
[SCTP] rto ......: 3000
[SCTP] mtu ......: 65532
[SCTP] ----------------------
[SCTP] Comm up notified for sd 88, assigned assoc_id 36
[SCTP] Found data for descriptor 88
[PROTO_AGENT] server started at port 192.168.200.22:600
[SCTP] Received notification for sd 88, type 32776
[F1AP] DU Task Received SCTP_NEW_ASSOCIATION_RESP
[F1AP] Sending ITTI message to SCTP Task
[SCTP] Successfully sent 111 bytes on stream 0 for assoc_id 36
[SCTP] Found data for descriptor 88
[SCTP] Received notification for sd 88, type 32777
[SCTP] Found data for descriptor 88
[SCTP] [36][88] Msg of length 107 received from port 30923, on stream 0, PPID 62
[F1AP] DU Task Received SCTP_DATA_IND
[F1AP] f1ap_decode_successful_outcome(): F1AP_ProcedureCode_id_F1Setup
[F1AP] Calling handler with instance 0
[ENB_APP] Received F1AP_SETUP_RESP: associated ngran_eNB_CU eNB-CU-Eurecom-LTEBox with 1 cells to activate
[ENB_APP] cells_to_activated 1, RRC instances 1
[ENB_APP] Checking cell 0, rrc inst 0 : rrc->nr_cellid bc614e, resp->nr_cellid bc614e
[ENB_APP] rrc inst 0: Trying to decode SI block 0 @ 0x7f28640024f0, length 38
[ENB_APP] Extracting SI 0/2
[ENB_APP] [RRC 0] Found SIB2 in CU F1AP_SETUP_RESP message
[ENB_APP] Extracting SI 1/2
[ENB_APP] [RRC 0] Found SIB3 in CU F1AP_SETUP_RESP message
[ENB_APP] Configuring MAC/L1 0, carrier->sib2 0x7f2870001ea0
[MAC] Configuring MIB for instance 0, CCid 0 : (band 7,N_RB_DL 25,Nid_cell 0,p 1,DL freq 2680000000,phich_config.resource 0, phich_config.duration 0)
[MAC] config_mib() NFAPI_CONFIG_REQUEST(num_tlv:16) DL_BW:25 UL_BW:25 Ncp 0,p_eNB 1,earfcn 3350,band 7,phich_resource 0 phich_duration 0 phich_power_offset 6000 PSS 6000 SSS 6000 PCI 0 PBCH repetition 0
[MAC] [CONFIG]SIB2/3 Contents (partial)
[MAC] [CONFIG]pusch_config_common.n_SB = 1
[MAC] [CONFIG]pusch_config_common.hoppingMode = 0
[MAC] [CONFIG]pusch_config_common.pusch_HoppingOffset = 0
[MAC] [CONFIG]pusch_config_common.enable64QAM = 0
[MAC] [CONFIG]pusch_config_common.groupHoppingEnabled = 1
[MAC] [CONFIG]pusch_config_common.groupAssignmentPUSCH = 0
[MAC] [CONFIG]pusch_config_common.sequenceHoppingEnabled = 0
[MAC] [CONFIG]pusch_config_common.cyclicShift = 1
Waiting for PHY_config_req
Waiting for PHY_config_req
[VNF] pnf connection indication idx:0
[VNF] RC.eNB[0][0]. Mod_id:0 CC_id:0 nb_CC[0]:1 abstraction_flag:0 single_thread_flag:0 if_inst:(nil)
RC.eNB[0][0]->if_inst->PHY_config_req is not installed - install it
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
Waiting for PHY_config_req
[PHY] Configuring MIB for instance 0, CCid 0 : (band 7,N_RB_DL 25, N_RB_UL 25, Nid_cell 0,eNB_tx_antenna_ports 1,Ncp 0,DL freq 3350,phich_config.resource 0, phich_config.duration 0)
[PHY] Initializing frame parms for N_RB_DL 25, Ncp 0, osf 1
[PHY] lte_parms.c: Setting N_RB_DL to 25, ofdm_symbol_size 512
[LIBCONFIG] loader.coding: 2/2 parameters successfully set, (1 to default value)
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
[LOADER] library libcoding.so successfully loaded
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
oai_create_enb() Waiting for eNB to become configured (by RRC/PHY) - need to wait otherwise NFAPI messages won't contain correct values
[PHY] prach_config_common.rootSequenceIndex = 0
[PHY] prach_config_common.prach_ConfigInfo.prach_ConfigIndex = 0
[PHY] prach_config_common.prach_ConfigInfo.highSpeedFlag = 0
[PHY] prach_config_common.prach_ConfigInfo.zeroCorrelationZoneConfig = 1
[PHY] prach_config_common.prach_ConfigInfo.prach_FreqOffset = 2
[PHY] pusch_config_common.n_SB = 1
[PHY] pusch_config_common.hoppingMode = 0
[PHY] pusch_config_common.pusch_HoppingOffset = 0
[PHY] pusch_config_common.enable64QAM = 0
[PHY] pusch_config_common.ul_ReferenceSignalsPUSCH.groupHoppingEnabled = 1
[PHY] pusch_config_common.ul_ReferenceSignalsPUSCH.groupAssignmentPUSCH = 0
[PHY] pusch_config_common.ul_ReferenceSignalsPUSCH.sequenceHoppingEnabled = 0
[PHY] pusch_config_common.ul_ReferenceSignalsPUSCH.cyclicShift = 2
[PHY] eNB 0/0 configured
oai_create_enb() eNB is now configured
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[VNF] pnf param response idx:0 error:0
[VNF] (PHY:0) phy_config_idx:0
[VNF] (PHY:0) (RF0) 0
[VNF] (PHY:0) (RF1) 0
[VNF] (RF:0) rf_config_idx:0
[VNF] (RF:1) rf_config_idx:0
DJP:Hard coded num phy rf to 2
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[VNF] pnf config response idx:0 resp[header[phy_id:0 message_id:103 message_length:12]]
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[VNF] pnf start response idx:0 config:0x39fb0a0 user_data:0x163dd80 p7_vnf[config:0x39faf60 thread_started:0]
[VNF] Sending NFAPI_PARAM_REQUEST phy_id:1
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[VNF] Received NFAPI_PARAM_RESP idx:0 phy_id:1
[VNF] 0.1 pnf p7 10.0.0.7:32123 timing 32 10 0 10
[VNF] Send NFAPI_CONFIG_REQUEST
[VNF] DJP local_port:50001
[VNF] DJP local_addr:10.0.0.7
[VNF] Timing window:32
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[VNF] Sent NFAPI_CONFIG_REQ num_tlv:43
[VNF] Received NFAPI_CONFIG_RESP idx:0 phy_id:1
[VNF] Calling oai_enb_init()
oai_enb_init() About to call init_eNB_afterRU()
[PHY] init_eNB_afterRU() RC.nb_inst:1
[PHY] RC.nb_CC[inst]:1
[PHY] RC.nb_CC[inst:0][CC_id:0]:0x7f2876577010
[PHY] [eNB 0] phy_init_lte_eNB() About to wait for eNB to be configured[PHY] [eNB 0] Initializing DL_FRAME_PARMS : N_RB_DL 25, PHICH Resource 1, PHICH Duration 0 nb_antennas_tx:0 nb_antennas_rx:0 nb_antenna_ports_eNB:1 PRACH[rootSequenceIndex:0 prach_Config_enabled:1 configIndex:0 highSpeed:0 zeroCorrelationZoneConfig:1 freqOffset:2]
[PHY] [eNB 0] Initializing DL_FRAME_PARMS : N_RB_DL 25, PHICH Resource 1, PHICH Duration 0
pcfich_reg : 0,12,25,37
[PHY] Mapping RX ports from 0 RUs to eNB 0
[PHY] Overwriting eNB->prach_vars.rxsigF[0]:(nil)
[PHY] Overwriting eNB->prach_vars_br.rxsigF.rxsigF[0]:(nil)
[PHY] Overwriting eNB->prach_vars_br.rxsigF.rxsigF[0]:(nil)
[PHY] Overwriting eNB->prach_vars_br.rxsigF.rxsigF[0]:(nil)
[PHY] Overwriting eNB->prach_vars_br.rxsigF.rxsigF[0]:(nil)
[PHY] eNB->num_RU:0
[PHY] init_eNB_afterRU() ************* DJP ***** eNB->frame_parms.nb_antennas_rx:0 - GOING TO HARD CODE TO 1[PHY] init_eNB_afterRU() ************* DJP ***** eNB->frame_parms.nb_antennas_tx:0 - GOING TO HARD CODE TO 1[PHY] inst 0, CC_id 0 : nb_antennas_rx 1
[PHY] Initialise transport
[PHY] init_eNB_proc(inst:0) RC.nb_CC[inst]:1
[PHY] Initializing eNB processes instance:0 CC_id 0
[PHY] eNB->single_thread_flag:0
[HW] thread_top_init() called with affinity>0, but overruled by #ifndef CPU_AFFINITY.
vnf_p7_start_thread()
[HW] [SCHED][eNB] RXn_TXnp4_0
started on CPU 5, sched_policy = SCHED_FIFO , priority = 99, CPU Affinity= CPU_0 CPU_1 CPU_2 CPU_3 CPU_4 CPU_5 CPU_6 CPU_7
[NFAPI_VNF] nfapi_vnf_pnf_list_find : config->pnf_list:0x7f28500008c0
[NFAPI_VNF] nfapi_vnf_pnf_list_find : curr->p5_idx:0 p5_idx:0
[HW] thread_top_init() called with affinity>0, but overruled by #ifndef CPU_AFFINITY.
[HW] [SCHED][eNB] RXn_TXnp4_1
started on CPU 2, sched_policy = SCHED_FIFO , priority = 99, CPU Affinity= CPU_0 CPU_1 CPU_2 CPU_3 CPU_4 CPU_5 CPU_6 CPU_7
[VNF] Send NFAPI_START_REQUEST idx:0 phy_id:1
[VNF] Received NFAPI_START_RESP idx:0 phy_id:1
[PHY] thread rxtx created id=20
[NFAPI_VNF] reallocing rx buffer 28
[NFAPI_VNF] ( 0/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 2001, 882121, 882125, 2631) txrx: 630 procT: 4 latency(us): 313
[PHY] thread rxtx created id=22
[NFAPI_VNF] ( 0/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 4000, 883634, 883635, 4097) txrx: 97 procT: 1 latency(us): 48
[NFAPI_VNF] ( 0/6) PNF to VNF !sync phy_id:1 (t1/2/3/4: 6001, 885596, 885597, 6064) txrx: 63 procT: 1 latency(us): 31
[NFAPI_VNF] ( 0/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 8001, 887603, 887604, 8082) txrx: 81 procT: 1 latency(us): 40
[NFAPI_VNF] ( 1/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 18001, 897618, 897619, 18080) txrx: 79 procT: 1 latency(us): 39
[NFAPI_VNF] ( 2/0) PNF to VNF !sync phy_id:1 (t1/2/3/4: 20001, 899619, 899620, 20072) txrx: 71 procT: 1 latency(us): 35
[NFAPI_VNF] ( 2/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 22000, 901600, 901601, 22059) txrx: 59 procT: 1 latency(us): 29
[NFAPI_VNF] ( 2/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 24001, 903591, 903593, 24058) txrx: 57 procT: 2 latency(us): 27
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment879 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 90/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 904001, 904599, 904601, 904058) txrx: 57 procT: 2 latency(us): 27
[NFAPI_VNF] ( 91/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 914001, 914588, 914589, 914085) txrx: 84 procT: 1 latency(us): 41
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 91/6) PNF to VNF !sync phy_id:1 (t1/2/3/4: 916001, 916600, 916602, 916062) txrx: 61 procT: 2 latency(us): 29
[NFAPI_VNF] ( 91/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 918001, 918602, 918604, 918057) txrx: 56 procT: 2 latency(us): 27
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 92/0) PNF to VNF !sync phy_id:1 (t1/2/3/4: 920000, 920596, 920597, 920060) txrx: 60 procT: 1 latency(us): 29
[NFAPI_VNF] ( 93/0) PNF to VNF !sync phy_id:1 (t1/2/3/4: 930001, 930606, 930607, 930075) txrx: 74 procT: 1 latency(us): 36
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 93/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 932001, 932607, 932608, 932064) txrx: 63 procT: 1 latency(us): 31
[NFAPI_VNF] ( 93/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 934001, 934577, 934578, 934058) txrx: 57 procT: 1 latency(us): 28
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 93/6) PNF to VNF !sync phy_id:1 (t1/2/3/4: 936000, 936681, 936682, 936075) txrx: 75 procT: 1 latency(us): 37
[NFAPI_VNF] ( 94/6) PNF to VNF !sync phy_id:1 (t1/2/3/4: 946000, 946618, 946620, 946086) txrx: 86 procT: 2 latency(us): 42
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 94/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 948001, 948597, 948599, 948061) txrx: 60 procT: 2 latency(us): 29
[NFAPI_VNF] ( 95/0) PNF to VNF !sync phy_id:1 (t1/2/3/4: 950000, 950589, 950590, 950056) txrx: 56 procT: 1 latency(us): 27
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 95/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 952001, 952597, 952598, 952061) txrx: 60 procT: 1 latency(us): 29
[NFAPI_VNF] ( 96/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 962001, 962583, 962584, 962082) txrx: 81 procT: 1 latency(us): 40
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 96/4) PNF to VNF !sync phy_id:1 (t1/2/3/4: 964000, 964599, 964601, 964065) txrx: 65 procT: 2 latency(us): 31
[NFAPI_VNF] ( 96/6) PNF to VNF !sync phy_id:1 (t1/2/3/4: 966001, 966596, 966597, 966059) txrx: 58 procT: 1 latency(us): 28
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 96/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 968001, 968606, 968607, 968056) txrx: 55 procT: 1 latency(us): 27
[NFAPI_VNF] ( 97/8) PNF to VNF !sync phy_id:1 (t1/2/3/4: 978001, 978605, 978606, 978071) txrx: 70 procT: 1 latency(us): 34
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 98/0) PNF to VNF !sync phy_id:1 (t1/2/3/4: 980001, 980587, 980588, 980067) txrx: 66 procT: 1 latency(us): 32
[NFAPI_VNF] ( 98/2) PNF to VNF !sync phy_id:1 (t1/2/3/4: 982001, 982593, 982594, 982070) txrx: 69 procT: 1 latency(us): 34
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ***** Adjusting VNF SFN/SF switching to filtered mode
[NFAPI_VNF] ( 98/4) 1604.842915077 PNF to VNF phy_id: 1 (t1/2/3/4: 984000, 984604, 984605, 984061) txrx: 61 procT: 1 latency(us): 30(avg: 33) offset(us): 574 filtered(us): 574 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 99/4) 1604.852941400 PNF to VNF phy_id: 1 (t1/2/3/4: 994001, 994614, 994615, 994088) txrx: 87 procT: 1 latency(us): 43(avg: 33) offset(us): 570 filtered(us): 573 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment1 phy->previous_sf_offset_filtered:0 phy->previous_sf_offset_filtered:0 phy->sf_offset_trend:0
[NFAPI_VNF] ( 99/6) 1604.853915712 PNF to VNF phy_id: 1 (t1/2/3/4: 996001, 995584, 995585, 996062) txrx: 61 procT: 1 latency(us): 30(avg: 33) offset(us): -447 filtered(us): -447 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 99/8) 1604.855908037 PNF to VNF phy_id: 1 (t1/2/3/4: 998000, 997591, 997592, 998064) txrx: 64 procT: 1 latency(us): 31(avg: 33) offset(us): -440 filtered(us): -447 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:573 phy->previous_sf_offset_filtered:573 phy->sf_offset_trend:0
[NFAPI_VNF] ( 100/0) 1604.857913761 PNF to VNF phy_id: 1 (t1/2/3/4: 1000000, 999598, 999599, 1000064) txrx: 64 procT: 1 latency(us): 31(avg: 33) offset(us): -433 filtered(us): -433 wrap[t1:0 t2:0]
[NFAPI_VNF] reallocing rx buffer 72
[NFAPI_VNF] ( 101/0) 1604.867939584 PNF to VNF phy_id: 1 (t1/2/3/4: 1010000, 1009622, 1009624, 1010078) txrx: 78 procT: 2 latency(us): 38(avg: 33) offset(us): -416 filtered(us): -431 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-447 phy->previous_sf_offset_filtered:-447 phy->sf_offset_trend:0
[NFAPI_VNF] ( 101/2) 1604.869903209 PNF to VNF phy_id: 1 (t1/2/3/4: 1012000, 1011600, 1011602, 1012054) txrx: 54 procT: 2 latency(us): 26(avg: 33) offset(us): -426 filtered(us): -426 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 101/4) 1604.871904233 PNF to VNF phy_id: 1 (t1/2/3/4: 1014001, 1013594, 1013596, 1014059) txrx: 58 procT: 2 latency(us): 28(avg: 33) offset(us): -435 filtered(us): -428 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-431 phy->previous_sf_offset_filtered:-431 phy->sf_offset_trend:0
[NFAPI_VNF] ( 101/6) 1604.873910058 PNF to VNF phy_id: 1 (t1/2/3/4: 1016001, 1015600, 1015602, 1016056) txrx: 55 procT: 2 latency(us): 26(avg: 33) offset(us): -427 filtered(us): -427 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 102/6) 1604.883920581 PNF to VNF phy_id: 1 (t1/2/3/4: 1026001, 1025613, 1025614, 1026071) txrx: 70 procT: 1 latency(us): 34(avg: 33) offset(us): -422 filtered(us): -427 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-428 phy->previous_sf_offset_filtered:-428 phy->sf_offset_trend:0
[NFAPI_VNF] ( 102/8) 1604.885907305 PNF to VNF phy_id: 1 (t1/2/3/4: 1028001, 1027588, 1027590, 1028059) txrx: 58 procT: 2 latency(us): 28(avg: 33) offset(us): -441 filtered(us): -441 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 103/0) 1604.887913630 PNF to VNF phy_id: 1 (t1/2/3/4: 1030001, 1029591, 1029593, 1030059) txrx: 58 procT: 2 latency(us): 28(avg: 33) offset(us): -438 filtered(us): -441 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-427 phy->previous_sf_offset_filtered:-427 phy->sf_offset_trend:0
[NFAPI_VNF] ( 103/2) 1604.889906154 PNF to VNF phy_id: 1 (t1/2/3/4: 1032001, 1031588, 1031590, 1032057) txrx: 56 procT: 2 latency(us): 27(avg: 33) offset(us): -440 filtered(us): -440 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 104/2) 1604.899934277 PNF to VNF phy_id: 1 (t1/2/3/4: 1042001, 1041589, 1041592, 1042090) txrx: 89 procT: 3 latency(us): 43(avg: 33) offset(us): -455 filtered(us): -442 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-441 phy->previous_sf_offset_filtered:-441 phy->sf_offset_trend:434
[NFAPI_VNF] ( 104/4) 1604.901950002 PNF to VNF phy_id: 1 (t1/2/3/4: 1044001, 1043630, 1043632, 1044084) txrx: 83 procT: 2 latency(us): 40(avg: 33) offset(us): -411 filtered(us): -411 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 104/6) 1604.903910926 PNF to VNF phy_id: 1 (t1/2/3/4: 1046000, 1045585, 1045586, 1046061) txrx: 61 procT: 1 latency(us): 30(avg: 33) offset(us): -445 filtered(us): -416 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-442 phy->previous_sf_offset_filtered:-442 phy->sf_offset_trend:441
[NFAPI_VNF] ( 104/8) 1604.905934651 PNF to VNF phy_id: 1 (t1/2/3/4: 1048001, 1047613, 1047615, 1048082) txrx: 81 procT: 2 latency(us): 39(avg: 33) offset(us): -427 filtered(us): -427 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 105/8) 1604.915975074 PNF to VNF phy_id: 1 (t1/2/3/4: 1058001, 1057624, 1057627, 1058121) txrx: 120 procT: 3 latency(us): 58(avg: 33) offset(us): -435 filtered(us): -428 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-416 phy->previous_sf_offset_filtered:-416 phy->sf_offset_trend:441
[NFAPI_VNF] ( 106/0) 1604.917941298 PNF to VNF phy_id: 1 (t1/2/3/4: 1060001, 1059345, 1059349, 1060099) txrx: 98 procT: 4 latency(us): 47(avg: 33) offset(us): -703 filtered(us): -703 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 106/2) 1604.919897122 PNF to VNF phy_id: 1 (t1/2/3/4: 1062000, 1061585, 1061587, 1062056) txrx: 56 procT: 2 latency(us): 27(avg: 33) offset(us): -442 filtered(us): -671 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-428 phy->previous_sf_offset_filtered:-428 phy->sf_offset_trend:422
[NFAPI_VNF] ( 106/4) 1604.921899347 PNF to VNF phy_id: 1 (t1/2/3/4: 1064000, 1063581, 1063583, 1064059) txrx: 59 procT: 2 latency(us): 28(avg: 33) offset(us): -447 filtered(us): -447 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 107/4) 1604.931929670 PNF to VNF phy_id: 1 (t1/2/3/4: 1074000, 1073582, 1073585, 1074089) txrx: 89 procT: 3 latency(us): 43(avg: 33) offset(us): -461 filtered(us): -449 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-671 phy->previous_sf_offset_filtered:-671 phy->sf_offset_trend:549
[NFAPI_VNF] ( 107/6) 1604.933900794 PNF to VNF phy_id: 1 (t1/2/3/4: 1076000, 1075583, 1075584, 1076060) txrx: 60 procT: 1 latency(us): 29(avg: 33) offset(us): -446 filtered(us): -446 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 107/8) 1604.935911919 PNF to VNF phy_id: 1 (t1/2/3/4: 1078001, 1077589, 1077591, 1078072) txrx: 71 procT: 2 latency(us): 34(avg: 33) offset(us): -446 filtered(us): -446 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-449 phy->previous_sf_offset_filtered:-449 phy->sf_offset_trend:549
[NFAPI_VNF] VNF P7 In Sync with phy (phy_id:1)
[VNF] SYNC ACHIEVED
[VNF] Signal to OAI main code that it can go
[NFAPI_VNF] ( 107/8) VNF phy_id:1 Apply minor insync adjustment -91us for 4 subframes (sf_offset_filtered:-446) 91 274 549 NEW:1078 CURR:1078 adjustment:0
[NFAPI_VNF] [VNF] AFTER adjustment - Subframe minor adjustment -91us sf_start.tv_nsec:937921326 duration:3
[VNF] subframe indication 1079
[MAC] SCHED_MODE = 0, PUSCH Target SNR:20, PUCCH Target SNR:20
[NFAPI_VNF] [VNF] AFTER adjustment - Subframe minor adjustment -91us sf_start.tv_nsec:939012326 duration:2
[NFAPI_VNF] [VNF] AFTER adjustment - Subframe minor adjustment -91us sf_start.tv_nsec:940103326 duration:1
[NFAPI_VNF] [VNF] AFTER adjustment - Subframe minor adjustment -91us sf_start.tv_nsec:941194326 duration:0
[ENB_APP] NFAPI*** - mutex and cond created - will block shortly for completion of PNF connection
waiting for NFAPI PNF connection and population of global structure (main?)
NFAPI: got sync (main?)
[ENB_APP] START MAIN THREADS
RC.nb_L1_inst:0
wait_eNBs()
Waiting for eNB L1 instances to all get configured ... sleeping 50ms (nb_L1_inst 0)
eNB L1 are configured
About to Init RU threads RC.nb_RU:0
[MME_APP] Creating MME_APP eNB Task
[TMR] Created Posix thread TASK_MME_APP
[LIBCONFIG] MMEs.[0]: 1/1 parameters successfully set, (1 to default value)
[MCE_APP] Creating MCE_APP eNB Task
[TMR] Created Posix thread TASK_MCE_APP
[LIBCONFIG] MCEs.[0]: 1/1 parameters successfully set, (1 to default value)
[LIBCONFIG] MCEs.[0]: 1/1 parameters successfully set, (1 to default value)
[ENB_APP] TYPE TO TERMINATE
[ENB_APP] [MCE 0] MCE_app_register via M3AP for instance 0
[NFAPI_VNF] ( 150/6) 1605.364331579 PNF to VNF phy_id: 1 (t1/2/3/4: 1506000, 1506001, 1506003, 1506124) txrx: 124 procT: 2 latency(us): 61(avg: 33) offset(us): -60 filtered(us): -60 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:2000 old_sfn/sf:2000 proc[rx:1999]
[NFAPI_VNF] ( 201/8) 1605.876319164 PNF to VNF phy_id: 1 (t1/2/3/4: 2018001, 2017972, 2017982, 2018113) txrx: 112 procT: 10 latency(us): 51(avg: 33) offset(us): -80 filtered(us): -63 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-446 phy->previous_sf_offset_filtered:-446 phy->sf_offset_trend:549
[NFAPI_VNF] ( 253/0) 1606.388387650 PNF to VNF phy_id: 1 (t1/2/3/4: 2530001, 2530013, 2530015, 2530181) txrx: 180 procT: 2 latency(us): 89(avg: 33) offset(us): -77 filtered(us): -77 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:3000 old_sfn/sf:3000 proc[rx:2999]
[NFAPI_VNF] ( 304/2) 1606.900444034 PNF to VNF phy_id: 1 (t1/2/3/4: 3042000, 3042105, 3042106, 3042237) txrx: 237 procT: 1 latency(us): 118(avg: 33) offset(us): -13 filtered(us): -69 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-63 phy->previous_sf_offset_filtered:-63 phy->sf_offset_trend:549
[NFAPI_VNF] ( 355/4) 1607.412367415 PNF to VNF phy_id: 1 (t1/2/3/4: 3554001, 3554020, 3554023, 3554162) txrx: 161 procT: 3 latency(us): 79(avg: 33) offset(us): -60 filtered(us): -60 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:4000 old_sfn/sf:4000 proc[rx:3999]
[NFAPI_VNF] ( 406/6) 1607.924343896 PNF to VNF phy_id: 1 (t1/2/3/4: 4066001, 4065997, 4066011, 4066138) txrx: 137 procT: 14 latency(us): 61(avg: 33) offset(us): -65 filtered(us): -61 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-69 phy->previous_sf_offset_filtered:-69 phy->sf_offset_trend:66
[NFAPI_VNF] ( 457/8) 1608.436361177 PNF to VNF phy_id: 1 (t1/2/3/4: 4578001, 4577968, 4578011, 4578155) txrx: 154 procT: 43 latency(us): 55(avg: 33) offset(us): -88 filtered(us): -88 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:5000 old_sfn/sf:5000 proc[rx:4999]
[NFAPI_VNF] ( 509/0) 1608.948340556 PNF to VNF phy_id: 1 (t1/2/3/4: 5090001, 5089994, 5089998, 5090135) txrx: 134 procT: 4 latency(us): 65(avg: 33) offset(us): -72 filtered(us): -86 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-61 phy->previous_sf_offset_filtered:-61 phy->sf_offset_trend:66
[RIC_AGENT] ranid 0 connecting to RIC at 192.168.200.11:36401 with IP 192.168.200.22
[SCTP] sctp_bindx SCTP_BINDX_ADD_ADDR socket bound to : 192.168.200.22
[SCTP] Converted ipv4 address 192.168.200.11 to network type
[SCTP] connectx assoc_id 40 in progress..., used 1 addresses
[SCTP] Inserted new descriptor for sd 92 in list, nb elements 2, assoc_id 40
[SCTP] Found data for descriptor 92
[SCTP] Received notification for sd 92, type 32769
[SCTP] Client association changed: 0
[SCTP] ----------------------
[SCTP] Peer addresses:
[SCTP] - [192.168.200.11]
[SCTP] ----------------------
[SCTP] ----------------------
[SCTP] SCTP Status:
[SCTP] assoc id .....: 40
[SCTP] state ........: 4
[SCTP] instrms ......: 1
[SCTP] outstrms .....: 1
[SCTP] fragmentation : 65484
[SCTP] pending data .: 0
[SCTP] unack data ...: 0
[SCTP] rwnd .........: 106496
[SCTP] peer info :
[SCTP] state ....: 2
[SCTP] cwnd .....: 131064
[SCTP] srtt .....: 0
[SCTP] rto ......: 3000
[SCTP] mtu ......: 65532
[SCTP] ----------------------
[SCTP] Comm up notified for sd 92, assigned assoc_id 40
[SCTP] Found data for descriptor 92
[SCTP] Received notification for sd 92, type 32776
[RIC_AGENT] new sctp assoc resp 40, sctp_state 2 for nb 0
[RIC_AGENT] new sctp assoc resp 40 for nb 0
1
3
02 F8 10
00000000111000000000
10
8
1
20 C0 4F 52 41 4E 2D 45 32 53 4D 2D 52 53 4D 00
00 1A 31 2E 33 2E 36 2E 31 2E 34 2E 31 2E 35 33
31 34 38 2E 31 2E 31 2E 32 2E 31 30 32 05 00 52
41 4E 20 53 6C 69 63 69 6E 67 01 00 01 00 04 00
04 00 01 04 30 04 43
1
1.3.6.1.4.1.53148.1.1.2.102
50
51
200
31 30 30
32 30 30
[RIC_AGENT] Send SCTP data, ranid:0, assoc_id:40, len:158
[SCTP] Successfully sent 158 bytes on stream 0 for assoc_id 40
[SCTP] Found data for descriptor 92
[SCTP] Received notification for sd 92, type 32777
[SCTP] Found data for descriptor 92
[SCTP] Received data from peer with unsollicited PPID 0, expecting 70
[SCTP] [40][92] Msg of length 64 received from port 36401, on stream 0, PPID 0
1
49
0
4
02 F8 10
11011110101111001010
52
53
S1-component
9
6
1
1
[RIC_AGENT] decoded successful outcome E2SetupResponse (1)
[RIC_AGENT] Received E2SetupResponse (ranid 0)
[RIC_AGENT] E2SetupResponse (ranid 0) from RIC (mcc=208,mnc=1,id=0)
[SCTP] Found data for descriptor 92
[SCTP] Received data from peer with unsollicited PPID 0, expecting 70
[SCTP] [40][92] Msg of length 31 received from port 36401, on stream 0, PPID 0
11
C0 A8 54 16
49
5
44
43
11000000101010000101010000010110
1000111001000101
[RIC_AGENT] decoded initiating E2ConnectionUpdate (11)
[RIC_AGENT] Received E2ConnectionUpdate from ranid 0
[RIC_AGENT] [e2ap_handle_e2_connection_update] Transaction ID:5[RIC_AGENT] Iter:0
[RIC_AGENT] [e2ap_handle_e2_connection_update] Received E2ConnectionUpdate Item within List
[RIC_AGENT] [e2ap_handle_e2_connection_update] Preparing E2connectionUpdateAcknowledge
11
49
5
39
43
11000000101010000101010000010110
1000111001000101
40
41
11000000101010000101010000010110
1000111001000101
[RIC_AGENT] [e2ap_handle_e2_connection_update] Setting up New SCTP for Data Connection
[RIC_AGENT] TNLAddress:3232257046 Port:36421
Remote Ipv4 Address:192.168.84.22
[RIC_AGENT] [e2ap_handle_e2_connection_update] ranid 0 Requesting data connection to RIC at 192.168.84.22:36421 with IP 192.168.200.22
[RIC_AGENT] Send SCTP data, ranid:0, assoc_id:40, len:49
[SCTP] sctp_bindx SCTP_BINDX_ADD_ADDR socket bound to : 192.168.200.22
[SCTP] Converted ipv4 address 192.168.84.22 to network type
[SCTP] connectx assoc_id 42 in progress..., used 1 addresses
[SCTP] Inserted new descriptor for sd 93 in list, nb elements 3, assoc_id 42
[SCTP] Found data for descriptor 93
[SCTP] Received notification for sd 93, type 32769
[SCTP] Client association changed: 0
[SCTP] ----------------------
[SCTP] Peer addresses:
[SCTP] - [192.168.84.22]
[SCTP] ----------------------
[SCTP] ----------------------
[SCTP] SCTP Status:
[SCTP] assoc id .....: 42
[SCTP] state ........: 4
[SCTP] instrms ......: 1
[SCTP] outstrms .....: 1
[SCTP] fragmentation : 1432
[SCTP] pending data .: 0
[SCTP] unack data ...: 0
[SCTP] rwnd .........: 106496
[SCTP] peer info :
[SCTP] state ....: 2
[SCTP] cwnd .....: 4380
[SCTP] srtt .....: 0
[SCTP] rto ......: 3000
[SCTP] mtu ......: 1480
[SCTP] ----------------------
[SCTP] Comm up notified for sd 93, assigned assoc_id 42
[RIC_AGENT] new sctp assoc resp 42, sctp_state 2 for nb 0
[RIC_AGENT] new sctp assoc resp 42 for nb 0
[RIC_AGENT] Data Connection Assoc Id:42 updated
[RIC_AGENT] e2ap_generate_e2_config_update
10
[SCTP] Successfully sent 49 bytes on stream 0 for assoc_id 40
[SCTP] Found data for descriptor 93
[SCTP] Received notification for sd 93, type 32776
49
10
3
02 F8 10
00000000111000000000
33
34
200
31 30 30
32 30 30
[RIC_AGENT] Send SCTP data, ranid:0, assoc_id:42, len:47
[SCTP] Successfully sent 47 bytes on stream 0 for assoc_id 42
[SCTP] Found data for descriptor 93
[SCTP] Received notification for sd 93, type 32777
[SCTP] Found data for descriptor 93
[SCTP] Received data from peer with unsollicited PPID 0, expecting 70
[SCTP] [42][93] Msg of length 13 received from port 36421, on stream 0, PPID 0
10
49
10
[RIC_AGENT] decoded successful outcome E2nodeConfigurationUpdateAcknowledge (10)
[SCTP] Found data for descriptor 92
[SCTP] Received notification for sd 92, type 32777
[NFAPI_VNF] ( 560/2) 1609.460382335 PNF to VNF phy_id: 1 (t1/2/3/4: 5602001, 5602030, 5602033, 5602177) txrx: 176 procT: 3 latency(us): 86(avg: 33) offset(us): -57 filtered(us): -57 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:6000 old_sfn/sf:6000 proc[rx:5999]
[NFAPI_VNF] ( 611/4) 1609.972325511 PNF to VNF phy_id: 1 (t1/2/3/4: 6114001, 6113966, 6113969, 6114121) txrx: 120 procT: 3 latency(us): 58(avg: 33) offset(us): -93 filtered(us): -62 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-86 phy->previous_sf_offset_filtered:-86 phy->sf_offset_trend:73
[NFAPI_VNF] ( 662/6) 1610.484303488 PNF to VNF phy_id: 1 (t1/2/3/4: 6626001, 6625952, 6625954, 6626098) txrx: 97 procT: 2 latency(us): 47(avg: 33) offset(us): -96 filtered(us): -96 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:7000 old_sfn/sf:7000 proc[rx:6999]
[NFAPI_VNF] ( 713/8) 1610.996913470 PNF to VNF phy_id: 1 (t1/2/3/4: 7138001, 7138564, 7138567, 7138708) txrx: 707 procT: 3 latency(us): 352(avg: 33) offset(us): 211 filtered(us): -58 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-62 phy->previous_sf_offset_filtered:-62 phy->sf_offset_trend:73
[NFAPI_VNF] ( 765/0) 1611.508317338 PNF to VNF phy_id: 1 (t1/2/3/4: 7650000, 7649975, 7649978, 7650111) txrx: 111 procT: 3 latency(us): 54(avg: 33) offset(us): -79 filtered(us): -79 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:8000 old_sfn/sf:8000 proc[rx:7999]
[NFAPI_VNF] ( 816/2) 1612.20314311 PNF to VNF phy_id: 1 (t1/2/3/4: 8162001, 8161974, 8161977, 8162109) txrx: 108 procT: 3 latency(us): 52(avg: 33) offset(us): -79 filtered(us): -79 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-58 phy->previous_sf_offset_filtered:-58 phy->sf_offset_trend:73
[NFAPI_VNF] ( 867/4) 1612.532325484 PNF to VNF phy_id: 1 (t1/2/3/4: 8674001, 8673974, 8673978, 8674120) txrx: 119 procT: 4 latency(us): 57(avg: 33) offset(us): -84 filtered(us): -84 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:9000 old_sfn/sf:9000 proc[rx:8999]
[NFAPI_VNF] ( 918/6) 1613.44326255 PNF to VNF phy_id: 1 (t1/2/3/4: 9186000, 9185993, 9185995, 9186120) txrx: 120 procT: 2 latency(us): 59(avg: 33) offset(us): -66 filtered(us): -82 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-79 phy->previous_sf_offset_filtered:-79 phy->sf_offset_trend:68
[NFAPI_VNF] ( 969/8) 1613.556310326 PNF to VNF phy_id: 1 (t1/2/3/4: 9698000, 9697969, 9697971, 9698105) txrx: 105 procT: 2 latency(us): 51(avg: 33) offset(us): -82 filtered(us): -82 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:10000 old_sfn/sf:10000 proc[rx:9999]
[NFAPI_VNF] (1021/0) 1614.68594698 PNF to VNF phy_id: 1 (t1/2/3/4:10210001, 10210251, 10210255, 10210204) txrx: 203 procT: 4 latency(us): 99(avg: 33) offset(us): 151 filtered(us): -53 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-82 phy->previous_sf_offset_filtered:-82 phy->sf_offset_trend:80
[PHY] [eNB] sfn/sf:00 old_sfn/sf:00 proc[rx:10239]
[NFAPI_VNF] ( 48/2) 1614.580316164 PNF to VNF phy_id: 1 (t1/2/3/4: 482001, 481975, 481977, 482111) txrx: 110 procT: 2 latency(us): 54(avg: 33) offset(us): -80 filtered(us): -80 wrap[t1:0 t2:0]
[NFAPI_VNF] ( 99/4) 1615.92338531 PNF to VNF phy_id: 1 (t1/2/3/4: 994001, 993993, 993997, 994133) txrx: 132 procT: 4 latency(us): 64(avg: 33) offset(us): -72 filtered(us): -79 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-53 phy->previous_sf_offset_filtered:-53 phy->sf_offset_trend:80
[PHY] [eNB] sfn/sf:1000 old_sfn/sf:1000 proc[rx:999]
[NFAPI_VNF] ( 150/6) 1615.604313698 PNF to VNF phy_id: 1 (t1/2/3/4: 1506001, 1505982, 1505985, 1506108) txrx: 107 procT: 3 latency(us): 52(avg: 33) offset(us): -71 filtered(us): -71 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:2000 old_sfn/sf:2000 proc[rx:1999]
[NFAPI_VNF] ( 201/8) 1616.116311263 PNF to VNF phy_id: 1 (t1/2/3/4: 2018001, 2017943, 2017945, 2018106) txrx: 105 procT: 2 latency(us): 51(avg: 33) offset(us): -109 filtered(us): -76 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-79 phy->previous_sf_offset_filtered:-79 phy->sf_offset_trend:66
[NFAPI_VNF] ( 253/0) 1616.628316728 PNF to VNF phy_id: 1 (t1/2/3/4: 2530001, 2529977, 2529979, 2530112) txrx: 111 procT: 2 latency(us): 54(avg: 33) offset(us): -78 filtered(us): -78 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:3000 old_sfn/sf:3000 proc[rx:2999]
[NFAPI_VNF] ( 304/2) 1617.140531594 PNF to VNF phy_id: 1 (t1/2/3/4: 3042001, 3042189, 3042192, 3042327) txrx: 326 procT: 3 latency(us): 161(avg: 33) offset(us): 27 filtered(us): -65 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-76 phy->previous_sf_offset_filtered:-76 phy->sf_offset_trend:66
[NFAPI_VNF] ( 355/4) 1617.652321554 PNF to VNF phy_id: 1 (t1/2/3/4: 3554000, 3553981, 3553984, 3554115) txrx: 115 procT: 3 latency(us): 56(avg: 33) offset(us): -75 filtered(us): -75 wrap[t1:0 t2:0]
[PHY] [eNB] sfn/sf:4000 old_sfn/sf:4000 proc[rx:3999]
[NFAPI_VNF] ( 406/6) 1618.164317915 PNF to VNF phy_id: 1 (t1/2/3/4: 4066001, 4065977, 4065980, 4066113) txrx: 112 procT: 3 latency(us): 54(avg: 33) offset(us): -78 filtered(us): -76 wrap[t1:0 t2:0]
[NFAPI_VNF] PNF to VNF phy_id:1 adjustment0 phy->previous_sf_offset_filtered:-65 phy->previous_sf_offset_filtered:-65 phy->sf_offset_trend:66
[NFAPI_VNF] ( 457/8) 1618.676312276 PNF to VNF phy_id: 1 (t1/2/3/4: 4578001, 4577966, 4577969, 4578107) txrx: 106 procT: 3 latency(us): 51(avg: 33) offset(us): -86 filtered(us): -86 wrap[t1:0 t2:0]
[PHY] [eNB] ERROR pthread_mutex_lock for eNB RXTX thread 1 (IC 0)
/root/nfapi/oai_integration/nfapi_vnf.c:338 wake_eNB_rxtx() Exiting OAI softmodem: error locking mutex_rxtx
riab oai-enb-du-0 1/1 Running 4 10m
Pod going to Crashloopback off frequently and coming back up.