diff --git a/nfapi/public_inc/nfapi_interface.h b/nfapi/public_inc/nfapi_interface.h index 2d58c2a..f665d11 100644 --- a/nfapi/public_inc/nfapi_interface.h +++ b/nfapi/public_inc/nfapi_interface.h @@ -1772,7 +1772,7 @@ typedef struct { uint8_t number_of_cc; struct { uint8_t ri_size; - uint8_t dl_cqi_pmi_size; + uint8_t dl_cqi_pmi_size[8]; } cc[NFAPI_MAX_CC]; } nfapi_ul_config_aperiodic_cqi_pmi_ri_report_t; 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..b25caf2 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 @@ -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..263f93c 100644 --- a/pnf/src/pnf_p7.c +++ b/pnf/src/pnf_p7.c @@ -25,12 +25,13 @@ #include <unistd.h> #include <errno.h> #include <pthread.h> +#include <stdio.h> #include "pnf_p7.h" #define FAPI2_IP_DSCP 0 -uint32_t get_current_time_hr() +uint32_t pnf_get_current_time_hr(void) { struct timeval now; (void)gettimeofday(&now, NULL); @@ -64,11 +65,14 @@ void pnf_p7_free(pnf_p7_t* pnf_p7, void* ptr) // todo : for now these just malloc/free need to move to a memory cache nfapi_dl_config_request_t* allocate_nfapi_dl_config_request(pnf_p7_t* pnf_p7) { - return pnf_p7_malloc(pnf_p7, sizeof(nfapi_dl_config_request_t)); + void *ptr= pnf_p7_malloc(pnf_p7, sizeof(nfapi_dl_config_request_t)); + //printf("%s() ptr:%p\n", __FUNCTION__, ptr); + return ptr; } void deallocate_nfapi_dl_config_request(nfapi_dl_config_request_t* req, pnf_p7_t* pnf_p7) { + //printf("%s() SFN/SF:%d %s req:%p pdu_list:%p\n", __FUNCTION__, NFAPI_SFNSF2DEC(req->sfn_sf), pnf_p7->_public.codec_config.deallocate ? "DEALLOCATE" : "FREE", req, req->dl_config_request_body.dl_config_pdu_list); if(pnf_p7->_public.codec_config.deallocate) { (pnf_p7->_public.codec_config.deallocate)(req->dl_config_request_body.dl_config_pdu_list); @@ -83,11 +87,14 @@ void deallocate_nfapi_dl_config_request(nfapi_dl_config_request_t* req, pnf_p7_t nfapi_ul_config_request_t* allocate_nfapi_ul_config_request(pnf_p7_t* pnf_p7) { - return pnf_p7_malloc(pnf_p7, sizeof(nfapi_ul_config_request_t)); + void *ptr= pnf_p7_malloc(pnf_p7, sizeof(nfapi_ul_config_request_t)); + //printf("%s() ptr:%p\n", __FUNCTION__, ptr); + return ptr; } void deallocate_nfapi_ul_config_request(nfapi_ul_config_request_t* req, pnf_p7_t* pnf_p7) { + //printf("%s() SFN/SF:%d %s req:%p pdu_list:%p\n", __FUNCTION__, NFAPI_SFNSF2DEC(req->sfn_sf), pnf_p7->_public.codec_config.deallocate ? "DEALLOCATE" : "FREE", req, req->ul_config_request_body.ul_config_pdu_list); if(pnf_p7->_public.codec_config.deallocate) { (pnf_p7->_public.codec_config.deallocate)(req->ul_config_request_body.ul_config_pdu_list); @@ -107,6 +114,7 @@ nfapi_hi_dci0_request_t* allocate_nfapi_hi_dci0_request(pnf_p7_t* pnf_p7) void deallocate_nfapi_hi_dci0_request(nfapi_hi_dci0_request_t* req, pnf_p7_t* pnf_p7) { + //printf("%s() SFN/SF:%d %s req:%p pdu_list:%p\n", __FUNCTION__, NFAPI_SFNSF2DEC(req->sfn_sf), pnf_p7->_public.codec_config.deallocate ? "DEALLOCATE" : "FREE", req, req->hi_dci0_request_body.hi_dci0_pdu_list); if(pnf_p7->_public.codec_config.deallocate) { (pnf_p7->_public.codec_config.deallocate)(req->hi_dci0_request_body.hi_dci0_pdu_list); @@ -127,6 +135,9 @@ nfapi_tx_request_t* allocate_nfapi_tx_request(pnf_p7_t* pnf_p7) void deallocate_nfapi_tx_request(nfapi_tx_request_t* req, pnf_p7_t* pnf_p7) { int i = 0; + + //printf("%s() SFN/SF:%d %s req:%p pdu[0]:data:%p\n", __FUNCTION__, NFAPI_SFNSF2DEC(req->sfn_sf), pnf_p7->_public.codec_config.deallocate ? "DEALLOCATE" : "FREE", req, req->tx_request_body.tx_pdu_list[i].segments[0].segment_data); + for(i = 0; i < req->tx_request_body.number_of_pdus; ++i) { void* data = req->tx_request_body.tx_pdu_list[i].segments[0].segment_data; @@ -307,11 +318,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 +493,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 +545,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 +576,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 +624,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 +641,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 +653,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 +671,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 +717,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 +756,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 +768,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 +783,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 +817,32 @@ 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; + + //printf("%s() POPULATE DL_CONFIG_REQ sfn_sf:%d buffer_index:%d\n", __FUNCTION__, sfn_sf_dec, buffer_index); // 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 +1043,13 @@ 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; +//printf("%s() POPULATE TX_REQ sfn_sf:%d buffer_index:%d\n", __FUNCTION__, sfn_sf_dec, buffer_index); + + 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 +1182,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 +1462,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 +1490,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 +1588,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..0aba0a2 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++; @@ -663,7 +664,7 @@ int nfapi_vnf_allocate_phy(nfapi_vnf_config_t* config, int p5_idx, uint16_t* phy info->p5_idx = p5_idx; info->phy_id = vnf->next_phy_id++; - info->timing_window = 10; + info->timing_window = 30; // This seems to override what gets set by the user - why??? info->timing_info_mode = 0x03; info->timing_info_period = 128; 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 @@ <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>