diff --git a/src/large-pcap-analyzer.cpp b/src/large-pcap-analyzer.cpp index 8f0ac10..4387b0a 100644 --- a/src/large-pcap-analyzer.cpp +++ b/src/large-pcap-analyzer.cpp @@ -193,6 +193,7 @@ int main(int argc, char** argv) int opt; bool append = false; bool preserve_ifg = false; + bool timestamp_analysis = false; bool timestamp_processing_option_present = false; bool traffic_report_present = false; bool report_based_on_inner = false; @@ -265,7 +266,7 @@ int main(int argc, char** argv) // timestamp processing options: case 't': - g_config.m_timestamp_analysis = true; + timestamp_analysis = true; timestamp_processing_option_present = true; break; case 'D': @@ -438,7 +439,7 @@ int main(int argc, char** argv) } } else if (timestamp_processing_option_present) { pproc = ×tamp_packet_proc; - if (!timestamp_packet_proc.prepare_processor(new_duration, preserve_ifg, set_timestamps)) { + if (!timestamp_packet_proc.prepare_processor(timestamp_analysis, new_duration, preserve_ifg, set_timestamps)) { // error was already logged return 1; } diff --git a/src/large-pcap-analyzer.h b/src/large-pcap-analyzer.h index af12ccd..b50e1dd 100644 --- a/src/large-pcap-analyzer.h +++ b/src/large-pcap-analyzer.h @@ -60,7 +60,6 @@ class LPAConfig { public: bool m_verbose = false; bool m_quiet = false; - bool m_timestamp_analysis = false; bool m_parsing_stats = false; // technically this is not a configuration but the status of the application... diff --git a/src/packet.h b/src/packet.h index 9a37f2f..c5b23e1 100644 --- a/src/packet.h +++ b/src/packet.h @@ -34,6 +34,7 @@ #endif #include +#include #include #include diff --git a/src/process_file.cpp b/src/process_file.cpp index 5280e67..f1f8730 100644 --- a/src/process_file.cpp +++ b/src/process_file.cpp @@ -225,18 +225,12 @@ static bool process_pcap_handle( unsigned long* nloadedOUT, unsigned long* nmatchingOUT) { - unsigned long nloaded = 0, nmatching = 0, ngtpu = 0, nbytes_avail = 0, - nbytes_orig = 0; + unsigned long nloaded = 0, nmatching = 0, ngtpu = 0; struct timeval start, stop; - bool first = true; ParsingStats parsing_stats; const u_char* pcap_packet; struct pcap_pkthdr* pcap_header; - struct pcap_pkthdr first_pcap_header, last_pcap_header; - - memset(&first_pcap_header, 0, sizeof(first_pcap_header)); - memset(&last_pcap_header, 0, sizeof(last_pcap_header)); std::string pcapfilter_desc = ""; if (filter && filter->is_capture_filter_set()) @@ -254,13 +248,13 @@ static bool process_pcap_handle( // filter and save to output eventually bool is_gtpu = false; - bool tosave = true; + bool toprocess = true; if (filter) - tosave = filter->is_matching(pkt, &is_gtpu); + toprocess = filter->is_matching(pkt, &is_gtpu); // else: filtering disabled, save all packets - if (tosave) { + if (toprocess) { if (pktprocessor) { bool pktWasChanged = false; if (!pktprocessor->process_packet(pkt, tempPkt, @@ -289,23 +283,12 @@ static bool process_pcap_handle( if (is_gtpu) ngtpu++; - if (g_config.m_timestamp_analysis) { - // save timestamps for later analysis: - if (UNLIKELY(first)) { - memcpy(&first_pcap_header, pcap_header, sizeof(struct pcap_pkthdr)); - first = false; - } else - memcpy(&last_pcap_header, pcap_header, sizeof(struct pcap_pkthdr)); - } - if (g_config.m_parsing_stats) { update_parsing_stats(pkt, parsing_stats); } // advance main stats counters: - nbytes_avail += pcap_header->caplen; - nbytes_orig += pcap_header->len; nloaded++; } gettimeofday(&stop, NULL); @@ -340,56 +323,6 @@ static bool process_pcap_handle( } } - // FIXME: move into TimestampPacketProcessor::post_processing(): - if (g_config.m_timestamp_analysis) { - if (!Packet::pcap_timestamp_is_valid(&first_pcap_header) && !Packet::pcap_timestamp_is_valid(&last_pcap_header)) { - printf_normal("Apparently both the first and last packet packets of the PCAP have no valid timestamp... cannot compute PCAP duration.\n"); - return false; - } - - if (!Packet::pcap_timestamp_is_valid(&last_pcap_header) && nloaded == 1) { - - // corner case: PCAP with just 1 packet... duration is zero by definition: - - if (g_config.m_quiet) - printf_quiet("0\n"); // be machine-friendly and indicate an error - else - printf_normal("The PCAP contains just 1 packet: duration is zero.\n"); - } else { - - double secStart = Packet::pcap_timestamp_to_seconds(&first_pcap_header); - double secStop = Packet::pcap_timestamp_to_seconds(&last_pcap_header); - double sec = secStop - secStart; - if (secStart < SMALL_NUM && secStop == SMALL_NUM) { - if (g_config.m_quiet) - printf_quiet("-1\n"); // be machine-friendly and indicate an error - else - printf_normal("Apparently the packets of the PCAP have no valid timestamp... cannot compute PCAP duration.\n"); - - return false; - } - - if (g_config.m_quiet) - printf_quiet("%f\n", sec); // be machine-friendly - else - printf_normal("Last packet has a timestamp offset = %.2fsec = %.2fmin = %.2fhours\n", - sec, sec / 60.0, sec / 3600.0); - - printf_verbose("Bytes loaded from PCAP = %lukiB = %luMiB; total bytes on wire = %lukiB = %luMiB\n", - nbytes_avail / KB, nbytes_avail / MB, nbytes_orig / KB, nbytes_orig / MB); - if (nbytes_avail == nbytes_orig) - printf_verbose(" => all packets in the PCAP have been captured WITHOUT truncation.\n"); - - if (sec > 0) { - printf_normal("Tcpreplay should replay this PCAP at an average of %.2fMbps / %.2fpps to respect PCAP timings.\n", - (float)(8 * nbytes_avail / MB) / sec, (float)nloaded / sec); - } else { - printf_normal("Cannot compute optimal tcpreplay speed for replaying: duration is null or negative.\n"); - return false; - } - } - } - if (g_config.m_parsing_stats) { if (g_config.m_quiet) { // be machine-friendly: use CSV format diff --git a/src/timestamp_pkt_processor.cpp b/src/timestamp_pkt_processor.cpp index 4c3a5d2..ced8efa 100644 --- a/src/timestamp_pkt_processor.cpp +++ b/src/timestamp_pkt_processor.cpp @@ -59,8 +59,9 @@ bool String2TimestampInSecs(const std::string& str, double& result) // TimestampPacketProcessor //------------------------------------------------------------------------------ -bool TimestampPacketProcessor::prepare_processor(const std::string& set_duration, bool preserve_ifg, const std::string& timestamp_file) +bool TimestampPacketProcessor::prepare_processor(bool print_timestamp_analysis, const std::string& set_duration, bool preserve_ifg, const std::string& timestamp_file) { + m_print_timestamp_analysis = print_timestamp_analysis; if (!set_duration.empty()) { // the duration string can be a number in format // SECONDS.FRACTIONAL_SECONDS @@ -144,6 +145,29 @@ bool TimestampPacketProcessor::process_packet(const Packet& pktIn, Packet& pktOu { pktWasChangedOut = false; // by default: no proc done, use original packet + if (IPacketProcessor::get_pass_index() == 0) { + m_num_input_pkts++; + + // regardless of which "processing mode" has been chosen, save timestamps of first/last pkts; + // these are used to + // * provide some basic timing info during the post_processing() phase + // * support the PROCMODE_CHANGE_DURATION_RESET_IFG/PROCMODE_CHANGE_DURATION_PRESERVE_IFG modes + if (UNLIKELY(pktIdx == 0)) { + assert(m_first_pkt_ts_sec == 0); + m_first_pkt_ts_sec = pktIn.pcap_timestamp_to_seconds(); + m_last_pkt_ts_sec = m_first_pkt_ts_sec; + printf_verbose("First pkt timestamp is %f\n", m_first_pkt_ts_sec); + } else { + // remember the timestamp of the last packet: + m_last_pkt_ts_sec = pktIn.pcap_timestamp_to_seconds(); + } + + // caplen indicates what has been _really_ captured + // len indicates how long was the original packet + m_nbytes_pcap += pktIn.header()->caplen; + m_nbytes_original += pktIn.header()->len; + } + switch (m_proc_mode) { case PROCMODE_NONE: { pktWasChangedOut = false; // no proc done, use original packet @@ -151,13 +175,9 @@ bool TimestampPacketProcessor::process_packet(const Packet& pktIn, Packet& pktOu case PROCMODE_CHANGE_DURATION_RESET_IFG: case PROCMODE_CHANGE_DURATION_PRESERVE_IFG: { - if (IPacketProcessor::get_pass_index() == 0) { - // in the first pass just count the number of packets to process & - // remember the timestamp of the last packet: - m_num_input_pkts++; - m_last_pkt_ts_sec = pktIn.pcap_timestamp_to_seconds(); - } else // second pass - { + if (IPacketProcessor::get_pass_index() == 1) { + // second pass + assert(m_new_duration_secs > 0); assert(m_num_input_pkts > 0); @@ -167,9 +187,6 @@ bool TimestampPacketProcessor::process_packet(const Packet& pktIn, Packet& pktOu //assert(m_last_pkt_ts_sec > 0); if (pktIdx == 0) { - assert(m_first_pkt_ts_sec == 0); - m_first_pkt_ts_sec = pktIn.pcap_timestamp_to_seconds(); - printf_verbose("First pkt timestamp is %f and there are %zu pkts; target duration is %f\n", m_first_pkt_ts_sec, m_num_input_pkts, m_new_duration_secs); @@ -194,6 +211,7 @@ bool TimestampPacketProcessor::process_packet(const Packet& pktIn, Packet& pktOu thisPktTs = m_first_pkt_ts_sec + secInterPktGap * (pktIdx + 1); } else // PROCMODE_CHANGE_DURATION_PRESERVE_IFG { + // this code executes only during the second pass, so m_last_pkt_ts_sec is now valid: double originalDuration = m_last_pkt_ts_sec - m_first_pkt_ts_sec; // constant for the whole PCAP of course double pktTsOffsetSincePcapStart = pktIn.pcap_timestamp_to_seconds() - m_first_pkt_ts_sec; @@ -237,27 +255,89 @@ bool TimestampPacketProcessor::process_packet(const Packet& pktIn, Packet& pktOu return true; } +bool TimestampPacketProcessor::print_timestamp_analysis() // internal helper function +{ + if (m_num_input_pkts == 1) { + // corner case: PCAP with just 1 packet... duration is zero by definition: + if (g_config.m_quiet) + printf_quiet("%.6f\n", 0.0f); // be machine-friendly and indicate an error + else + printf_normal("The PCAP contains just 1 packet: duration is zero.\n"); + + return false; + } + + if (m_first_pkt_ts_sec <= 0 && m_last_pkt_ts_sec <= 0) { + // corner case: negative or null timestamps at start/end of the PCAP + if (g_config.m_quiet) + printf_quiet("%.6f\n", -1.0f); // be machine-friendly and indicate an error + else + printf_normal("Apparently both the first and last packet packets of the PCAP have no valid timestamp... cannot compute PCAP duration.\n"); + return false; + } + + if (m_first_pkt_ts_sec < SMALL_NUM && m_last_pkt_ts_sec == SMALL_NUM) { + // another corner case: close-to-zero timestamps + if (g_config.m_quiet) + printf_quiet("%.6f\n", -1.0f); // be machine-friendly and indicate an error + else + printf_normal("Apparently the packets of the PCAP have no valid timestamp (extremely small at least)... cannot compute PCAP duration.\n"); + + return false; + } + + // normal case: + double duration_sec = m_last_pkt_ts_sec - m_first_pkt_ts_sec; + + if (g_config.m_quiet) + printf_quiet("%.6f\n", duration_sec); // be machine-friendly + else + printf_normal("Last packet has a timestamp offset = %.2fsec = %.2fmin = %.2fhours\n", + duration_sec, duration_sec / 60.0, duration_sec / 3600.0); + + printf_verbose("Bytes loaded from PCAP = %lukiB = %luMiB; total bytes on wire = %lukiB = %luMiB\n", + m_nbytes_pcap / KB, m_nbytes_pcap / MB, m_nbytes_original / KB, m_nbytes_original / MB); + if (m_nbytes_pcap == m_nbytes_original) + printf_verbose(" => all packets in the PCAP have been captured WITHOUT truncation.\n"); + + if (duration_sec > 0) { + printf_normal("Tcpreplay should replay this PCAP at an average of %.2fMbps / %.2fpps to respect PCAP timings.\n", + (float)(8 * m_nbytes_pcap / MB) / duration_sec, (float)m_num_input_pkts / duration_sec); + } else { + printf_normal("Cannot compute optimal tcpreplay speed for replaying: duration is null or negative.\n"); + return false; + } + return true; +} + bool TimestampPacketProcessor::post_processing(const std::string& /*infile*/, unsigned int totNumPkts) { + bool timestamp_analysis_success = true; + if (m_print_timestamp_analysis) + timestamp_analysis_success = print_timestamp_analysis(); + + bool timestamp_change_success = true; switch (m_proc_mode) { case PROCMODE_NONE: case PROCMODE_CHANGE_DURATION_RESET_IFG: case PROCMODE_CHANGE_DURATION_PRESERVE_IFG: - return true; // no error + timestamp_change_success = true; // no error + break; case PROCMODE_SET_TIMESTAMPS: { if (totNumPkts < m_timestamps.size()) { printf_error("Too many timestamps specified in the file with timestamps '%s': %zu but input PCAP has %zu packets.\n", m_timestamps_input_file.c_str(), m_timestamps.size(), totNumPkts); - return false; - } - - return true; + timestamp_change_success = false; + } else + timestamp_change_success = true; } break; default: assert(0); return false; } + + return timestamp_analysis_success && timestamp_change_success; } diff --git a/src/timestamp_pkt_processor.h b/src/timestamp_pkt_processor.h index ad0ac4b..0524555 100644 --- a/src/timestamp_pkt_processor.h +++ b/src/timestamp_pkt_processor.h @@ -55,18 +55,23 @@ class TimestampPacketProcessor : public IPacketProcessor { public: TimestampPacketProcessor() { + // config m_proc_mode = PROCMODE_NONE; + m_print_timestamp_analysis = false; m_new_duration_secs = 0; + + // status m_first_pkt_ts_sec = 0; m_last_pkt_ts_sec = 0; m_previous_pkt_ts_sec = 0; m_num_input_pkts = 0; + m_nbytes_pcap = 0; + m_nbytes_original = 0; } - ~TimestampPacketProcessor() {} + ~TimestampPacketProcessor() { } - bool prepare_processor(const std::string& set_duration, bool preserve_ifg, - const std::string& timestamp_file); + bool prepare_processor(bool print_timestamp_analysis, const std::string& set_duration, bool preserve_ifg, const std::string& timestamp_file); virtual bool is_some_processing_active() const { @@ -86,19 +91,24 @@ class TimestampPacketProcessor : public IPacketProcessor { virtual bool post_processing(const std::string& file, unsigned int totNumPkts) override; +protected: + bool print_timestamp_analysis(); + private: // configuration: TimestampProcessingModes m_proc_mode; + bool m_print_timestamp_analysis; double m_new_duration_secs; - std::vector m_timestamps; + std::vector m_timestamps; // timestamps loaded from input file, to apply to all packets std::string m_timestamps_input_file; // status: double m_first_pkt_ts_sec; double m_last_pkt_ts_sec; - double m_previous_pkt_ts_sec; unsigned long m_num_input_pkts; + uint64_t m_nbytes_pcap; + uint64_t m_nbytes_original; }; #endif // TIMESTAMP_PKT_PROCESSOR_H_ diff --git a/test-pcaps/ipv4_sctp_iua.pcap b/test-pcaps/ipv4_sctp_iua.pcap new file mode 100644 index 0000000..6da5e71 Binary files /dev/null and b/test-pcaps/ipv4_sctp_iua.pcap differ diff --git a/test-pcaps/run_tests.sh b/test-pcaps/run_tests.sh index 83e33cc..b8d2913 100755 --- a/test-pcaps/run_tests.sh +++ b/test-pcaps/run_tests.sh @@ -30,6 +30,30 @@ function assert_strings_match() fi } +function assert_file_contains() +{ + local FILE="$1" + local EXPECTED_CONTENT="$2" + + grep -q -- "$EXPECTED_CONTENT" "$FILE" + if [ $? -ne 0 ]; then + echo "Expecting [$EXPECTED_CONTENT] inside [$FILE], but that string/pattern has not been found. Aborting." + exit 2 + fi +} + +function assert_file_contains_expected_number_of_lines() +{ + local FILE="$1" + local EXPECTED_NUMLINES="$2" + + num_lines=$(wc -l "$FILE" | cut -f1 -d ' ') + if [ $num_lines -ne $EXPECTED_NUMLINES ]; then + echo "Expecting [$EXPECTED_NUMLINES] lines inside [$FILE], but found instead [$num_lines] lines. Aborting." + exit 2 + fi +} + function assert_files_match() { local FILE_UNDER_TEST="$1" @@ -93,33 +117,61 @@ function test_timing() # test short option test_file[1]="timing-test.pcap" expected_pps[1]="0.50pps" - expected_duration[1]="60.00sec" + expected_duration[1]="60.00" expected_exitcode[1]=0 + expected_human_friendly_output_lines[1]=3 # try to check timing of an invalid PCAP file containing negative timestamps test_file[2]="invalid_timestamp1_negative_ts.pcap" expected_pps[2]="0" - expected_duration[2]="0" + expected_duration[2]="-1.0" expected_exitcode[2]=2 # we expect a failure in timing analysis + expected_human_friendly_output_lines[2]=2 # try to check timing of an invalid PCAP file containing "0" as timestamp for all pkts test_file[3]="invalid_timestamp2_zero_ts.pcap" expected_pps[3]="0" - expected_duration[3]="0" + expected_duration[3]="0.0" expected_exitcode[3]=2 # we expect a failure in timing analysis + expected_human_friendly_output_lines[3]=3 + + # try to check timing of an invalid PCAP file containing a mix of positive and negative timestamps: + test_file[4]="ipv4_sctp_iua.pcap" + expected_pps[4]="0" + expected_duration[4]="-1.0" + expected_exitcode[4]=2 # we expect a failure in timing analysis + expected_human_friendly_output_lines[4]=2 - for testnum in $(seq 1 3); do + for testnum in $(seq 1 4); do + + # ---- first test ----- + # check the human-friendly output: $lpa_binary -t "${test_file[testnum]}" >/tmp/timing-test-${testnum} if [ $? -ne ${expected_exitcode[testnum]} ]; then echo "Failed test of timing analysis (-t option)" ; exit 1 ; fi - # test that the line that starts as "Tcpreplay should replay this PCAP at an average of"... contains the right PPS - cat /tmp/timing-test-${testnum} | grep -q "${expected_pps[testnum]}" - if [ $? -ne 0 ]; then echo "Failed test of timing analysis (-t option)" ; exit 1 ; fi + # we should produce a specific number lines: + assert_file_contains_expected_number_of_lines "/tmp/timing-test-${testnum}" "${expected_human_friendly_output_lines[testnum]}" + + # human-friendly output should contain (somewhere) the expected PPS & expected duration: + assert_file_contains "/tmp/timing-test-${testnum}" "${expected_pps[testnum]}" + if [ ${expected_exitcode[testnum]} -eq 0 ]; then + assert_file_contains "/tmp/timing-test-${testnum}" "${expected_duration[testnum]}" + fi + + # ---- second test ----- + # now analyze again the PCAP using the script-friendly output (--quiet): + $lpa_binary -q -t "${test_file[testnum]}" >/tmp/timing-test-quiet-${testnum} + if [ $? -ne ${expected_exitcode[testnum]} ]; then echo "Failed test of timing analysis (-t option)" ; exit 1 ; fi - cat /tmp/timing-test-${testnum} | grep -q "${expected_duration[testnum]}" - if [ $? -ne 0 ]; then echo "Failed test of timing analysis (-t option)" ; exit 1 ; fi + #if [ ${expected_exitcode[testnum]} -eq 0 ]; then + # in quiet mode the LPA should always produce just 1 line + assert_file_contains_expected_number_of_lines "/tmp/timing-test-quiet-${testnum}" "1" + # that line must contain the duration: + local actual_duration=$(cat /tmp/timing-test-quiet-${testnum}) + assert_floatingpoint_numbers_match "$actual_duration" "${expected_duration[testnum]}" + #fi echo " ... testcase #$testnum passed." done }