diff --git a/open-nfapi.oai.patch b/open-nfapi.oai.patch index 95aeb2e64a40eb403a1f4df3c4b60cbcc056596c..7e8ccf92ae6582ee544642eebe5dc2831f0e64e8 100644 --- a/open-nfapi.oai.patch +++ b/open-nfapi.oai.patch @@ -1,25 +1,7 @@ diff --git a/nfapi/public_inc/nfapi_interface.h b/nfapi/public_inc/nfapi_interface.h -index 2d58c2a..45af99a 100644 +index 2d58c2a..f665d11 100644 --- a/nfapi/public_inc/nfapi_interface.h +++ b/nfapi/public_inc/nfapi_interface.h -@@ -34,7 +34,7 @@ - #define NFAPI_MAX_NUM_ANTENNAS 8 - #define NFAPI_MAX_NUM_SUBBANDS 13 - #define NFAPI_MAX_BF_VECTORS 8 --#define NFAPI_MAX_CC 1 -+#define NFAPI_MAX_CC 2 - #define NFAPI_MAX_NUM_PHYSICAL_ANTENNAS 8 - #define NFAPI_MAX_RSSI 8 - #define NFAPI_MAX_PSC_LIST 32 -@@ -1689,7 +1689,7 @@ typedef struct { - uint16_t number_pdu; - uint8_t number_pdsch_rnti; - uint16_t transmission_power_pcfich; -- nfapi_dl_config_request_pdu_t* dl_config_pdu_list; -+ nfapi_dl_config_request_pdu_t* dl_config_pdu_list; - } nfapi_dl_config_request_body_t; - #define NFAPI_DL_CONFIG_REQUEST_BODY_TAG 0x2000 - @@ -1772,7 +1772,7 @@ typedef struct { uint8_t number_of_cc; struct { @@ -29,12 +11,1104 @@ index 2d58c2a..45af99a 100644 } cc[NFAPI_MAX_CC]; } nfapi_ul_config_aperiodic_cqi_pmi_ri_report_t; -@@ -1962,7 +1962,7 @@ typedef struct { - } nfapi_ul_config_harq_information_rel8_fdd_t; - #define NFAPI_UL_CONFIG_REQUEST_HARQ_INFORMATION_REL8_FDD_TAG 0x2019 +diff --git a/nfapi/src/nfapi.c b/nfapi/src/nfapi.c +index 0e06963..3f017bc 100644 +--- a/nfapi/src/nfapi.c ++++ b/nfapi/src/nfapi.c +@@ -823,6 +823,10 @@ uint8_t pack_tlv(uint16_t tag, void *tlv, uint8_t **ppWritePackedMsg, uint8_t *e + { + NFAPI_TRACE(NFAPI_TRACE_WARN, "Warning pack_tlv tag 0x%x does not match expected 0x%x\n", tl->tag, tag); + } ++ else ++ { ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "Warning pack_tlv tag 0x%x ZERO does not match expected 0x%x\n", tl->tag, tag); ++ } + } + + return 1; +diff --git a/nfapi/src/nfapi_p7.c b/nfapi/src/nfapi_p7.c +index a3b0141..76be11a 100644 +--- a/nfapi/src/nfapi_p7.c ++++ b/nfapi/src/nfapi_p7.c +@@ -111,6 +111,8 @@ static uint8_t pack_dl_config_dci_dl_pdu_rel8_value(void* tlv, uint8_t **ppWrite + { + nfapi_dl_config_dci_dl_pdu_rel8_t* value = (nfapi_dl_config_dci_dl_pdu_rel8_t*)tlv; + ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s() dci_format:%u\n", __FUNCTION__, value->dci_format); ++ + return ( push8(value->dci_format, ppWritePackedMsg, end) && + push8(value->cce_idx, ppWritePackedMsg, end) && + push8(value->aggregation_level, ppWritePackedMsg, end) && +@@ -234,6 +236,8 @@ static uint8_t pack_dl_config_bch_pdu_rel8_value(void* tlv, uint8_t **ppWritePac + { + nfapi_dl_config_bch_pdu_rel8_t* value = (nfapi_dl_config_bch_pdu_rel8_t*)tlv; + ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s()\n", __FUNCTION__); ++ + return( push16(value->length, ppWritePackedMsg, end) && + push16(value->pdu_index, ppWritePackedMsg, end) && + push16(value->transmission_power, ppWritePackedMsg, end)); +@@ -545,6 +549,8 @@ static uint8_t pack_dl_config_request_body_value(void* tlv, uint8_t **ppWritePac + { + nfapi_dl_config_request_body_t* value = (nfapi_dl_config_request_body_t*)tlv; + ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s() dci:%u pdu:%u pdsch:%u rnti:%u pcfich:%u\n", __FUNCTION__, value->number_dci, value->number_pdu, value->number_pdsch_rnti, value->transmission_power_pcfich); ++ + if(!(push8(value->number_pdcch_ofdm_symbols, ppWritePackedMsg, end) && + push8(value->number_dci, ppWritePackedMsg, end) && + push16(value->number_pdu, ppWritePackedMsg, end) && +@@ -574,6 +580,8 @@ static uint8_t pack_dl_config_request_body_value(void* tlv, uint8_t **ppWritePac + { + case NFAPI_DL_CONFIG_DCI_DL_PDU_TYPE: + { ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s() NFAPI_DL_CONFIG_DCI_DL_PDU_TYPE\n", __FUNCTION__); ++ + if(!(pack_tlv(NFAPI_DL_CONFIG_REQUEST_DCI_DL_PDU_REL8_TAG, &pdu->dci_dl_pdu.dci_dl_pdu_rel8, ppWritePackedMsg, end, &pack_dl_config_dci_dl_pdu_rel8_value) && + pack_tlv(NFAPI_DL_CONFIG_REQUEST_DCI_DL_PDU_REL9_TAG, &pdu->dci_dl_pdu.dci_dl_pdu_rel9, ppWritePackedMsg, end, &pack_dl_config_dci_dl_pdu_rel9_value) && + pack_tlv(NFAPI_DL_CONFIG_REQUEST_DCI_DL_PDU_REL10_TAG, &pdu->dci_dl_pdu.dci_dl_pdu_rel10, ppWritePackedMsg, end, &pack_dl_config_dci_dl_pdu_rel10_value) && +@@ -587,6 +595,8 @@ static uint8_t pack_dl_config_request_body_value(void* tlv, uint8_t **ppWritePac + break; + case NFAPI_DL_CONFIG_BCH_PDU_TYPE: + { ++ //NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s() NFAPI_DL_CONFIG_BCH_PDU_TYPE\n", __FUNCTION__); ++ + if(!(pack_tlv(NFAPI_DL_CONFIG_REQUEST_BCH_PDU_REL8_TAG, &pdu->bch_pdu.bch_pdu_rel8, ppWritePackedMsg, end, &pack_dl_config_bch_pdu_rel8_value))) + return 0; + } +@@ -684,10 +694,21 @@ static uint8_t pack_dl_config_request(void *msg, uint8_t **ppWritePackedMsg, uin + { + nfapi_dl_config_request_t *pNfapiMsg = (nfapi_dl_config_request_t*)msg; + +- return ( push16(pNfapiMsg->sfn_sf, ppWritePackedMsg, end) && +- pack_tlv(NFAPI_DL_CONFIG_REQUEST_BODY_TAG, &pNfapiMsg->dl_config_request_body, ppWritePackedMsg, end, &pack_dl_config_request_body_value) && +- pack_p7_vendor_extension_tlv(pNfapiMsg->vendor_extension, ppWritePackedMsg, end, config)); ++ //return ( push16(pNfapiMsg->sfn_sf, ppWritePackedMsg, end) && ++ //pack_tlv(NFAPI_DL_CONFIG_REQUEST_BODY_TAG, &pNfapiMsg->dl_config_request_body, ppWritePackedMsg, end, &pack_dl_config_request_body_value) && ++ //pack_p7_vendor_extension_tlv(pNfapiMsg->vendor_extension, ppWritePackedMsg, end, config)); ++ { ++ uint8_t x = push16(pNfapiMsg->sfn_sf, ppWritePackedMsg, end); ++ uint8_t y = pack_tlv(NFAPI_DL_CONFIG_REQUEST_BODY_TAG, &pNfapiMsg->dl_config_request_body, ppWritePackedMsg, end, &pack_dl_config_request_body_value); ++ uint8_t z = pack_p7_vendor_extension_tlv(pNfapiMsg->vendor_extension, ppWritePackedMsg, end, config); ++ ++ if (!x || !y || !z) ++ { ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() NFAPI_DL_CONFIG_REQUEST x:%u y:%u z:%u \n", __FUNCTION__,x,y,z); ++ } + ++ return x && y && z; ++ } + } + + static uint8_t pack_ul_config_request_ulsch_rel8_value(void *tlv, uint8_t **ppWritePackedMsg, uint8_t * end) +@@ -1518,7 +1539,21 @@ static uint8_t pack_tx_request_body_value(void* tlv, uint8_t **ppWritePackedMsg, + for(j = 0; j < pdu->num_segments; ++j) + { + // Use -1 as it is unbounded +- if(pusharray8(pdu->segments[j].segment_data, (uint32_t)(-1), pdu->segments[j].segment_length, ppWritePackedMsg, end) == 0) ++ // DJP - does not handle -1 ++ // DJP - if(pusharray8(pdu->segments[j].segment_data, (uint32_t)(-1), pdu->segments[j].segment_length, ppWritePackedMsg, end) == 0) ++ int push_ret = pusharray8(pdu->segments[j].segment_data, 65535, pdu->segments[j].segment_length, ppWritePackedMsg, end); ++ ++ if (0 && pdu->segments[j].segment_length == 3) ++ { ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() BCH? segment_data:%x %x %x\n", __FUNCTION__, ++ pdu->segments[j].segment_data[0], ++ pdu->segments[j].segment_data[1], ++ pdu->segments[j].segment_data[2] ++ ); ++ } ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() segment_data:%p segment_length:%u pusharray8()=%d\n", __FUNCTION__, pdu->segments[j].segment_data, pdu->segments[j].segment_length, push_ret); ++ ++ if (push_ret == 0) + { + return 0; + } +@@ -1532,9 +1567,13 @@ static uint8_t pack_tx_request(void *msg, uint8_t **ppWritePackedMsg, uint8_t *e + { + nfapi_tx_request_t *pNfapiMsg = (nfapi_tx_request_t*)msg; + +- return ( push16(pNfapiMsg->sfn_sf, ppWritePackedMsg, end) && +- pack_tlv(NFAPI_TX_REQUEST_BODY_TAG, &pNfapiMsg->tx_request_body, ppWritePackedMsg, end, &pack_tx_request_body_value) && +- pack_p7_vendor_extension_tlv(pNfapiMsg->vendor_extension, ppWritePackedMsg, end, config)); ++ int x = push16(pNfapiMsg->sfn_sf, ppWritePackedMsg, end); ++ int y = pack_tlv(NFAPI_TX_REQUEST_BODY_TAG, &pNfapiMsg->tx_request_body, ppWritePackedMsg, end, &pack_tx_request_body_value); ++ int z = pack_p7_vendor_extension_tlv(pNfapiMsg->vendor_extension, ppWritePackedMsg, end, config); ++ ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() x:%d y:%d z:%d\n", __FUNCTION__, x, y, z); ++ ++ return x && y && z; + } + + static uint8_t pack_rx_ue_information_value(void* tlv, uint8_t **ppWritePackedMsg, uint8_t *end) +@@ -2592,11 +2631,16 @@ int nfapi_p7_message_pack(void *pMessageBuf, void *pPackedBuf, uint32_t packedBu + return -1; + } + ++ if (pMessageHeader->message_id != NFAPI_TIMING_INFO) ++ { ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() message_id:0x%04x phy_id:%u m_segment_sequence:%u timestamp:%u\n", __FUNCTION__, pMessageHeader->message_id, pMessageHeader->phy_id, pMessageHeader->m_segment_sequence, pMessageHeader->transmit_timestamp); ++ } + // look for the specific message + uint8_t result = 0; + switch (pMessageHeader->message_id) + { + case NFAPI_DL_CONFIG_REQUEST: ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() NFAPI_DL_CONFIG_REQUEST\n", __FUNCTION__); + result = pack_dl_config_request(pMessageHeader, &pWritePackedMessage, end, config); + break; + +@@ -2609,6 +2653,7 @@ int nfapi_p7_message_pack(void *pMessageBuf, void *pPackedBuf, uint32_t packedBu + break; + + case NFAPI_TX_REQUEST: ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() NFAPI_TX_REQUEST\n", __FUNCTION__); + result = pack_tx_request(pMessageHeader, &pWritePackedMessage, end, config); + break; + +@@ -4394,6 +4439,14 @@ static uint8_t unpack_tx_request(uint8_t **ppReadPackedMsg, uint8_t *end, void * + { + if(!pullarray8(ppReadPackedMsg, pdu->segments[0].segment_data, pdu->segments[0].segment_length, pdu->segments[0].segment_length, end)) + return 0; ++ if (0 && pdu->segments[0].segment_length == 3) ++ { ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() BCH? segment_data:%x %x %x\n", __FUNCTION__, ++ pdu->segments[0].segment_data[0], ++ pdu->segments[0].segment_data[1], ++ pdu->segments[0].segment_data[2] ++ ); ++ } + } + else + { +diff --git a/pnf/public_inc/nfapi_pnf_interface.h b/pnf/public_inc/nfapi_pnf_interface.h +index f93624d..e48b932 100644 +--- a/pnf/public_inc/nfapi_pnf_interface.h ++++ b/pnf/public_inc/nfapi_pnf_interface.h +@@ -319,10 +319,10 @@ typedef struct nfapi_pnf_config + * 0 will be returned if it fails. + * + * \code +- * nfapi_pnf_config_t* config = nfapi_pnf_config_create(); ++ * nfapi_pnf_config_t* config = nfapi_pnf_config_create(void); + * \endcode + */ +-nfapi_pnf_config_t* nfapi_pnf_config_create(); ++nfapi_pnf_config_t* nfapi_pnf_config_create(void); + + /*! Delete a pnf configuration + * \param config A pointer to a pnf configuraiton +@@ -338,7 +338,7 @@ int nfapi_pnf_config_destroy(nfapi_pnf_config_t* config); + * + * \code + * // Create the pnf config +- * nfapi_pnf_config_t* config = nfapi_pnf_config_create(); ++ * nfapi_pnf_config_t* config = nfapi_pnf_config_create(void); + * + * // Assumed that the vnf_address and vnf_port are provided over the P9 interface + * config->vnf_ip_addr = vnf_address; +@@ -681,7 +681,7 @@ typedef struct nfapi_pnf_p7_config + /*! Create and initialise a nfapi_pnf_p7_config structure + * \return A pointer to a PNF P7 config structure + */ +-nfapi_pnf_p7_config_t* nfapi_pnf_p7_config_create(); ++nfapi_pnf_p7_config_t* nfapi_pnf_p7_config_create(void); + + /*! Delete an nfapi_pnf_p7_config structure + * \param config +diff --git a/pnf/src/pnf.c b/pnf/src/pnf.c +index d6cf364..d0a7fa6 100644 +--- a/pnf/src/pnf.c ++++ b/pnf/src/pnf.c +@@ -412,10 +412,10 @@ void pnf_handle_start_request(pnf_t* pnf, void *pRecvMsg, int recvMsgLen) + { + nfapi_start_request_t req; + +- NFAPI_TRACE(NFAPI_TRACE_INFO, "START.request received\n"); +- + nfapi_pnf_config_t* config = &(pnf->_public); + ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() START.request received state:%d\n", __FUNCTION__, config->state); ++ + // unpack the message + if (nfapi_p5_message_unpack(pRecvMsg, recvMsgLen, &req, sizeof(req), &config->codec_config) >= 0) + { +diff --git a/pnf/src/pnf_interface.c b/pnf/src/pnf_interface.c +index 74f29a0..7310fc0 100644 +--- a/pnf/src/pnf_interface.c ++++ b/pnf/src/pnf_interface.c +@@ -76,6 +76,7 @@ int nfapi_pnf_start(nfapi_pnf_config_t* config) + + sleep(1); + } ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() terminate=1 - EXITTING............\n", __FUNCTION__); + + return 0; + } +@@ -227,7 +228,7 @@ int nfapi_pnf_start_resp(nfapi_pnf_config_t* config, nfapi_start_response_t* res + } + else + { +- NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s: unknow phy id %d\n", __FUNCTION__, resp->header.phy_id); ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s: unknown phy id %d\n", __FUNCTION__, resp->header.phy_id); + return -1; + } + +diff --git a/pnf/src/pnf_p7.c b/pnf/src/pnf_p7.c +index 0fd7828..94b4fba 100644 +--- a/pnf/src/pnf_p7.c ++++ b/pnf/src/pnf_p7.c +@@ -30,7 +30,7 @@ + + #define FAPI2_IP_DSCP 0 + +-uint32_t get_current_time_hr() ++uint32_t pnf_get_current_time_hr() + { + struct timeval now; + (void)gettimeofday(&now, NULL); +@@ -307,11 +307,11 @@ void pnf_p7_rx_reassembly_queue_remove_old_msgs(pnf_p7_t* pnf_p7, pnf_p7_rx_reas + } + + +-uint32_t get_sf_time(uint32_t now_hr, uint32_t sf_start_hr) ++static uint32_t get_sf_time(uint32_t now_hr, uint32_t sf_start_hr) + { + if(now_hr < sf_start_hr) + { +- NFAPI_TRACE(NFAPI_TRACE_INFO, "now is earlier that start of subframe\n"); ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "now is earlier than start of subframe now_hr:%u sf_start_hr:%u\n", now_hr, sf_start_hr); + return 0; + } + else +@@ -482,29 +482,36 @@ void pnf_pack_and_send_timing_info(pnf_p7_t* pnf_p7) + + void send_dummy_subframe(pnf_p7_t* pnf_p7, uint16_t sfn_sf) + { ++ if(pnf_p7->_public.tx_req && pnf_p7->_public.dummy_subframe.tx_req) ++ { ++ pnf_p7->_public.dummy_subframe.tx_req->sfn_sf = sfn_sf; ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy tx_req - enter\n"); ++ (pnf_p7->_public.tx_req)(&pnf_p7->_public, pnf_p7->_public.dummy_subframe.tx_req); ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy tx_req - exit\n"); ++ } + if(pnf_p7->_public.dl_config_req && pnf_p7->_public.dummy_subframe.dl_config_req) + { + pnf_p7->_public.dummy_subframe.dl_config_req->sfn_sf = sfn_sf; ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy dl_config_req - enter\n"); + (pnf_p7->_public.dl_config_req)(&(pnf_p7->_public), pnf_p7->_public.dummy_subframe.dl_config_req); ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy dl_config_req - exit\n"); + } + if(pnf_p7->_public.ul_config_req && pnf_p7->_public.dummy_subframe.ul_config_req) + { + pnf_p7->_public.dummy_subframe.ul_config_req->sfn_sf = sfn_sf; ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy ul_config_req - enter\n"); + (pnf_p7->_public.ul_config_req)(&pnf_p7->_public, pnf_p7->_public.dummy_subframe.ul_config_req); + } + if(pnf_p7->_public.hi_dci0_req && pnf_p7->_public.dummy_subframe.hi_dci0_req) + { + pnf_p7->_public.dummy_subframe.hi_dci0_req->sfn_sf = sfn_sf; ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy hi_dci0 - enter\n"); + (pnf_p7->_public.hi_dci0_req)(&pnf_p7->_public, pnf_p7->_public.dummy_subframe.hi_dci0_req); + } +- if(pnf_p7->_public.tx_req && pnf_p7->_public.dummy_subframe.tx_req) +- { +- pnf_p7->_public.dummy_subframe.tx_req->sfn_sf = sfn_sf; +- (pnf_p7->_public.tx_req)(&pnf_p7->_public, pnf_p7->_public.dummy_subframe.tx_req); +- } + if(pnf_p7->_public.lbt_dl_config_req && pnf_p7->_public.dummy_subframe.lbt_dl_config_req) + { + pnf_p7->_public.dummy_subframe.lbt_dl_config_req->sfn_sf = sfn_sf; ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "Dummy lbt - enter\n"); + (pnf_p7->_public.lbt_dl_config_req)(&pnf_p7->_public, pnf_p7->_public.dummy_subframe.lbt_dl_config_req); + } + } +@@ -527,7 +534,7 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + } + + // save the curren time and sfn_sf +- pnf_p7->sf_start_time_hr = get_current_time_hr(); ++ pnf_p7->sf_start_time_hr = pnf_get_current_time_hr(); + pnf_p7->sfn_sf = sfn_sf; + + // If the subframe_buffer has been configured +@@ -558,18 +565,38 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + + nfapi_pnf_p7_subframe_buffer_t* subframe_buffer = &(pnf_p7->subframe_buffer[buffer_index]); + ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() subframe_buffer->sfn_sf:%d sfn_sf:%d sfn_sf_dec:%d buffer_index:%u subframe_buffer->dl_config_req:%p\n", ++ //__FUNCTION__, subframe_buffer->sfn_sf, sfn_sf, sfn_sf_dec, buffer_index, subframe_buffer->dl_config_req); ++ + // if the subframe buffer sfn sf is set then we have atlease 1 message + // from the vnf. + // todo : how to handle the messages we don't have, send dummies for + // now + if(subframe_buffer->sfn_sf == sfn_sf) + { ++ if(subframe_buffer->tx_req != 0) ++ { ++ if(pnf_p7->_public.tx_req) ++ (pnf_p7->_public.tx_req)(&(pnf_p7->_public), subframe_buffer->tx_req); ++ ++ //deallocate_nfapi_tx_request(subframe_buffer->tx_req, pnf_p7); ++ } ++ else ++ { ++ // send dummy ++ if(pnf_p7->_public.tx_req && pnf_p7->_public.dummy_subframe.tx_req) ++ { ++ pnf_p7->_public.dummy_subframe.tx_req->sfn_sf = sfn_sf; ++ (pnf_p7->_public.tx_req)(&(pnf_p7->_public), pnf_p7->_public.dummy_subframe.tx_req); ++ } ++ } ++ + if(subframe_buffer->dl_config_req != 0) + { + if(pnf_p7->_public.dl_config_req) + (pnf_p7->_public.dl_config_req)(&(pnf_p7->_public), subframe_buffer->dl_config_req); + +- deallocate_nfapi_dl_config_request(subframe_buffer->dl_config_req, pnf_p7); ++ //deallocate_nfapi_dl_config_request(subframe_buffer->dl_config_req, pnf_p7); + } + else + { +@@ -586,7 +613,7 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + if(pnf_p7->_public.ul_config_req) + (pnf_p7->_public.ul_config_req)(&(pnf_p7->_public), subframe_buffer->ul_config_req); + +- deallocate_nfapi_ul_config_request(subframe_buffer->ul_config_req, pnf_p7); ++ //deallocate_nfapi_ul_config_request(subframe_buffer->ul_config_req, pnf_p7); + } + else + { +@@ -603,7 +630,7 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + if(pnf_p7->_public.hi_dci0_req) + (pnf_p7->_public.hi_dci0_req)(&(pnf_p7->_public), subframe_buffer->hi_dci0_req); + +- deallocate_nfapi_hi_dci0_request(subframe_buffer->hi_dci0_req, pnf_p7); ++ //deallocate_nfapi_hi_dci0_request(subframe_buffer->hi_dci0_req, pnf_p7); + } + else + { +@@ -615,29 +642,12 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + } + } + +- if(subframe_buffer->tx_req != 0) +- { +- if(pnf_p7->_public.tx_req) +- (pnf_p7->_public.tx_req)(&(pnf_p7->_public), subframe_buffer->tx_req); +- +- deallocate_nfapi_tx_request(subframe_buffer->tx_req, pnf_p7); +- } +- else +- { +- // send dummy +- if(pnf_p7->_public.tx_req && pnf_p7->_public.dummy_subframe.tx_req) +- { +- pnf_p7->_public.dummy_subframe.tx_req->sfn_sf = sfn_sf; +- (pnf_p7->_public.tx_req)(&(pnf_p7->_public), pnf_p7->_public.dummy_subframe.tx_req); +- } +- } +- + if(subframe_buffer->lbt_dl_config_req != 0) + { + if(pnf_p7->_public.lbt_dl_config_req) + (pnf_p7->_public.lbt_dl_config_req)(&(pnf_p7->_public), subframe_buffer->lbt_dl_config_req); + +- deallocate_nfapi_lbt_dl_config_request(subframe_buffer->lbt_dl_config_req, pnf_p7); ++ //deallocate_nfapi_lbt_dl_config_request(subframe_buffer->lbt_dl_config_req, pnf_p7); + } + else + { +@@ -650,6 +660,17 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + + } + ++ if(subframe_buffer->dl_config_req != 0) ++ deallocate_nfapi_dl_config_request(subframe_buffer->dl_config_req, pnf_p7); ++ if(subframe_buffer->ul_config_req != 0) ++ deallocate_nfapi_ul_config_request(subframe_buffer->ul_config_req, pnf_p7); ++ if(subframe_buffer->hi_dci0_req != 0) ++ deallocate_nfapi_hi_dci0_request(subframe_buffer->hi_dci0_req, pnf_p7); ++ if(subframe_buffer->tx_req != 0) ++ deallocate_nfapi_tx_request(subframe_buffer->tx_req, pnf_p7); ++ if(subframe_buffer->lbt_dl_config_req != 0) ++ deallocate_nfapi_lbt_dl_config_request(subframe_buffer->lbt_dl_config_req, pnf_p7); ++ + memset(&(pnf_p7->subframe_buffer[buffer_index]), 0, sizeof(nfapi_pnf_p7_subframe_buffer_t)); + pnf_p7->subframe_buffer[buffer_index].sfn_sf = -1; + } +@@ -685,7 +706,7 @@ int pnf_p7_subframe_ind(pnf_p7_t* pnf_p7, uint16_t phy_id, uint16_t sfn_sf) + if(pnf_p7->tick == 1000) + { + +- NFAPI_TRACE(NFAPI_TRACE_INFO, "[PNF P7:%d] DL:(%d/%d) UL:(%d/%d) HI:(%d/%d) TX:(%d/%d)\n", pnf_p7->_public.phy_id, ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "[PNF P7:%d] (ONTIME/LATE) DL:(%d/%d) UL:(%d/%d) HI:(%d/%d) TX:(%d/%d)\n", pnf_p7->_public.phy_id, + pnf_p7->stats.dl_conf_ontime, pnf_p7->stats.dl_conf_late, + pnf_p7->stats.ul_conf_ontime, pnf_p7->stats.ul_conf_late, + pnf_p7->stats.hi_dci0_ontime, pnf_p7->stats.hi_dci0_late, +@@ -724,7 +745,7 @@ uint8_t is_p7_request_in_window(uint16_t sfnsf, const char* name, pnf_p7_t* phy) + if(recv_sfn_sf_dec > ((current_sfn_sf_dec + timing_window) % NFAPI_MAX_SFNSFDEC)) + { + // out of window +- //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is late %d (with wrap)\n", current_sfn_sf_dec, name, recv_sfn_sf_dec); ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is late %d (with wrap)\n", current_sfn_sf_dec, name, recv_sfn_sf_dec); + } + else + { +@@ -736,7 +757,7 @@ uint8_t is_p7_request_in_window(uint16_t sfnsf, const char* name, pnf_p7_t* phy) + else + { + // too late +- //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is in late %d (%d)\n", current_sfn_sf_dec, name, recv_sfn_sf_dec, (current_sfn_sf_dec - recv_sfn_sf_dec)); ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is in late %d (delta:%d)\n", current_sfn_sf_dec, name, recv_sfn_sf_dec, (current_sfn_sf_dec - recv_sfn_sf_dec)); + } + + } +@@ -751,8 +772,8 @@ uint8_t is_p7_request_in_window(uint16_t sfnsf, const char* name, pnf_p7_t* phy) + } + else + { +- // to far in the future +- //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is out of window %d (%d) [%d]\n", current_sfn_sf_dec, name, recv_sfn_sf_dec, (recv_sfn_sf_dec - current_sfn_sf_dec), timing_window); ++ // too far in the future ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] %s is out of window %d (delta:%d) [max:%d]\n", current_sfn_sf_dec, name, recv_sfn_sf_dec, (recv_sfn_sf_dec - current_sfn_sf_dec), timing_window); + } + + } +@@ -785,15 +806,30 @@ void pnf_handle_dl_config_request(void* pRecvMsg, int recvMsgLen, pnf_p7_t* pnf_ + return; + } + +- if(is_p7_request_in_window(req->sfn_sf, "dl_config_request", pnf_p7)) +- { +- uint32_t sfn_sf_dec = NFAPI_SFNSF2DEC(req->sfn_sf); +- uint8_t buffer_index = sfn_sf_dec % pnf_p7->_public.subframe_buffer_size; ++ if ( ++ 0 && ++ (NFAPI_SFNSF2DEC(req->sfn_sf) % 100 ==0 || ++ NFAPI_SFNSF2DEC(req->sfn_sf) % 105 ==0 ++ ) ++ ) ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "DL_CONFIG.req sfn_sf:%d pdcch:%u dci:%u pdu:%u pdsch_rnti:%u pcfich:%u\n", ++ NFAPI_SFNSF2DEC(req->sfn_sf), ++ req->dl_config_request_body.number_pdcch_ofdm_symbols, ++ req->dl_config_request_body.number_dci, ++ req->dl_config_request_body.number_pdu, ++ req->dl_config_request_body.number_pdsch_rnti, ++ req->dl_config_request_body.transmission_power_pcfich ++ ); ++ ++ if(is_p7_request_in_window(req->sfn_sf, "dl_config_request", pnf_p7)) ++ { ++ uint32_t sfn_sf_dec = NFAPI_SFNSF2DEC(req->sfn_sf); ++ uint8_t buffer_index = sfn_sf_dec % pnf_p7->_public.subframe_buffer_size; + + // if there is already an dl_config_req make sure we free it. + if(pnf_p7->subframe_buffer[buffer_index].dl_config_req != 0) + { +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "HERE HERE HERE\n"); ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "%s() is_p7_request_in_window()=TRUE buffer_index occupied - free it first sfn_sf:%d buffer_index:%d\n", __FUNCTION__, NFAPI_SFNSF2DEC(req->sfn_sf), buffer_index); + //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] Freeing dl_config_req at index %d (%d/%d)", + // pMyPhyInfo->sfnSf, bufferIdx, + // SFNSF2SFN(dreq->sfn_sf), SFNSF2SF(dreq->sfn_sf)); +@@ -994,6 +1030,11 @@ void pnf_handle_tx_request(void* pRecvMsg, int recvMsgLen, pnf_p7_t* pnf_p7) + uint32_t sfn_sf_dec = NFAPI_SFNSF2DEC(req->sfn_sf); + uint8_t buffer_index = sfn_sf_dec % pnf_p7->_public.subframe_buffer_size; + ++ if (0 && NFAPI_SFNSF2DEC(req->sfn_sf)%100==0) NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() TX_REQ.req sfn_sf:%d pdus:%d - TX_REQ is within window\n", ++ __FUNCTION__, ++ NFAPI_SFNSF2DEC(req->sfn_sf), ++ req->tx_request_body.number_of_pdus); ++ + if(pnf_p7->subframe_buffer[buffer_index].tx_req != 0) + { + //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[%d] Freeing tx_req at index %d (%d/%d)", +@@ -1126,12 +1167,27 @@ uint32_t calculate_t2(uint32_t now_time_hr, uint16_t sfn_sf, uint32_t sf_start_t + uint32_t sf_time_us = get_sf_time(now_time_hr, sf_start_time_hr); + uint32_t t2 = (NFAPI_SFNSF2DEC(sfn_sf) * 1000) + sf_time_us; + ++ if (0) ++ { ++ static uint32_t prev_t2 = 0; ++ ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s(now_time_hr:%u sfn_sf:%d sf_start_time_Hr:%u) sf_time_us:%u t2:%u prev_t2:%u diff:%u\n", ++ __FUNCTION__, ++ now_time_hr, NFAPI_SFNSF2DEC(sfn_sf), sf_start_time_hr, ++ sf_time_us, ++ t2, ++ prev_t2, ++ t2-prev_t2); ++ ++ prev_t2 = t2; ++ } ++ + return t2; + } + + uint32_t calculate_t3(uint16_t sfn_sf, uint32_t sf_start_time_hr) + { +- uint32_t now_time_hr = get_current_time_hr(); ++ uint32_t now_time_hr = pnf_get_current_time_hr(); + + uint32_t sf_time_us = get_sf_time(now_time_hr, sf_start_time_hr); + +@@ -1391,6 +1447,8 @@ void pnf_nfapi_p7_read_dispatch_message(pnf_p7_t* pnf_p7, uint32_t now_hr_time) + // read the segment + recvfrom_result = recvfrom(pnf_p7->p7_sock, pnf_p7->rx_message_buffer, header.message_length, MSG_DONTWAIT, (struct sockaddr*)&remote_addr, &remote_addr_size); + ++ now_hr_time = pnf_get_current_time_hr(); //DJP - moved to here - get closer timestamp??? ++ + if(recvfrom_result > 0) + { + pnf_handle_p7_message(pnf_p7->rx_message_buffer, recvfrom_result, pnf_p7, now_hr_time); +@@ -1417,7 +1475,10 @@ void pnf_nfapi_p7_read_dispatch_message(pnf_p7_t* pnf_p7, uint32_t now_hr_time) + + // need to update the time as we would only use the value from the + // select +- now_hr_time = get_current_time_hr(); ++#if 0 ++// DJP - why do this here and not on return from recv??? ++ now_hr_time = pnf_get_current_time_hr(); ++#endif + } + while(recvfrom_result > 0); + } +@@ -1512,7 +1573,7 @@ int pnf_p7_message_pump(pnf_p7_t* pnf_p7) + + selectRetval = select(pnf_p7->p7_sock+1, &rfds, NULL, NULL, &timeout); + +- uint32_t now_hr_time = get_current_time_hr(); ++ uint32_t now_hr_time = pnf_get_current_time_hr(); + + if(selectRetval == 0) + { +diff --git a/vnf/inc/vnf_p7.h b/vnf/inc/vnf_p7.h +index ab9a335..fc2ab4e 100644 +--- a/vnf/inc/vnf_p7.h ++++ b/vnf/inc/vnf_p7.h +@@ -116,7 +116,8 @@ typedef struct { + + } vnf_p7_t; + +-uint32_t get_current_time_hr(); ++uint32_t vnf_get_current_time_hr(void); ++ + uint16_t increment_sfn_sf(uint16_t sfn_sf); + int vnf_sync(vnf_p7_t* vnf_p7, nfapi_vnf_p7_connection_info_t* p7_info); + int send_mac_subframe_indications(vnf_p7_t* config); +diff --git a/vnf/public_inc/nfapi_vnf_interface.h b/vnf/public_inc/nfapi_vnf_interface.h +index 6659e5d..4629013 100644 +--- a/vnf/public_inc/nfapi_vnf_interface.h ++++ b/vnf/public_inc/nfapi_vnf_interface.h +@@ -450,7 +450,7 @@ typedef struct nfapi_vnf_config + /*! Creates and initialise the vnf config structure before use + * \return A pointer to a vnf config structure + */ +-nfapi_vnf_config_t* nfapi_vnf_config_create(); ++nfapi_vnf_config_t* nfapi_vnf_config_create(void); + + /*! Delete an vnf config + */ +@@ -864,7 +864,7 @@ typedef struct nfapi_vnf_p7_config + /*! Creates and initializes the nfapi_vnf_p7_config structure before use + * \return A pointer to an allocated vnf p7 configuration + */ +-nfapi_vnf_p7_config_t* nfapi_vnf_p7_config_create(); ++nfapi_vnf_p7_config_t* nfapi_vnf_p7_config_create(void); + + /*! Cleanup and delete nfapi_vnf_p7_config structure + * \param config A pointer to an vnf p7 configuration structure +diff --git a/vnf/src/vnf.c b/vnf/src/vnf.c +index fea3cf7..6800ee2 100644 +--- a/vnf/src/vnf.c ++++ b/vnf/src/vnf.c +@@ -82,11 +82,18 @@ void nfapi_vnf_pnf_list_add(nfapi_vnf_config_t* config, nfapi_vnf_pnf_info_t* no + + nfapi_vnf_pnf_info_t* nfapi_vnf_pnf_list_find(nfapi_vnf_config_t* config, int p5_idx) + { ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s : config->pnf_list:%p\n", __FUNCTION__, config->pnf_list); ++ + nfapi_vnf_pnf_info_t* curr = config->pnf_list; + while(curr != 0) + { + if(curr->p5_idx == p5_idx) ++ { ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s : curr->p5_idx:%d p5_idx:%d\n", __FUNCTION__, curr->p5_idx, p5_idx); + return curr; ++ } ++ ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s : curr->next:%p\n", __FUNCTION__, curr->next); + + curr = curr->next; + } +diff --git a/vnf/src/vnf_interface.c b/vnf/src/vnf_interface.c +index e559730..163bb6b 100644 +--- a/vnf/src/vnf_interface.c ++++ b/vnf/src/vnf_interface.c +@@ -342,6 +342,7 @@ int nfapi_vnf_start(nfapi_vnf_config_t* config) + { + NFAPI_TRACE(NFAPI_TRACE_INFO, "PNF connection (fd:%d) accepted from %s:%d \n", p5Sock, inet_ntoa(addr.sin_addr), ntohs(addr.sin_port)); + nfapi_vnf_pnf_info_t* pnf = (nfapi_vnf_pnf_info_t*)malloc(sizeof(nfapi_vnf_pnf_info_t)); ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "MALLOC nfapi_vnf_pnf_info_t for pnf_list pnf:%p\n", pnf); + memset(pnf, 0, sizeof(nfapi_vnf_pnf_info_t)); + pnf->p5_sock = p5Sock; + pnf->p5_idx = p5_idx++; +diff --git a/vnf/src/vnf_p7.c b/vnf/src/vnf_p7.c +index 8630385..4947c40 100644 +--- a/vnf/src/vnf_p7.c ++++ b/vnf/src/vnf_p7.c +@@ -15,6 +15,8 @@ + */ + + ++#include <time.h> ++ + #include <sys/time.h> + #include <stdlib.h> + #include <string.h> +@@ -159,7 +161,7 @@ vnf_p7_rx_message_t* vnf_p7_rx_reassembly_queue_add_segment(vnf_p7_t* vnf_p7, vn + msg->sequence_number = sequence_number; + msg->num_segments_expected = m ? 255 : segment_number + 1; + msg->num_segments_received = 1; +- msg->rx_hr_time = get_current_time_hr(); ++ msg->rx_hr_time = vnf_get_current_time_hr(); + + msg->segments[segment_number].buffer = (uint8_t*)vnf_p7_malloc(vnf_p7, data_len); + memcpy(msg->segments[segment_number].buffer, data, data_len); +@@ -216,7 +218,7 @@ void vnf_p7_rx_reassembly_queue_remove_old_msgs(vnf_p7_t* vnf_p7, vnf_p7_rx_reas + vnf_p7_rx_message_t* iterator = queue->msg_queue; + vnf_p7_rx_message_t* previous = 0; + +- uint32_t rx_hr_time = get_current_time_hr(); ++ uint32_t rx_hr_time = vnf_get_current_time_hr(); + + while(iterator != 0) + { +@@ -254,7 +256,7 @@ void vnf_p7_rx_reassembly_queue_remove_old_msgs(vnf_p7_t* vnf_p7, vnf_p7_rx_reas + } + } + +-uint32_t get_current_time_hr() ++uint32_t vnf_get_current_time_hr() + { + struct timeval now; + (void)gettimeofday(&now, NULL); +@@ -297,7 +299,7 @@ struct timespec timespec_delta(struct timespec start, struct timespec end) + return temp; + } + +-uint32_t get_sf_time(uint32_t now_hr, uint32_t sf_start_hr) ++static uint32_t get_sf_time(uint32_t now_hr, uint32_t sf_start_hr) + { + if(now_hr < sf_start_hr) + { +@@ -321,7 +323,7 @@ uint32_t get_sf_time(uint32_t now_hr, uint32_t sf_start_hr) + + uint32_t calculate_t1(uint16_t sfn_sf, uint32_t sf_start_time_hr) + { +- uint32_t now_time_hr = get_current_time_hr(); ++ uint32_t now_time_hr = vnf_get_current_time_hr(); + + uint32_t sf_time_us = get_sf_time(now_time_hr, sf_start_time_hr); + +@@ -344,7 +346,7 @@ uint32_t calculate_t4(uint32_t now_time_hr, uint16_t sfn_sf, uint32_t sf_start_t + + uint32_t calculate_transmit_timestamp(uint16_t sfn_sf, uint32_t sf_start_time_hr) + { +- uint32_t now_time_hr = get_current_time_hr(); ++ uint32_t now_time_hr = vnf_get_current_time_hr(); + + uint32_t sf_time_us = get_sf_time(now_time_hr, sf_start_time_hr); + +@@ -410,6 +412,8 @@ int vnf_p7_pack_and_send_p7_msg(vnf_p7_t* vnf_p7, nfapi_p7_message_header_t* hea + + int len = nfapi_p7_message_pack(header, buffer, sizeof(buffer), &vnf_p7->_public.codec_config); + ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() phy_id:%d nfapi_p7_message_pack()=len=%d vnf_p7->_public.segment_size:%u\n", __FUNCTION__, header->phy_id, len, vnf_p7->_public.segment_size); ++ + if(len < 0) + { + NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() failed to pack p7 message phy_id:%d\n", __FUNCTION__, header->phy_id); +@@ -429,6 +433,7 @@ int vnf_p7_pack_and_send_p7_msg(vnf_p7_t* vnf_p7, nfapi_p7_message_header_t* hea + int segment = 0; + int offset = NFAPI_P7_HEADER_LENGTH; + uint8_t tx_buffer[vnf_p7->_public.segment_size]; ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() MORE THAN ONE SEGMENT phy_id:%d nfapi_p7_message_pack()=len=%d vnf_p7->_public.segment_size:%u\n", __FUNCTION__, header->phy_id, len, vnf_p7->_public.segment_size); + for(segment = 0; segment < segment_count; ++segment) + { + uint8_t last = 0; +@@ -851,7 +856,7 @@ void vnf_handle_p7_vendor_extension(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vn + + void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + { +- uint32_t now_time_hr = get_current_time_hr(); ++ uint32_t now_time_hr = vnf_get_current_time_hr(); + + if (pRecvMsg == NULL || vnf_p7 == NULL) + { +@@ -871,7 +876,7 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + nfapi_vnf_p7_connection_info_t* phy = vnf_p7_connection_info_list_find(vnf_p7, ind.header.phy_id); + uint32_t t4 = calculate_t4(now_time_hr, phy->sfn_sf, vnf_p7->sf_start_time_hr); + +- uint32_t tx_2_rx = t4 - ind.t1; ++ uint32_t tx_2_rx = t4>ind.t1 ? t4 - ind.t1 : t4 + NFAPI_MAX_SFNSFDEC - ind.t1 ; + uint32_t pnf_proc_time = ind.t3 - ind.t2; + + // divide by 2 using shift operator +@@ -881,7 +886,7 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + { + phy->latency[phy->min_sync_cycle_count] = latency; + +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%d/%d) PNF to VNF !sync phy_id:%d (t1/2/3/4:%8u, %8u, %8u, %8u) txrx:%4u procT:%3u latency(us):%4d\n", ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%4d/%d) PNF to VNF !sync phy_id:%d (t1/2/3/4:%8u, %8u, %8u, %8u) txrx:%4u procT:%3u latency(us):%4d\n", + NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ind.header.phy_id, ind.t1, ind.t2, ind.t3, t4, + tx_2_rx, pnf_proc_time, latency); + } +@@ -923,15 +928,27 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + + if(1) + { +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%4d/%1d) PNF to VNF phy_id:%2d (t1/2/3/4:%8u, %8u, %8u, %8u) txrx:%4u procT:%3u latency(us):%4d offset(us):%8d filtered(us):%8d wrap[t1:%u t2:%u]\n", +- NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ind.header.phy_id, ++ struct timespec ts; ++ clock_gettime(CLOCK_MONOTONIC, &ts); ++ ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%4d/%1d) %d.%d PNF to VNF phy_id:%2d (t1/2/3/4:%8u, %8u, %8u, %8u) txrx:%4u procT:%3u latency(us):%4d(avg:%4d) offset(us):%8d filtered(us):%8d wrap[t1:%u t2:%u]\n", ++ NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ts.tv_sec, ts.tv_nsec, ind.header.phy_id, + ind.t1, ind.t2, ind.t3, t4, +- tx_2_rx, pnf_proc_time, latency, phy->sf_offset, phy->sf_offset_filtered, ++ tx_2_rx, pnf_proc_time, latency, phy->average_latency, phy->sf_offset, phy->sf_offset_filtered, + (ind.t1<phy->previous_t1), (ind.t2<phy->previous_t2)); + } + + } + ++ if (phy->filtered_adjust && (phy->sf_offset_filtered > 1e6 || phy->sf_offset_filtered < -1e6)) ++ { ++ phy->filtered_adjust = 0; ++ phy->zero_count=0; ++ phy->min_sync_cycle_count = 2; ++ phy->in_sync = 0; ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "%s - ADJUST TOO BAD - go out of filtered phy->sf_offset_filtered:%d\n", __FUNCTION__, phy->sf_offset_filtered); ++ } ++ + if(phy->min_sync_cycle_count) + phy->min_sync_cycle_count--; + +@@ -954,7 +971,6 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + phy->sf_offset = ind.t2 - (ind.t1 - phy->average_latency); + + sfn_sf_dec += (phy->sf_offset / 1000); +- + } + else + { +@@ -981,7 +997,6 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + phy->previous_t1 = 0; + phy->previous_t2 = 0; + +- + if(phy->previous_sf_offset_filtered > 0) + { + if( phy->sf_offset_filtered > phy->previous_sf_offset_filtered) +@@ -1083,9 +1098,14 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + + if(phy->insync_minor_adjustment != 0) + { +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d suframes (sf_offset_filtered:%d) %d %d %d\n", ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%4d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d subframes (sf_offset_filtered:%d) %d %d %d NEW:%d CURR:%d adjustment:%d\n", + NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ind.header.phy_id, +- phy->insync_minor_adjustment, phy->insync_minor_adjustment_duration, phy->sf_offset_filtered, insync_minor_adjustment_1, insync_minor_adjustment_2, phy->sf_offset_trend); ++ phy->insync_minor_adjustment, phy->insync_minor_adjustment_duration, ++ phy->sf_offset_filtered, ++ insync_minor_adjustment_1, insync_minor_adjustment_2, phy->sf_offset_trend, ++ NFAPI_SFNSF2DEC(new_sfn_sf), ++ NFAPI_SFNSF2DEC(curr_sfn_sf), ++ phy->adjustment); + } + } + } +@@ -1121,10 +1141,13 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + // out of sync? + } + +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d suframes (adjusment:%d sf_offset_filtered:%d) %d %d %d\n", ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%4d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d subframes (adjustment:%d sf_offset_filtered:%d) %d %d %d NEW:%d CURR:%d adj:%d\n", + NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ind.header.phy_id, + phy->insync_minor_adjustment, phy->insync_minor_adjustment_duration, phy->adjustment, phy->sf_offset_filtered, +- insync_minor_adjustment_1, insync_minor_adjustment_2, phy->sf_offset_trend); ++ insync_minor_adjustment_1, insync_minor_adjustment_2, phy->sf_offset_trend, ++ NFAPI_SFNSF2DEC(new_sfn_sf), ++ NFAPI_SFNSF2DEC(curr_sfn_sf), ++ phy->adjustment); + + } + else if(phy->adjustment < 0) +@@ -1151,7 +1174,7 @@ void vnf_handle_ul_node_sync(void *pRecvMsg, int recvMsgLen, vnf_p7_t* vnf_p7) + // out of sync? + } + +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d suframes (adjusment:%d sf_offset_filtered:%d) %d %d %d\n", ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "(%d/%d) VNF phy_id:%d Apply minor insync adjustment %dus for %d subframes (adjustment:%d sf_offset_filtered:%d) %d %d %d\n", + NFAPI_SFNSF2SFN(phy->sfn_sf), NFAPI_SFNSF2SF(phy->sfn_sf), ind.header.phy_id, + phy->insync_minor_adjustment, phy->insync_minor_adjustment_duration, phy->adjustment, phy->sf_offset_filtered, + insync_minor_adjustment_1, insync_minor_adjustment_2, phy->sf_offset_trend); +diff --git a/vnf/src/vnf_p7_interface.c b/vnf/src/vnf_p7_interface.c +index ab4f00c..0f9c90d 100644 +--- a/vnf/src/vnf_p7_interface.c ++++ b/vnf/src/vnf_p7_interface.c +@@ -142,6 +142,7 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + NFAPI_TRACE(NFAPI_TRACE_INFO, "VNF P7 bind succeeded...\n"); + + ++ struct timespec original_pselect_timeout; + struct timespec pselect_timeout; + pselect_timeout.tv_sec = 0; + pselect_timeout.tv_nsec = 1000000; // ns in a 1 us +@@ -157,13 +158,13 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + + struct timespec sf_duration; + sf_duration.tv_sec = 0; +- sf_duration.tv_nsec = 1000000; // ns in a 1 us ++ sf_duration.tv_nsec = 1e6; // We want 1ms pause + + struct timespec sf_start; + clock_gettime(CLOCK_MONOTONIC, &sf_start); + long millisecond = sf_start.tv_nsec / 1e6; + sf_start = timespec_add(sf_start, sf_duration); +- //NFAPI_TRACE(NFAPI_TRACE_INFO, "next subframe will start at %d.%d\n", sf_start.tv_sec, sf_start.tv_nsec); ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "next subframe will start at %d.%d\n", sf_start.tv_sec, sf_start.tv_nsec); + + while(vnf_p7->terminate == 0) + { +@@ -181,6 +182,8 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + + if((last_millisecond == -1) || (millisecond == last_millisecond) || (millisecond == (last_millisecond + 1) % 1000) ) + { ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "pselect_start:%d.%d sf_start:%d.%d\n", pselect_start.tv_sec, pselect_start.tv_nsec, sf_start.tv_sec, sf_start.tv_nsec); ++ + + if((pselect_start.tv_sec > sf_start.tv_sec) || + ((pselect_start.tv_sec == sf_start.tv_sec) && (pselect_start.tv_nsec > sf_start.tv_nsec))) +@@ -196,8 +199,18 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + { + // still time before the end of the subframe wait + pselect_timeout = timespec_sub(sf_start, pselect_start); ++ ++#if 0 ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s() sf_start:%d.%ld pselect_start:%d.%ld pseclect_timeout:%d.%ld\n", ++ __FUNCTION__, ++ sf_start.tv_sec, sf_start.tv_nsec, ++ pselect_start.tv_sec, pselect_start.tv_nsec, ++ pselect_timeout.tv_sec, pselect_timeout.tv_nsec); ++#endif + } + ++original_pselect_timeout = pselect_timeout; ++ + // detemine how long to sleep in ns before the start of the next 1ms + //pselect_timeout.tv_nsec = 1e6 - (pselect_start.tv_nsec % 1000000); + +@@ -237,34 +250,91 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + */ + + ++//long wraps = pselect_timeout.tv_nsec % 1e9; ++ ++ + selectRetval = pselect(maxSock+1, &rfds, NULL, NULL, &pselect_timeout, NULL); + + clock_gettime(CLOCK_MONOTONIC, &pselect_stop); + ++ nfapi_vnf_p7_connection_info_t* phy = vnf_p7->p7_connections; ++ ++if (selectRetval==-1 && errno == 22) ++{ ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "INVAL: pselect_timeout:%d.%ld adj[dur:%d adj:%d], sf_dur:%d.%ld\n", ++ pselect_timeout.tv_sec, pselect_timeout.tv_nsec, ++ phy->insync_minor_adjustment_duration, phy->insync_minor_adjustment, ++ sf_duration.tv_sec, sf_duration.tv_nsec); ++} ++#if 0 ++ if (selectRetval != 0 || phy->insync_minor_adjustment_duration != 0) ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "pselect()=%d maxSock:%d vnf_p7->socket:%d pselect_timeout:%u.%u original_pselect_timeout:%u.%u\n", ++ selectRetval, maxSock, vnf_p7->socket, pselect_timeout.tv_sec, pselect_timeout.tv_nsec, ++ original_pselect_timeout.tv_sec, original_pselect_timeout.tv_nsec); ++#endif ++ + if(selectRetval == 0) + { +- // calcualte the start of the next subframe ++ // calculate the start of the next subframe + sf_start = timespec_add(sf_start, sf_duration); + //NFAPI_TRACE(NFAPI_TRACE_INFO, "next subframe will start at %d.%d\n", sf_start.tv_sec, sf_start.tv_nsec); + +- nfapi_vnf_p7_connection_info_t* phy = vnf_p7->p7_connections; + if(phy && phy->in_sync && phy->insync_minor_adjustment != 0 && phy->insync_minor_adjustment_duration > 0) + { +- NFAPI_TRACE(NFAPI_TRACE_NOTE, "[VNF] Subframe minor adjustment %dus\n", phy->insync_minor_adjustment); ++ long insync_minor_adjustment_ns = (phy->insync_minor_adjustment * 1000); ++ ++ sf_start.tv_nsec -= insync_minor_adjustment_ns; ++ ++#if 1 ++ if (sf_start.tv_nsec > 1e9) ++ { ++ sf_start.tv_sec++; ++ sf_start.tv_nsec-=1e9; ++ } ++ else if (sf_start.tv_nsec < 0) ++ { ++ sf_start.tv_sec--; ++ sf_start.tv_nsec+=1e9; ++ } ++#else ++ //NFAPI_TRACE(NFAPI_TRACE_NOTE, "[VNF] BEFORE adjustment - Subframe minor adjustment %dus sf_start.tv_nsec:%d\n", phy->insync_minor_adjustment, sf_start.tv_nsec); + if(phy->insync_minor_adjustment > 0) + { + // decrease the subframe duration a little +- sf_start.tv_nsec = sf_start.tv_nsec - (phy->insync_minor_adjustment * 1000); ++ if (sf_start.tv_nsec > insync_minor_adjustment_ns) ++ sf_start.tv_nsec -= insync_minor_adjustment_ns; ++ else ++ { ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "[VNF] Adjustment would make it negative sf:%d.%ld adjust:%ld\n\n\n", sf_start.tv_sec, sf_start.tv_nsec, insync_minor_adjustment_ns); ++ sf_start.tv_sec--; ++ sf_start.tv_nsec += 1e9 - insync_minor_adjustment_ns; ++ } + } + else if(phy->insync_minor_adjustment < 0) + { + // todo check we don't go below 0 + // increase the subframe duration a little +- sf_start.tv_nsec = sf_start.tv_nsec - (phy->insync_minor_adjustment * 1000); ++ sf_start.tv_nsec += insync_minor_adjustment_ns; ++ ++ if (sf_start.tv_nsec < 0) ++ { ++ NFAPI_TRACE(NFAPI_TRACE_ERROR, "[VNF] OVERFLOW %d.%ld\n\n\n\n", sf_start.tv_sec, sf_start.tv_nsec); ++ sf_start.tv_sec++; ++ sf_start.tv_nsec += 1e9; ++ } + } ++#endif + + //phy->insync_minor_adjustment = 0; +- phy->insync_minor_adjustment_duration--; ++ phy->insync_minor_adjustment_duration--; ++ ++ NFAPI_TRACE(NFAPI_TRACE_NOTE, "[VNF] AFTER adjustment - Subframe minor adjustment %dus sf_start.tv_nsec:%d duration:%u\n", ++ phy->insync_minor_adjustment, sf_start.tv_nsec, phy->insync_minor_adjustment_duration); ++ ++ if (phy->insync_minor_adjustment_duration==0) ++ { ++ phy->insync_minor_adjustment = 0; ++ } + } + /* + long pselect_stop_millisecond = pselect_stop.tv_nsec / 1e6; +@@ -298,7 +368,7 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + + if(selectRetval == 0) + { +- vnf_p7->sf_start_time_hr = get_current_time_hr(); ++ vnf_p7->sf_start_time_hr = vnf_get_current_time_hr(); + + // pselect timed out + nfapi_vnf_p7_connection_info_t* curr = vnf_p7->p7_connections; +@@ -326,14 +396,18 @@ int nfapi_vnf_p7_start(nfapi_vnf_p7_config_t* config) + else + { + // pselect error +- if(selectRetval == EINTR) ++ if(selectRetval == -1 && errno == EINTR) + { + // a sigal was received. + } + else + { +- NFAPI_TRACE(NFAPI_TRACE_INFO, "P7 select failed result %d errno %d timeout:%d.%d\n", selectRetval, errno, pselect_timeout.tv_sec, pselect_timeout.tv_nsec); ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "P7 select failed result %d errno %d timeout:%d.%d orginal:%d.%d last_ms:%ld ms:%ld\n", selectRetval, errno, pselect_timeout.tv_sec, pselect_timeout.tv_nsec, pselect_timeout.tv_sec, pselect_timeout.tv_nsec, last_millisecond, millisecond); + // should we exit now? ++ if (selectRetval == -1 && errno == 22) // invalid argument??? not sure about timeout duration ++ { ++ usleep(100000); ++ } + } + } + +@@ -360,10 +434,12 @@ int nfapi_vnf_p7_stop(nfapi_vnf_p7_config_t* config) + + int nfapi_vnf_p7_add_pnf(nfapi_vnf_p7_config_t* config, const char* pnf_p7_addr, int pnf_p7_port, int phy_id) + { +- NFAPI_TRACE(NFAPI_TRACE_INFO, "%s(phy_id:%d pnf_addr:%s:%d)\n", __FUNCTION__, phy_id, pnf_p7_addr, pnf_p7_port); ++ NFAPI_TRACE(NFAPI_TRACE_INFO, "%s(config:%p phy_id:%d pnf_addr:%s pnf_p7_port:%d)\n", __FUNCTION__, config, phy_id, pnf_p7_addr, pnf_p7_port); + + if(config == 0) +- return -1; ++ { ++ return -1; ++ } + + vnf_p7_t* vnf_p7 = (vnf_p7_t*)config; + +@@ -411,6 +487,8 @@ int nfapi_vnf_p7_del_pnf(nfapi_vnf_p7_config_t* config, int phy_id) + } + int nfapi_vnf_p7_dl_config_req(nfapi_vnf_p7_config_t* config, nfapi_dl_config_request_t* req) + { ++ //NFAPI_TRACE(NFAPI_TRACE_INFO, "%s(config:%p req:%p)\n", __FUNCTION__, config, req); ++ + if(config == 0 || req == 0) + return -1; + +diff --git a/xml/pnf_phy_1_A.xml b/xml/pnf_phy_1_A.xml +index da6cc26..02a6b14 100644 +--- a/xml/pnf_phy_1_A.xml ++++ b/xml/pnf_phy_1_A.xml +@@ -26,7 +26,7 @@ + <phy> + <index>88</index> + <port>2500</port> +- <address>127.0.0.1</address> ++ <address>192.168.1.74</address> + + <duplex_mode>1</duplex_mode> + +@@ -54,9 +54,9 @@ --typedef struct { -+typedef struct { - nfapi_tl_t tl; - uint8_t harq_size; - uint8_t ack_nack_mode; + <data> + <udp> +- <rx_port>7722</rx_port> +- <tx_addr>127.0.0.1</tx_addr> +- <tx_port>7733</tx_port> ++ <rx_port>5201</rx_port> ++ <tx_addr>192.168.1.78</tx_addr> ++ <tx_port>5200</tx_port> + </udp> + </data> + </phy> +diff --git a/xml/vnf_A.xml b/xml/vnf_A.xml +index e609c93..ec14b7b 100644 +--- a/xml/vnf_A.xml ++++ b/xml/vnf_A.xml +@@ -2,8 +2,8 @@ + <vnf> + <vnf_p7_list> + <vnf_p7> +- <port>5200</port> +- <address>127.0.0.1</address> ++ <port>5201</port> ++ <address>192.168.1.78</address> + <timing_window>10</timing_window> + <periodic_timing_enabled>0</periodic_timing_enabled> + <periodic_timing_window>0</periodic_timing_window> +@@ -12,7 +12,7 @@ + <data> + <udp> + <rx_port>8891</rx_port> +- <tx_addr>127.0.0.1</tx_addr> ++ <tx_addr>192.168.1.78</tx_addr> + <tx_port>8892</tx_port> + </udp> + </data>