diff --git a/openair3/TEST/EPC_TEST/play_scenario.c b/openair3/TEST/EPC_TEST/play_scenario.c index d85faf4c2cec17fcfa24d16f17acd562b7aa37ec..e7cb8ef84801e711906587e2c402af9530f94dd4 100644 --- a/openair3/TEST/EPC_TEST/play_scenario.c +++ b/openair3/TEST/EPC_TEST/play_scenario.c @@ -830,13 +830,13 @@ int et_play_scenario(et_scenario_t* const scenario, const struct shift_packet_s while (shift) { packet = scenario->list_packet; while (packet) { - fprintf(stdout, "*shift: %p\n", shift); - fprintf(stdout, "\tframe_number: %p\n", shift->frame_number); - fprintf(stdout, "\tshift_seconds: %ld\n", shift->shift_seconds); - fprintf(stdout, "\tshift_microseconds: %ld\n", shift->shift_microseconds); - fprintf(stdout, "\tsingle: %d\n\n", shift->single); - fprintf(stdout, "\tshift_all_packets_seconds: %ld\n", shift_all_packets.tv_sec); - fprintf(stdout, "\tshift_all_packets_microseconds: %ld\n", shift_all_packets.tv_usec); +// fprintf(stdout, "*shift: %p\n", shift); +// fprintf(stdout, "\tframe_number: %p\n", shift->frame_number); +// fprintf(stdout, "\tshift_seconds: %ld\n", shift->shift_seconds); +// fprintf(stdout, "\tshift_microseconds: %ld\n", shift->shift_microseconds); +// fprintf(stdout, "\tsingle: %d\n\n", shift->single); +// fprintf(stdout, "\tshift_all_packets_seconds: %ld\n", shift_all_packets.tv_sec); +// fprintf(stdout, "\tshift_all_packets_microseconds: %ld\n", shift_all_packets.tv_usec); AssertFatal((packet->time_relative_to_first_packet.tv_sec >= 0) && (packet->time_relative_to_first_packet.tv_usec >= 0), "Bad timing result time_relative_to_first_packet=%d.%d packet num %u, original frame number %u", @@ -856,21 +856,21 @@ int et_play_scenario(et_scenario_t* const scenario, const struct shift_packet_s packet->time_relative_to_last_sent_packet.tv_usec, packet->packet_number, packet->original_frame_number); - fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_first_packet=%d.%d\n", - packet->packet_number, - packet->original_frame_number, - packet->time_relative_to_first_packet.tv_sec, - packet->time_relative_to_first_packet.tv_usec); - fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_last_received_packet=%d.%d\n", - packet->packet_number, - packet->original_frame_number, - packet->time_relative_to_last_received_packet.tv_sec, - packet->time_relative_to_last_received_packet.tv_usec); - fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_last_sent_packet=%d.%d\n", - packet->packet_number, - packet->original_frame_number, - packet->time_relative_to_last_sent_packet.tv_sec, - packet->time_relative_to_last_sent_packet.tv_usec); +// fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_first_packet=%d.%d\n", +// packet->packet_number, +// packet->original_frame_number, +// packet->time_relative_to_first_packet.tv_sec, +// packet->time_relative_to_first_packet.tv_usec); +// fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_last_received_packet=%d.%d\n", +// packet->packet_number, +// packet->original_frame_number, +// packet->time_relative_to_last_received_packet.tv_sec, +// packet->time_relative_to_last_received_packet.tv_usec); +// fprintf(stdout, "\tpacket num %u, original frame number %u time_relative_to_last_sent_packet=%d.%d\n", +// packet->packet_number, +// packet->original_frame_number, +// packet->time_relative_to_last_sent_packet.tv_sec, +// packet->time_relative_to_last_sent_packet.tv_usec); if ((shift->single) && (shift->frame_number == packet->original_frame_number)) { struct timeval t_offset = { .tv_sec = shift->shift_seconds, .tv_usec = shift->shift_microseconds }; @@ -891,11 +891,11 @@ int et_play_scenario(et_scenario_t* const scenario, const struct shift_packet_s shift_all_packets.tv_sec = shift->shift_seconds; shift_all_packets.tv_usec = shift->shift_microseconds; timeval_add(&packet->time_relative_to_first_packet, &packet->time_relative_to_first_packet, &shift_all_packets); - fprintf(stdout, "\tpacket num %u, now original frame number %u time_relative_to_first_packet=%d.%d\n", - packet->packet_number, - packet->original_frame_number, - packet->time_relative_to_first_packet.tv_sec, - packet->time_relative_to_first_packet.tv_usec); +// fprintf(stdout, "\tpacket num %u, now original frame number %u time_relative_to_first_packet=%d.%d\n", +// packet->packet_number, +// packet->original_frame_number, +// packet->time_relative_to_first_packet.tv_sec, +// packet->time_relative_to_first_packet.tv_usec); AssertFatal((packet->time_relative_to_first_packet.tv_sec >= 0) && (packet->time_relative_to_first_packet.tv_usec >= 0), "Bad timing result time_relative_to_first_packet=%d.%d packet num %u, original frame number %u", packet->time_relative_to_first_packet.tv_sec, @@ -904,11 +904,11 @@ int et_play_scenario(et_scenario_t* const scenario, const struct shift_packet_s packet->original_frame_number); } else if ((0 == shift->single) && (shift->frame_number < packet->original_frame_number)) { timeval_add(&packet->time_relative_to_first_packet, &packet->time_relative_to_first_packet, &shift_all_packets); - fprintf(stdout, "\tpacket num %u, now original frame number %u time_relative_to_first_packet=%d.%d\n", - packet->packet_number, - packet->original_frame_number, - packet->time_relative_to_first_packet.tv_sec, - packet->time_relative_to_first_packet.tv_usec); +// fprintf(stdout, "\tpacket num %u, now original frame number %u time_relative_to_first_packet=%d.%d\n", +// packet->packet_number, +// packet->original_frame_number, +// packet->time_relative_to_first_packet.tv_sec, +// packet->time_relative_to_first_packet.tv_usec); AssertFatal((packet->time_relative_to_first_packet.tv_sec >= 0) && (packet->time_relative_to_first_packet.tv_usec >= 0), "Bad timing result time_relative_to_first_packet=%d.%d packet num %u, original frame number %u", packet->time_relative_to_first_packet.tv_sec, diff --git a/openair3/TEST/EPC_TEST/play_scenario.h b/openair3/TEST/EPC_TEST/play_scenario.h index ca569e514180318ae7f4305b78ed12c3e46c46a0..c1458047bd499bdc80f99661cc5c0278ced07e01 100644 --- a/openair3/TEST/EPC_TEST/play_scenario.h +++ b/openair3/TEST/EPC_TEST/play_scenario.h @@ -90,10 +90,10 @@ typedef struct shift_packet_s { - unsigned int frame_number; + unsigned int frame_number; // original frame number int shift_seconds; int shift_microseconds; - int single; // only this packet + int single; // shift timing only for this packet (not also following packets) struct shift_packet_s *next; } shift_packet_t; @@ -261,6 +261,7 @@ typedef enum { typedef struct et_s1ap_s { //et_s1ap_pdu_type_t pdu_type; S1AP_PDU_t pdu; // decoded ASN1 C type: choice of initiatingMessage, successfulOutcome, unsuccessfulOutcome + uint16_t xml_stream_pos_offset; uint16_t binary_stream_pos; uint16_t binary_stream_allocated_size; uint8_t *binary_stream; @@ -366,6 +367,8 @@ typedef struct et_scenario_s { 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) + + int timer_count; } et_scenario_t; @@ -457,7 +460,7 @@ int et_generate_xml_scenario( void timeval_add (struct timeval * const result, const struct timeval * const a, const struct timeval * const b); int timeval_subtract (struct timeval * const result, struct timeval * const a, struct timeval * const b); void et_scenario_wait_rx_packet(et_packet_t * const packet); -void et_scenario_schedule_tx_packet(et_packet_t * const packet); +void et_scenario_schedule_tx_packet(et_packet_t * packet); et_fsm_state_t et_scenario_fsm_notify_event_state_running(et_event_t event); et_fsm_state_t et_scenario_fsm_notify_event_state_waiting_tx(et_event_t event); et_fsm_state_t et_scenario_fsm_notify_event_state_waiting_rx(et_event_t event); diff --git a/openair3/TEST/EPC_TEST/play_scenario_fsm.c b/openair3/TEST/EPC_TEST/play_scenario_fsm.c index dece907deee706a52055c0feac304a9ef33abfcb..5dee83afc9339e4d43cdbc44788e8bff7677cd86 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_fsm.c +++ b/openair3/TEST/EPC_TEST/play_scenario_fsm.c @@ -70,6 +70,7 @@ void timeval_add (struct timeval * const result, const struct timeval * const a, //------------------------------------------------------------------------------ // it is assumed that if a time is negative tv_sec and tv_usec are both negative +// return true if result is positive int timeval_subtract (struct timeval * const result, struct timeval * const a, struct timeval * const b) { AssertFatal(((a->tv_sec <= 0) && (a->tv_usec <= 0)) || ((a->tv_sec >= 0) && (a->tv_usec >= 0)), " Bad time format arg a\n"); @@ -81,7 +82,7 @@ int timeval_subtract (struct timeval * const result, struct timeval * const a, s if ((result != a) && (result != b)) { 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 result->tv_sec < 0; + return (result->tv_sec >= 0) && (result->tv_usec >= 0); } //------------------------------------------------------------------------------ @@ -93,10 +94,11 @@ void et_scenario_wait_rx_packet(et_packet_t * const packet) packet, &packet->timer_id) < 0) { AssertFatal(0, " Can not start waiting RX event timer\n"); } - LOG_D(ENB_APP, "Waiting RX packet num %d\n", packet->packet_number); + g_scenario->timer_count++; + LOG_D(ENB_APP, "Waiting RX packet num %d original frame number %u\n", packet->packet_number, packet->original_frame_number); } //------------------------------------------------------------------------------ -void et_scenario_schedule_tx_packet(et_packet_t * const packet) +void et_scenario_schedule_tx_packet(et_packet_t * packet) { s1ap_eNB_instance_t *s1ap_eNB_instance = NULL; struct timeval now = { .tv_sec = 0, .tv_usec = 0 }; @@ -104,8 +106,9 @@ void et_scenario_schedule_tx_packet(et_packet_t * const packet) struct timeval offset_last_rx_packet = { .tv_sec = 0, .tv_usec = 0 }; struct timeval offset_tx_rx = { .tv_sec = 0, .tv_usec = 0 }; struct timeval offset = { .tv_sec = 0, .tv_usec = 0 }; - int last_packet_was_tx = 0; - int we_are_too_early = 0; + int last_packet_was_rx = 0; + int we_are_too_late = 0; + int original_frame_number = -1; AssertFatal(NULL != packet, "packet argument is NULL"); s1ap_eNB_instance = et_s1ap_eNB_get_instance(packet->enb_instance); @@ -124,19 +127,19 @@ void et_scenario_schedule_tx_packet(et_packet_t * const 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 { + last_packet_was_rx = timeval_subtract(&offset_tx_rx,&offset_last_tx_packet,&offset_last_rx_packet); + if (last_packet_was_rx) { 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); + we_are_too_late = timeval_subtract(&offset,&offset_last_rx_packet,&packet->time_relative_to_last_received_packet); + LOG_D(ENB_APP, "we_are_too_late=%d, offset=%ld.%06d\n", we_are_too_late, offset.tv_sec, offset.tv_usec); + } else { + LOG_D(ENB_APP, "last_packet_was_tx\n"); + we_are_too_late = 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_late, offset.tv_sec, offset.tv_usec); } - if ((0 < we_are_too_early) && (0 == g_max_speed)){ + if ((0 == we_are_too_late) && (0 == g_max_speed)){ // set timer - if (offset.tv_sec < 0) { + if ((offset.tv_sec <= 0) || (offset.tv_usec <= 0)){ offset.tv_sec = -offset.tv_sec; offset.tv_usec = -offset.tv_usec; } @@ -148,23 +151,27 @@ void et_scenario_schedule_tx_packet(et_packet_t * const packet) if (timer_setup (offset.tv_sec, offset.tv_usec, TASK_S1AP, INSTANCE_DEFAULT, TIMER_ONE_SHOT,packet, &packet->timer_id) < 0) { AssertFatal(0, " Can not start TX event timer\n"); } + g_scenario->timer_count++; // Done g_fsm_state = ET_FSM_STATE_WAITING_TX_EVENT; } else { - 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"); + original_frame_number = packet->original_frame_number; + do { + 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; - 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( + LOG_D(ENB_APP, "Sending packet num %d original frame number %u immediately\n",packet->packet_number, packet->original_frame_number); + et_s1ap_eNB_itti_send_sctp_data_req( packet->enb_instance, packet->sctp_hdr.u.data_hdr.assoc_id, packet->sctp_hdr.u.data_hdr.payload.binary_stream, packet->sctp_hdr.u.data_hdr.payload.binary_stream_allocated_size, packet->sctp_hdr.u.data_hdr.stream); - packet->status = ET_PACKET_STATUS_SENT; - g_scenario->next_packet = g_scenario->next_packet->next; + packet->status = ET_PACKET_STATUS_SENT; + g_scenario->next_packet = g_scenario->next_packet->next; + packet = packet->next; + } while ((NULL != packet) && (packet->original_frame_number == original_frame_number)); g_fsm_state = ET_FSM_STATE_RUNNING; } break; @@ -183,7 +190,7 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_running(et_event_t event) switch (event.code){ case ET_EVENT_TICK: while (NULL != g_scenario->next_packet) { - LOG_D(ENB_APP, "EVENT_TICK: Considering packet num %d:\n", g_scenario->next_packet->packet_number); + LOG_D(ENB_APP, "EVENT_TICK: Considering packet num %d original frame number %u\n", g_scenario->next_packet->packet_number, g_scenario->next_packet->original_frame_number); switch (g_scenario->next_packet->sctp_hdr.chunk_type) { case SCTP_CID_DATA : // no init in this scenario, may be sub-scenario @@ -251,6 +258,13 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_running(et_event_t event) fprintf(stderr, "No Packet found in this scenario: %s\n", g_scenario->name); g_fsm_state = ET_FSM_STATE_NULL; pthread_mutex_unlock(&g_fsm_lock); + if (0 == g_scenario->timer_count) { + fprintf(stderr, "End of scenario: %s\n", g_scenario->name); + fflush(stderr); + fflush(stdout); + exit(0); + } + fprintf(stderr, "Remaining timers running: %d\n", g_scenario->timer_count); return g_fsm_state; break; case ET_EVENT_RX_PACKET_TIME_OUT: @@ -272,7 +286,10 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_running(et_event_t event) //------------------------------------------------------------------------------ et_fsm_state_t et_scenario_fsm_notify_event_state_waiting_tx(et_event_t event) { - int rv = 0; + int rv = 0; + int original_frame_number = -1; + et_packet_t *packet = NULL; + switch (event.code){ case ET_EVENT_TICK: fprintf(stdout, "EVENT_TICK: waiting for tx event\n"); @@ -284,19 +301,25 @@ 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, - event.u.tx_timed_packet->sctp_hdr.u.data_hdr.payload.binary_stream, - event.u.tx_timed_packet->sctp_hdr.u.data_hdr.payload.binary_stream_allocated_size, - event.u.tx_timed_packet->sctp_hdr.u.data_hdr.stream); - event.u.tx_timed_packet->status = ET_PACKET_STATUS_SENT; - g_scenario->next_packet = event.u.tx_timed_packet->next; + packet = event.u.tx_timed_packet; + AssertFatal(0 == gettimeofday(&packet->timestamp_packet, NULL), "gettimeofday() Failed"); + + original_frame_number = packet->original_frame_number; + do { + 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; + + LOG_D(ENB_APP, "Sending packet num %d original frame number %u immediately\n",packet->packet_number, packet->original_frame_number); + et_s1ap_eNB_itti_send_sctp_data_req( + packet->enb_instance, + packet->sctp_hdr.u.data_hdr.assoc_id, + packet->sctp_hdr.u.data_hdr.payload.binary_stream, + packet->sctp_hdr.u.data_hdr.payload.binary_stream_allocated_size, + packet->sctp_hdr.u.data_hdr.stream); + packet->status = ET_PACKET_STATUS_SENT; + packet = packet->next; + g_scenario->next_packet = packet; + } while ( (NULL != packet) && (packet->original_frame_number == original_frame_number)); g_fsm_state = ET_FSM_STATE_RUNNING; break; @@ -411,6 +434,13 @@ et_fsm_state_t et_scenario_fsm_notify_event_state_connecting_s1c(et_event_t even fprintf(stderr, "No Packet found in this scenario: %s\n", g_scenario->name); g_fsm_state = ET_FSM_STATE_NULL; pthread_mutex_unlock(&g_fsm_lock); + if (0 == g_scenario->timer_count) { + fprintf(stderr, "End of scenario: %s\n", g_scenario->name); + fflush(stderr); + fflush(stdout); + exit(0); + } + fprintf(stderr, "Remaining timers running: %d\n", g_scenario->timer_count); return g_fsm_state; break; diff --git a/openair3/TEST/EPC_TEST/play_scenario_parse.c b/openair3/TEST/EPC_TEST/play_scenario_parse.c index 11dac34f0a451f48c71e11638945c10d282e3d36..aedc021f73028fb0e5b33bf2c56a177e0b2664f5 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_parse.c +++ b/openair3/TEST/EPC_TEST/play_scenario_parse.c @@ -71,10 +71,15 @@ void et_parse_s1ap(xmlDocPtr doc, const xmlNode const *s1ap_node, et_s1ap_t * co if ((NULL != s1ap_node) && (NULL != s1ap)) { // see http://www.xmlsoft.org/html/libxml-tree.html#xmlCopyNode - cur_node = xmlCopyNode(s1ap_node, 1); - AssertFatal(NULL != cur_node, "xmlCopyNode Failed"); - s1ap->doc = xmlNewDoc(BAD_CAST "1.0"); - xmlDocSetRootElement(s1ap->doc, cur_node); + if (NULL == s1ap->doc) { + xmlUnlinkNode(s1ap_node); + //cur_node = xmlCopyNodeList(s1ap_node); + // arg2: if 1 do a recursive copy (properties, namespaces and children when applicable) if 2 copy properties and namespaces (when applicable) + //cur_node = xmlCopyNode(s1ap_node, 1); + //AssertFatal(NULL != cur_node, "xmlCopyNode Failed"); + s1ap->doc = xmlNewDoc(BAD_CAST "1.0"); + xmlDocSetRootElement(s1ap->doc, s1ap_node); + } for (cur_node = (xmlNode *)s1ap_node; cur_node; cur_node = cur_node->next) { go_deeper_in_tree = 1; @@ -97,17 +102,17 @@ void et_parse_s1ap(xmlDocPtr doc, const xmlNode const *s1ap_node, et_s1ap_t * co xml_char = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"value"); if (NULL != xml_char) { xml_char2 = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"name"); - fprintf(stdout, "s1ap %p field %s size %d value %s\n",s1ap, xml_char2, size, xml_char); + fprintf(stdout, "s1ap %p field name %s size %d value %s\n",s1ap, xml_char2, size, xml_char); xmlFree(xml_char2); // if success to get value, do not parse children //AssertFatal ((xmlStrlen(xml_char) == size), "ERROR %s() mismatch in size %d and strlen %d\n", __FUNCTION__, size, xmlStrlen(xml_char)); //if (xmlStrlen(xml_char) == size) { AssertFatal ((s1ap->binary_stream_pos+xmlStrlen(xml_char)/2) <= s1ap->binary_stream_allocated_size, - "ERROR %s() in buffer size: binary_stream_pos %d xmlStrlen(xml_char)/2=%d\n", __FUNCTION__, s1ap->binary_stream_pos, xmlStrlen(xml_char)/2); + "ERROR in buffer size: binary_stream_pos %d xmlStrlen(xml_char)/2=%d\n", s1ap->binary_stream_pos, xmlStrlen(xml_char)/2); rc = et_hex2data( &s1ap->binary_stream[s1ap->binary_stream_pos], xml_char, xmlStrlen(xml_char)); s1ap->binary_stream_pos += xmlStrlen(xml_char)/2; - et_display_node(cur_node, 0); - AssertFatal (rc >= 0, "ERROR %s() in converting hex string %s len %d size %d rc %d\n", __FUNCTION__, xml_char, xmlStrlen(xml_char), size, rc); + //et_display_node(cur_node, 0); + AssertFatal (rc >= 0, "ERROR in converting hex string %s len %d size %d rc %d\n", xml_char, xmlStrlen(xml_char), size, rc); go_deeper_in_tree = 0; //} xmlFree(xml_char); @@ -274,15 +279,23 @@ void et_parse_sctp(xmlDocPtr doc, const xmlNode const *sctp_node, et_sctp_hdr_t if (NULL != xml_char) { if ((!xmlStrcmp(xml_char, (const xmlChar *)"s1ap"))) { xmlFree(xml_char); - xml_char2 = xmlGetProp((xmlNode *)sctp_node, (const xmlChar *)"size"); - if (NULL != xml_char2) { - sctp_hdr->u.data_hdr.payload.binary_stream_allocated_size = strtoul((const char *)xml_char2, NULL, 0); - sctp_hdr->u.data_hdr.payload.binary_stream = calloc(1, sctp_hdr->u.data_hdr.payload.binary_stream_allocated_size); - xmlFree(xml_char2); + xml_char = xmlGetProp((xmlNode *)sctp_node, (const xmlChar *)"pos"); + if (NULL != xml_char) { + sctp_hdr->u.data_hdr.payload.xml_stream_pos_offset = strtoul((const char *)xml_char, NULL, 0); + xmlFree(xml_char); + + xml_char2 = xmlGetProp((xmlNode *)sctp_node, (const xmlChar *)"size"); + if (NULL != xml_char2) { + sctp_hdr->u.data_hdr.payload.binary_stream_allocated_size = strtoul((const char *)xml_char2, NULL, 0); + sctp_hdr->u.data_hdr.payload.binary_stream = calloc(1, sctp_hdr->u.data_hdr.payload.binary_stream_allocated_size); + sctp_hdr->u.data_hdr.payload.binary_stream_pos = 0; + fprintf(stdout, "Allocating payload of sctp_hdr %p %u bytes\n", sctp_hdr, sctp_hdr->u.data_hdr.payload.binary_stream_allocated_size); + xmlFree(xml_char2); + } + et_parse_s1ap(doc, sctp_node, &sctp_hdr->u.data_hdr.payload); + et_decode_s1ap(&sctp_hdr->u.data_hdr.payload); + return; } - et_parse_s1ap(doc, sctp_node, &sctp_hdr->u.data_hdr.payload); - et_decode_s1ap(&sctp_hdr->u.data_hdr.payload); - return; } xmlFree(xml_char); } @@ -388,6 +401,7 @@ et_packet_t* et_parse_xml_packet(xmlDocPtr doc, xmlNodePtr node) xml_char = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"value"); afloat = atof((const char*)xml_char); xmlFree(xml_char); + fprintf(stdout, "Parsing packet frame.time_relative: %f\n", afloat); packet->time_relative_to_first_packet.tv_sec = (int)afloat; packet->time_relative_to_first_packet.tv_usec = (int)((afloat - packet->time_relative_to_first_packet.tv_sec)*1000000.0); @@ -400,48 +414,10 @@ et_packet_t* et_parse_xml_packet(xmlDocPtr doc, xmlNodePtr node) timersub(&packet->time_relative_to_first_packet, &initial_time, &packet->time_relative_to_first_packet); } - if (packet->action == ET_PACKET_ACTION_S1C_SEND) { - if (first_sent_packet > 0) { - relative_last_sent_packet = packet->time_relative_to_first_packet; - packet->time_relative_to_last_sent_packet.tv_sec = 0; - packet->time_relative_to_last_sent_packet.tv_usec = 0; - first_sent_packet = 0; - } else { - timersub(&packet->time_relative_to_first_packet, &relative_last_sent_packet, - &packet->time_relative_to_last_sent_packet); - relative_last_sent_packet = packet->time_relative_to_first_packet; - } - if (first_received_packet > 0) { - packet->time_relative_to_last_received_packet.tv_sec = 0; - packet->time_relative_to_last_received_packet.tv_usec = 0; - } else { - timersub(&packet->time_relative_to_first_packet, &relative_last_received_packet, - &packet->time_relative_to_last_received_packet); - } - } else if (packet->action == ET_PACKET_ACTION_S1C_RECEIVE) { - if (first_received_packet > 0) { - relative_last_received_packet.tv_sec = packet->time_relative_to_first_packet.tv_sec; - relative_last_received_packet.tv_usec = packet->time_relative_to_first_packet.tv_usec; - packet->time_relative_to_last_received_packet.tv_sec = 0; - packet->time_relative_to_last_received_packet.tv_usec = 0; - first_received_packet = 0; - } else { - timersub(&packet->time_relative_to_first_packet, &relative_last_received_packet, - &packet->time_relative_to_last_received_packet); - relative_last_received_packet = packet->time_relative_to_first_packet; - } - if (first_sent_packet > 0) { - packet->time_relative_to_last_sent_packet.tv_sec = 0; - packet->time_relative_to_last_sent_packet.tv_usec = 0; - } else { - timersub(&packet->time_relative_to_first_packet, &relative_last_sent_packet, - &packet->time_relative_to_last_sent_packet); - } - } - } else if ((!xmlStrcmp(cur_node->name, (const xmlChar *)"frame.number"))) { xml_char = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"value"); packet->original_frame_number = strtoul((const char *)xml_char, NULL, 0); + fprintf(stdout, "Parsing packet frame.number: %u\n", packet->original_frame_number); xmlFree(xml_char); } else if ((!xmlStrcmp(cur_node->name, (const xmlChar *)"ip.src"))) { xml_char = xmlNodeListGetString(doc, cur_node->xmlChildrenNode, 1); @@ -473,13 +449,14 @@ et_packet_t* et_parse_xml_packet(xmlDocPtr doc, xmlNodePtr node) et_scenario_t* et_generate_scenario( const char * const tsml_out_scenario_filename) { - xmlDocPtr doc = NULL; - xmlNodePtr root = NULL; - xmlNodePtr node = NULL; - xmlChar *xml_char = NULL; - et_scenario_t *scenario = NULL; - et_packet_t *packet = NULL; - et_packet_t **next_packet = NULL; + xmlDocPtr doc = NULL; + xmlNodePtr root = NULL; + xmlNodePtr node = NULL; + xmlChar *xml_char = NULL; + et_scenario_t *scenario = NULL; + et_packet_t *last_packet = NULL; + et_packet_t *packet = NULL; + et_packet_t **next_packet = NULL; doc = xmlParseFile(tsml_out_scenario_filename); if (NULL == doc) { @@ -503,6 +480,14 @@ et_scenario_t* et_generate_scenario( if ((!xmlStrcmp(node->name, (const xmlChar *)"packet"))) { packet = et_parse_xml_packet(doc, node); if (NULL != packet) { + // special case: S1AP same frame for 2 packets + if (NULL != last_packet) { + if (last_packet->original_frame_number == packet->original_frame_number) { + // updating because these informations are not in 2nd sctp header (same IP packet) + packet->sctp_hdr.dst_port = last_packet->sctp_hdr.dst_port; + packet->sctp_hdr.src_port = last_packet->sctp_hdr.src_port; + } + } *next_packet = packet; next_packet = &packet->next; } else { @@ -510,6 +495,7 @@ et_scenario_t* et_generate_scenario( et_display_node(node, 0); } } + last_packet = packet; } } } else { diff --git a/openair3/TEST/EPC_TEST/play_scenario_s1ap.c b/openair3/TEST/EPC_TEST/play_scenario_s1ap.c index 285b883ded865e9a2181bb576506670109bab65b..5d5a3672d3139b17b655cfb1ceb9e4334599898b 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_s1ap.c +++ b/openair3/TEST/EPC_TEST/play_scenario_s1ap.c @@ -362,8 +362,16 @@ int et_handle_s1ap_mismatch_mme_ue_s1ap_id(et_packet_t * const spacket, et_packe case S1ap_ProcedureCode_id_UEContextRelease: if (present == S1AP_PDU_PR_initiatingMessage) { - //rx_mme_ue_s1ap_id = rx_packet->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.mme_ue_s1ap_id; - //scenario_mme_ue_s1ap_id = spacket->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.mme_ue_s1ap_id; + switch (rx_packet->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.uE_S1AP_IDs.present) { + case S1ap_UE_S1AP_IDs_PR_uE_S1AP_ID_pair: + rx_mme_ue_s1ap_id = rx_packet->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.uE_S1AP_IDs.choice.uE_S1AP_ID_pair.mME_UE_S1AP_ID; + scenario_mme_ue_s1ap_id = spacket->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.uE_S1AP_IDs.choice.uE_S1AP_ID_pair.mME_UE_S1AP_ID; + break; + case S1ap_UE_S1AP_IDs_PR_mME_UE_S1AP_ID: + rx_mme_ue_s1ap_id = rx_packet->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.uE_S1AP_IDs.choice.mME_UE_S1AP_ID; + scenario_mme_ue_s1ap_id = spacket->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCommandIEs.uE_S1AP_IDs.choice.mME_UE_S1AP_ID; + break; + } } else { rx_mme_ue_s1ap_id = rx_packet->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCompleteIEs.mme_ue_s1ap_id; scenario_mme_ue_s1ap_id = spacket->sctp_hdr.u.data_hdr.payload.message.msg.s1ap_UEContextReleaseCompleteIEs.mme_ue_s1ap_id; @@ -511,6 +519,7 @@ int et_handle_s1ap_mismatch_mme_ue_s1ap_id(et_packet_t * const spacket, et_packe AssertFatal(0, "Unknown procedure code %ld", rx_packet->sctp_hdr.u.data_hdr.payload.message.procedureCode); } if (scenario_mme_ue_s1ap_id != rx_mme_ue_s1ap_id) { + S1AP_DEBUG("%s() Updating mme_ue_s1ap_id %u -> %u \n", __FUNCTION__, scenario_mme_ue_s1ap_id, rx_mme_ue_s1ap_id); et_packet_t * p = spacket; while (p) { et_s1ap_update_mme_ue_s1ap_id(p, scenario_mme_ue_s1ap_id, rx_mme_ue_s1ap_id); @@ -615,6 +624,7 @@ int et_scenario_set_packet_received(et_packet_t * const packet) 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); + g_scenario->timer_count--; return rc; } return 1; @@ -656,7 +666,8 @@ int et_s1ap_process_rx_packet(et_event_s1ap_data_ind_t * const s1ap_data_ind) packet = g_scenario->last_rx_packet->next; } // not_found threshold may sure depend on number of mme, may be not sure on number of UE - while ((NULL != packet) && (not_found < 5)) { + while ((NULL != packet) && (not_found < 7)) { + S1AP_DEBUG("%s() Considering packet num %d original frame number %u\n", __FUNCTION__, packet->packet_number, packet->original_frame_number); if (packet->action == ET_PACKET_ACTION_S1C_RECEIVE) { comp_results = et_sctp_is_matching(&packet->sctp_hdr, &rx_packet->sctp_hdr, g_constraints); if (NULL == comp_results) { @@ -681,11 +692,15 @@ int et_s1ap_process_rx_packet(et_event_s1ap_data_ind_t * const s1ap_data_ind) return et_scenario_set_packet_received(packet); } } else if (strcmp(comp_results->name, "S1ap-TransportLayerAddress") == 0) { - S1AP_WARN("Some work needed there for %s, TODO in generic_scenario.xsl, add epc conf file in the process\n",comp_results->name); + S1AP_WARN("Some work needed there for %s, TODO in generic_scenario.xsl, add epc conf file in the process, anyway continuing...\n",comp_results->name); 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_WARN("\n\nRX PACKET:\n"); + et_display_packet_sctp(&rx_packet->sctp_hdr); + S1AP_WARN("\n\nWAITED PACKET:\n"); + et_display_packet_sctp(&packet->sctp_hdr); AssertFatal(0,"Some work needed there"); } } @@ -1112,6 +1127,7 @@ void *et_s1ap_eNB_task(void *arg) { et_packet_t * packet = (et_packet_t*)TIMER_HAS_EXPIRED (received_msg).arg; et_event_t event; + g_scenario->timer_count--; if (NULL != packet) { if (packet->status == ET_PACKET_STATUS_SCHEDULED_FOR_RECEIVING) { memset((void*)&event, 0, sizeof(event)); @@ -1123,6 +1139,10 @@ void *et_s1ap_eNB_task(void *arg) event.code = ET_EVENT_TX_TIMED_PACKET; event.u.tx_timed_packet = packet; et_scenario_fsm_notify_event(event); + + et_event_t continue_event; + continue_event.code = ET_EVENT_TICK; + et_scenario_fsm_notify_event(continue_event); } else if ((packet->status != ET_PACKET_STATUS_SENT) && ((packet->status != ET_PACKET_STATUS_RECEIVED))) { AssertFatal (0, "Bad status %d of packet timed out!\n", packet->status); } diff --git a/openair3/TEST/EPC_TEST/play_scenario_s1ap_compare_ie.c b/openair3/TEST/EPC_TEST/play_scenario_s1ap_compare_ie.c index 32b571f823d47f6fd65939feec813f8b451a6115..ad720ab7dc2e6272da79067f6fa92c30c4fdbcdd 100644 --- a/openair3/TEST/EPC_TEST/play_scenario_s1ap_compare_ie.c +++ b/openair3/TEST/EPC_TEST/play_scenario_s1ap_compare_ie.c @@ -467,6 +467,8 @@ void update_xpath_node_mme_ue_s1ap_id(et_s1ap_t * const s1ap, xmlNode *node, con int size = 0; int pos = 0; int go_deeper_in_tree = 1; + S1AP_DEBUG("%s() mme_ue_s1ap_id %u\n", __FUNCTION__, new_id); + // modify for (cur_node = (xmlNode *)node; cur_node; cur_node = cur_node->next) { go_deeper_in_tree = 1; @@ -484,6 +486,8 @@ void update_xpath_node_mme_ue_s1ap_id(et_s1ap_t * const s1ap, xmlNode *node, con xml_char = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"pos"); if (NULL != xml_char) { pos = strtoul((const char *)xml_char, NULL, 0); + pos -= s1ap->xml_stream_pos_offset; + AssertFatal(pos >= 0, "Bad pos %d xml_stream_pos_offset %d", pos, s1ap->xml_stream_pos_offset); xmlFree(xml_char); xml_char = xmlGetProp((xmlNode *)cur_node, (const xmlChar *)"size"); if (NULL != xml_char) { @@ -499,11 +503,11 @@ void update_xpath_node_mme_ue_s1ap_id(et_s1ap_t * const s1ap, xmlNode *node, con xmlFree(xml_char); // second: try to set value (always hex) ret = snprintf((char *)value_d, 32, "%ld", new_id); - AssertFatal((ret < 0) || (ret > 32), "Could not convert int to dec str"); + AssertFatal((ret > 0) && (ret < 32), "Could not convert int to dec str"); ret = snprintf((char *)value_h, 20, "C0%08X", new_id); - AssertFatal((ret < 0) || (ret > 20), "Could not convert int to hex str"); + AssertFatal((ret > 0) && (ret < 20), "Could not convert int to hex str"); ret = snprintf((char *)showname, 64, "MME-UE-S1AP-ID: %d", new_id); - AssertFatal((ret < 0) || (ret > 64), "Could not convert int to dec str"); + AssertFatal((ret > 0) && (ret < 64), "Could not convert int to dec str"); attr = xmlSetProp((xmlNode *)cur_node, (const xmlChar *)"value", value_h); attr = xmlSetProp((xmlNode *)cur_node, (const xmlChar *)"show", value_d); @@ -592,11 +596,12 @@ int et_s1ap_update_mme_ue_s1ap_id(et_packet_t * const packet, const S1ap_MME_UE_ xmlXPathContextPtr xpath_ctx = NULL; xmlXPathObjectPtr xpath_obj = NULL; + S1AP_DEBUG("%s() packet num %u original frame number %u, mme_ue_s1ap_id %u -> %u\n", __FUNCTION__, packet->packet_number, packet->original_frame_number, old_id, new_id); + ret = snprintf(xpath_expression, ET_XPATH_EXPRESSION_MAX_LENGTH, "//field[@name=\"s1ap.MME_UE_S1AP_ID\"][@show=\"%d\"]", old_id); AssertFatal((ret > 0) && (ret < ET_XPATH_EXPRESSION_MAX_LENGTH), "Could not build XPATH expression err=%d", ret); doc = packet->sctp_hdr.u.data_hdr.payload.doc; - // Create xpath evaluation context xpath_ctx = xmlXPathNewContext(doc); if(xpath_ctx == NULL) {