Refactor code for timestamp analysis

* Move all timestamp analysis code in the new timestamp processor
* Make sure to always print the PCAP duration (even in case of error, as -1.0) when using --quiet option to be script-friendly
* Improve integration tests (test also the -q output; add a new PCAP file)
* Fix Snap build by including stdint.h

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 = &timestamp_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;
         }

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...

src/packet.h

@@ -34,6 +34,7 @@
 #endif
 
 #include <linux/types.h>
+#include <stdint.h>
 #include <stdlib.h>
 #include <string.h>
 

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

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,20 +145,39 @@ 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
     } break;
 
     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;
 }

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<double> m_timestamps;
+    std::vector<double> 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_