pcap/file: fix race during pcap processing start

A race condition during the start of pcap file processing could cause
missed alerts and logged events. This race happens between the packet
threads and the flow manager. It was observed on slower hardware, but in
theory could happen on any machine. It required the 'autofp' runmode.

In commit 6f560144c1b9 ("time: improve offline time handling") the logic
was added to make the flow manager use a minimum of all the packet threads
perception of time.

The race condition was that the flow manager may become active _before_
all of the packet threads have started processing packets and thus setting
their timestamp. The threads that had not yet initialized their timestamp
would not be considered when calculating the minimum.

As a result of this, older packets timestamps would not yet be registered.
This would give the Flow Manager a timestamp too far in the future. While
the FM was running, the packet processing would start and a flow would
be created. This flow would then immediately be considered 'timed out' by
the FM, due to the timestamp too far in the future.

In the observed case, the thread processing packet 1 from the pcap had not
yet started processing while other threads had already started. The FM was
also already active. Due to the timestamps in the pcap this meant that the
time the FM used was about 500 seconds in the future compared to packet 1.

This patch fixes the issue by initializing all of the threads timestamps
with the timestamp value of the first packet. This way the minimum will
always consider this timestamp.

(cherry picked from commit 9f1922e1756017b66c7161d49202a4120dd7f231)

diff --git a/src/source-pcap-file-helper.c b/src/source-pcap-file-helper.c
index 22b9c747a09b1cc2cb77e42f528552099b99f5a2..64ac2f7ac4fe029155f285586c9069bced11fd21 100644 (file)
--- a/src/source-pcap-file-helper.c
+++ b/src/source-pcap-file-helper.c
@@ -120,6 +120,14 @@ TmEcode PcapFileDispatch(PcapFileFileVars *ptv)
 {
     SCEnter();
 
+    /* initialize all the threads initial timestamp */
+    if (likely(ptv->first_pkt_hdr != NULL)) {
+        TmThreadsInitThreadsTimestamp(&ptv->first_pkt_ts);
+        PcapFileCallbackLoop((char *)ptv, ptv->first_pkt_hdr, (u_char *)ptv->first_pkt_data);
+        ptv->first_pkt_hdr = NULL;
+        ptv->first_pkt_data = NULL;
+    }
+
     int packet_q_len = 64;
     int r;
     TmEcode loop_result = TM_ECODE_OK;
@@ -160,6 +168,23 @@ TmEcode PcapFileDispatch(PcapFileFileVars *ptv)
     SCReturnInt(loop_result);
 }
 
+/** \internal
+ *  \brief get the timestamp of the first packet and rewind
+ *  \retval bool true on success, false on error
+ */
+static bool PeekFirstPacketTimestamp(PcapFileFileVars *pfv)
+{
+    int r = pcap_next_ex(pfv->pcap_handle, &pfv->first_pkt_hdr, &pfv->first_pkt_data);
+    if (r <= 0 || pfv->first_pkt_hdr == NULL) {
+        SCLogError(SC_ERR_PCAP_OPEN_OFFLINE,
+                "failed to get first packet timestamp. pcap_next_ex(): %d", r);
+        return false;
+    }
+    pfv->first_pkt_ts.tv_sec = pfv->first_pkt_hdr->ts.tv_sec;
+    pfv->first_pkt_ts.tv_usec = pfv->first_pkt_hdr->ts.tv_usec;
+    return true;
+}
+
 TmEcode InitPcapFile(PcapFileFileVars *pfv)
 {
     char errbuf[PCAP_ERRBUF_SIZE] = "";
@@ -196,6 +221,9 @@ TmEcode InitPcapFile(PcapFileFileVars *pfv)
     pfv->datalink = pcap_datalink(pfv->pcap_handle);
     SCLogDebug("datalink %" PRId32 "", pfv->datalink);
 
+    if (!PeekFirstPacketTimestamp(pfv))
+        SCReturnInt(TM_ECODE_FAILED);
+
     DecoderFunc temp;
     TmEcode validated = ValidateLinkType(pfv->datalink, &temp);
     SCReturnInt(validated);

diff --git a/src/source-pcap-file-helper.h b/src/source-pcap-file-helper.h
index 5d8ee2b72ca007a4231ab09cf398befe50d281ec..937e3e70ff0962d0e54c58f1179bf098cf02bcc5 100644 (file)
--- a/src/source-pcap-file-helper.h
+++ b/src/source-pcap-file-helper.h
@@ -1,4 +1,4 @@
-/* Copyright (C) 2007-2010 Open Information Security Foundation
+/* Copyright (C) 2007-2020 Open Information Security Foundation
  *
  * You can copy, redistribute or modify this Program under the terms of
  * the GNU General Public License version 2 as published by the Free
@@ -74,6 +74,12 @@ typedef struct PcapFileFileVars_
     struct bpf_program filter;
 
     PcapFileSharedVars *shared;
+
+    /* fields used to get the first packets timestamp early,
+     * so it can be used to setup the time subsys. */
+    const u_char *first_pkt_data;
+    struct pcap_pkthdr *first_pkt_hdr;
+    struct timeval first_pkt_ts;
 } PcapFileFileVars;
 
 /**

diff --git a/src/tm-threads.c b/src/tm-threads.c
index 44b6b07c8ca574913a3e98b3d7bc946a392207b8..2656891df2d24a68961246769f04be71d12cc744 100644 (file)
--- a/src/tm-threads.c
+++ b/src/tm-threads.c
@@ -2388,6 +2388,7 @@ end:
     SCMutexUnlock(&thread_store_lock);
 }
 
+#define COPY_TIMESTAMP(src,dst) ((dst)->tv_sec = (src)->tv_sec, (dst)->tv_usec = (src)->tv_usec) // XXX unify with flow-util.h
 void TmThreadsSetThreadTimestamp(const int id, const struct timeval *ts)
 {
     SCMutexLock(&thread_store_lock);
@@ -2398,12 +2399,22 @@ void TmThreadsSetThreadTimestamp(const int id, const struct timeval *ts)
 
     int idx = id - 1;
     Thread *t = &thread_store.threads[idx];
-    t->ts.tv_sec = ts->tv_sec;
-    t->ts.tv_usec = ts->tv_usec;
+    COPY_TIMESTAMP(ts, &t->ts);
+    SCMutexUnlock(&thread_store_lock);
+}
+
+void TmThreadsInitThreadsTimestamp(const struct timeval *ts)
+{
+    SCMutexLock(&thread_store_lock);
+    for (size_t s = 0; s < thread_store.threads_size; s++) {
+        Thread *t = &thread_store.threads[s];
+        if (!t->in_use)
+            break;
+        COPY_TIMESTAMP(ts, &t->ts);
+    }
     SCMutexUnlock(&thread_store_lock);
 }
 
-#define COPY_TIMESTAMP(src,dst) ((dst)->tv_sec = (src)->tv_sec, (dst)->tv_usec = (src)->tv_usec) // XXX unify with flow-util.h
 void TmThreadsGetMinimalTimestamp(struct timeval *ts)
 {
     struct timeval local, nullts;

diff --git a/src/tm-threads.h b/src/tm-threads.h
index e8a1df2c601026287caab13e3d06b20b9d76aa14..165967bf3d2a6ef33494fc8b4fa70261f08e6ccb 100644 (file)
--- a/src/tm-threads.h
+++ b/src/tm-threads.h
@@ -285,6 +285,7 @@ int TmThreadsRegisterThread(ThreadVars *tv, const int type);
 void TmThreadsUnregisterThread(const int id);
 int TmThreadsInjectPacketsById(Packet **, int id);
 
+void TmThreadsInitThreadsTimestamp(const struct timeval *ts);
 void TmThreadsSetThreadTimestamp(const int id, const struct timeval *ts);
 void TmThreadsGetMinimalTimestamp(struct timeval *ts);