diff --git a/openair3/TEST/EPC_TEST/play_scenario.h b/openair3/TEST/EPC_TEST/play_scenario.h index 604d0000bccc26143c707b82e7581b527c53ebe0..a926ea55e49ff5450fcea867f21271491845f134 100644 --- a/openair3/TEST/EPC_TEST/play_scenario.h +++ b/openair3/TEST/EPC_TEST/play_scenario.h @@ -344,11 +344,11 @@ typedef struct et_scenario_s { hash_table_t *hash_mme2association_id; hash_table_t *hash_old_ue_mme_id2ue_mme_id; - struct timeval time_last_tx_packet; - struct timeval time_last_rx_packet; - et_packet_t *last_rx_packet; // last packet received with all previous scenario RX packet received. - et_packet_t *last_tx_packet; // last sent packet - et_packet_t *next_packet; // next packet to be handled in the scenario (RX or TX packet) + struct timeval time_last_tx_packet; // Time last sent packet + struct timeval time_last_rx_packet; // Time last packet received with all previous scenario RX packet received. + et_packet_t *last_rx_packet; // Last packet received with all previous scenario RX packet received. + et_packet_t *last_tx_packet; // Last sent packet + et_packet_t *next_packet; // Next packet to be handled in the scenario (RX or TX packet) } et_scenario_t; diff --git a/openair3/TEST/EPC_TEST/play_scenario_fsm.c b/openair3/TEST/EPC_TEST/play_scenario_fsm.c index 1db9df632eec6b87bd23b5a01db05e39fc1c417f..b76d2240f58757e1ce1de9dbcaddd137099a3fd1 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_fsm.c +++ b/openair3/TEST/EPC_TEST/play_scenario_fsm.c @@ -55,17 +55,19 @@ uint32_t g_constraints = ET_BIT_MASK_MATCH_SCTP_STREAM | ET_BIT_MASK_MA int timeval_subtract (struct timeval * const result, struct timeval * const a, struct timeval * const b) { struct timeval b2; + int nsec = 0; b2.tv_sec = b->tv_sec; b2.tv_usec = b->tv_usec; + /* Perform the carry for the later subtraction by updating y. */ if (a->tv_usec < b2.tv_usec) { - int nsec = (b2.tv_usec - a->tv_usec) / 1000000 + 1; + nsec = (b2.tv_usec - a->tv_usec) / 1000000 + 1; b2.tv_usec -= 1000000 * nsec; b2.tv_sec += nsec; } if (a->tv_usec - b2.tv_usec > 1000000) { - int nsec = (a->tv_usec - b2.tv_usec) / 1000000; + nsec = (a->tv_usec - b2.tv_usec) / 1000000; b2.tv_usec += 1000000 * nsec; b2.tv_sec -= nsec; } @@ -75,7 +77,8 @@ int timeval_subtract (struct timeval * const result, struct timeval * const a, s result->tv_sec = a->tv_sec - b2.tv_sec; result->tv_usec = a->tv_usec - b2.tv_usec; - /* Return 1 if result is negative. */ + LOG_D(ENB_APP, "timeval_subtract(%ld.%06d, %ld.%06d)=%ld.%06d\n", a->tv_sec, a->tv_usec, b->tv_sec, b->tv_usec, result->tv_sec, result->tv_usec); + return a->tv_sec < b2.tv_sec; } @@ -117,15 +120,22 @@ void et_scenario_schedule_tx_packet(et_packet_t * const packet) AssertFatal(gettimeofday(&now, NULL) == 0, "gettimeofday failed"); timeval_subtract(&offset_last_tx_packet,&now,&g_scenario->time_last_tx_packet); timeval_subtract(&offset_last_rx_packet,&now,&g_scenario->time_last_rx_packet); + LOG_D(ENB_APP, "offset_last_tx_packet=%ld.%06d\n", offset_last_tx_packet.tv_sec, offset_last_tx_packet.tv_usec); + LOG_D(ENB_APP, "offset_last_rx_packet=%ld.%06d\n", offset_last_rx_packet.tv_sec, offset_last_rx_packet.tv_usec); + last_packet_was_tx = timeval_subtract(&offset_tx_rx,&offset_last_tx_packet,&offset_last_rx_packet); if (last_packet_was_tx) { + LOG_D(ENB_APP, "last_packet_was_tx\n"); we_are_too_early = timeval_subtract(&offset,&offset_last_tx_packet,&packet->time_relative_to_last_sent_packet); + LOG_D(ENB_APP, "we_are_too_early=%d, offset=%ld.%06d\n", we_are_too_early, offset.tv_sec, offset.tv_usec); } else { + LOG_D(ENB_APP, "last_packet_was_rx\n"); we_are_too_early = timeval_subtract(&offset,&offset_last_rx_packet,&packet->time_relative_to_last_received_packet); + LOG_D(ENB_APP, "we_are_too_early=%d, offset=%ld.%06d\n", we_are_too_early, offset.tv_sec, offset.tv_usec); } if (we_are_too_early > 0) { // set timer - LOG_D(ENB_APP, "Send packet num %u original frame number %u in %ld.%d sec\n", + LOG_D(ENB_APP, "Send packet num %u original frame number %u in %ld.%06d sec\n", packet->packet_number, packet->original_frame_number, offset.tv_sec, offset.tv_usec); packet->status = ET_PACKET_STATUS_SCHEDULED_FOR_SENDING; @@ -138,6 +148,10 @@ void et_scenario_schedule_tx_packet(et_packet_t * const packet) LOG_D(ENB_APP, "Send packet num %u original frame number %u immediately\n", packet->packet_number, packet->original_frame_number); // send immediately AssertFatal(0 == gettimeofday(&packet->timestamp_packet, NULL), "gettimeofday() Failed"); + + g_scenario->time_last_tx_packet.tv_sec = packet->timestamp_packet.tv_sec; + g_scenario->time_last_tx_packet.tv_usec = packet->timestamp_packet.tv_usec; + et_s1ap_eNB_itti_send_sctp_data_req( packet->enb_instance, packet->sctp_hdr.u.data_hdr.assoc_id, @@ -266,6 +280,10 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_waiting_tx(et_event_t event) case ET_EVENT_TX_TIMED_PACKET: // send immediately AssertFatal(0 == gettimeofday(&event.u.tx_timed_packet->timestamp_packet, NULL), "gettimeofday() Failed"); + + g_scenario->time_last_tx_packet.tv_sec = event.u.tx_timed_packet->timestamp_packet.tv_sec; + g_scenario->time_last_tx_packet.tv_usec = event.u.tx_timed_packet->timestamp_packet.tv_usec; + et_s1ap_eNB_itti_send_sctp_data_req( event.u.tx_timed_packet->enb_instance, event.u.tx_timed_packet->sctp_hdr.u.data_hdr.assoc_id, @@ -325,8 +343,7 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_connecting_s1c(et_event_t even break; case ET_EVENT_S1C_CONNECTED: - // hack simulate we have been able to get the right timing values - AssertFatal(gettimeofday(&g_scenario->time_last_tx_packet, NULL) == 0, "gettimeofday failed"); + // hack simulate we have been able to get the right timing values for STCP connect AssertFatal(gettimeofday(&g_scenario->time_last_rx_packet, NULL) == 0, "gettimeofday failed"); while (NULL != g_scenario->next_packet) { @@ -452,6 +469,7 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_null(et_event_t event) // Try to register each eNB g_scenario->registered_enb = 0; g_fsm_state = ET_FSM_STATE_CONNECTING_S1C; + AssertFatal(gettimeofday(&g_scenario->time_last_tx_packet, NULL) == 0, "gettimeofday failed"); et_eNB_app_register (g_scenario->enb_properties); pthread_mutex_unlock(&g_fsm_lock); return g_fsm_state; diff --git a/openair3/TEST/EPC_TEST/play_scenario_parse.c b/openair3/TEST/EPC_TEST/play_scenario_parse.c index cb302f229a0c3d7d8a95d4caf6c3ec2d8bc07bff..496102449ac3eba5ccfac581996ef78a246ea420 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_parse.c +++ b/openair3/TEST/EPC_TEST/play_scenario_parse.c @@ -343,6 +343,7 @@ et_packet_t* et_parse_xml_packet(xmlDocPtr doc, xmlNodePtr node) { xml_char = xmlGetProp(node, (const xmlChar *)"action"); packet->action = et_action_str2et_action_t(xml_char); + packet->status = ET_PACKET_STATUS_NONE; xmlFree(xml_char); packet->packet_number = packet_number++; diff --git a/openair3/TEST/EPC_TEST/play_scenario_s1ap.c b/openair3/TEST/EPC_TEST/play_scenario_s1ap.c index 142ab069e93e1bdec8f59aed74f85659ba40a9cb..df26de97c2dd6de8fe640a5a505912736955eb39 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_s1ap.c +++ b/openair3/TEST/EPC_TEST/play_scenario_s1ap.c @@ -254,13 +254,18 @@ int et_scenario_set_packet_received(et_packet_t * const packet) int rc = 0; packet->status = ET_PACKET_STATUS_RECEIVED; - S1AP_DEBUG("Packet num %d received\n", packet->packet_number); + S1AP_DEBUG("Packet received: num %u | original frame number %u \n", packet->packet_number, packet->original_frame_number); + S1AP_DEBUG("Last Packet received: num %u | original frame number %u \n", g_scenario->last_rx_packet->packet_number, g_scenario->last_rx_packet->original_frame_number); p = g_scenario->last_rx_packet; while (NULL != p) { - if (p->action == ET_PACKET_ACTION_S1C_RECEIVE) { - if (p->status == ET_PACKET_STATUS_RECEIVED) { + if (ET_PACKET_ACTION_S1C_RECEIVE == p->action) { + if ((ET_PACKET_STATUS_RECEIVED == p->status) || (ET_PACKET_STATUS_NOT_TAKEN_IN_ACCOUNT == p->status)) { g_scenario->last_rx_packet = p; + g_scenario->time_last_rx_packet.tv_sec = p->timestamp_packet.tv_sec; + g_scenario->time_last_rx_packet.tv_usec = p->timestamp_packet.tv_usec; + S1AP_DEBUG("Set Last Packet received: num %u | original frame number %u \n", g_scenario->last_rx_packet->packet_number, g_scenario->last_rx_packet->original_frame_number); + S1AP_DEBUG("Set time_last_rx_packet %ld.%06d\n", g_scenario->time_last_rx_packet.tv_sec, g_scenario->time_last_rx_packet.tv_usec); } else { break; } @@ -268,7 +273,7 @@ int et_scenario_set_packet_received(et_packet_t * const packet) p = p->next; } - if (packet->timer_id != 0) { + if (0 != packet->timer_id) { rc = timer_remove(packet->timer_id); AssertFatal(rc == 0, "TODO: Debug Timer on Rx packet num %d unknown", packet->packet_number); return rc; @@ -291,9 +296,14 @@ int et_s1ap_process_rx_packet(et_event_s1ap_data_ind_t * const s1ap_data_ind) packet = g_scenario->list_packet; while (NULL != packet) { if (packet->action == ET_PACKET_ACTION_S1C_RECEIVE) { - if (packet->status == ET_PACKET_STATUS_RECEIVED) { + if ((ET_PACKET_STATUS_RECEIVED == packet->status) || (ET_PACKET_STATUS_NOT_TAKEN_IN_ACCOUNT == packet->status)) { g_scenario->last_rx_packet = packet; - g_scenario->time_last_rx_packet = g_scenario->last_rx_packet->timestamp_packet; + if (ET_PACKET_STATUS_NOT_TAKEN_IN_ACCOUNT != packet->status) { + g_scenario->time_last_rx_packet.tv_sec = packet->timestamp_packet.tv_sec; + g_scenario->time_last_rx_packet.tv_usec = packet->timestamp_packet.tv_usec; + } + S1AP_DEBUG("Set Last Packet received: num %u | original frame number %u \n", g_scenario->last_rx_packet->packet_number, g_scenario->last_rx_packet->original_frame_number); + S1AP_DEBUG("Set time_last_rx_packet %ld.%06d\n", g_scenario->time_last_rx_packet.tv_sec, g_scenario->time_last_rx_packet.tv_usec); } else { break; } @@ -309,10 +319,13 @@ int et_s1ap_process_rx_packet(et_event_s1ap_data_ind_t * const s1ap_data_ind) if (packet->action == ET_PACKET_ACTION_S1C_RECEIVE) { rv = et_sctp_is_matching(&packet->sctp_hdr, &rx_packet->sctp_hdr, g_constraints); if (0 == rv) { - S1AP_DEBUG("Compare RX packet with packet num %d succeeded\n", packet->packet_number); + S1AP_DEBUG("Compare RX packet with packet: num %u | original frame number %u \n", packet->packet_number, packet->original_frame_number); + packet->timestamp_packet.tv_sec = rx_packet->timestamp_packet.tv_sec; + packet->timestamp_packet.tv_usec = rx_packet->timestamp_packet.tv_usec; return et_scenario_set_packet_received(packet); } else { - S1AP_DEBUG("Compare RX packet with packet num %d failed %s\n", packet->packet_number, et_error_match2str(rv)); + S1AP_DEBUG("Compare RX packet with packet: num %u | original frame number %u failed:%s\n", + packet->packet_number, packet->original_frame_number, et_error_match2str(rv)); // asn1 compare no match return code, may not collide with non asn1 error return codes // (each asn1 rc <= 166 (enum e_S1ap_ProtocolIE_ID, in generated file S1ap_ProtocolIE_ID.h)) if ((rv > 0) || (rv <= -ET_ERROR_MATCH_END)) {