Flow timeout timing/v14 #12084

victorjulien · 2024-11-04T10:34:40Z

More precise flow timeout enforcement.

Cleans up unix socket initialization.

When a thread fails to spawn, include the thread name in the error message.

No longer init then deinit part of the engine at startup of the unix socket mode.

Timeout checks would access certain fields w/o locking, which could lead to thread safety issues.

Use a more precise calculation for timing out flows, using both the seconds and the micro seconds.

The flow worker needs to get the opportunity to run the flow update before globally making it's current timestamp available. This is to avoid another thread using the time to evict the flow that is about to get a legitimate update.

If seconds match a flow can still be timing out.

When timing out flows, use the timestamp from the "owning" thread. This avoids problems with threads being out of sync with each other.

As this may mean that a threads ts is a bit ahead of the minimum time the flow manager normally uses, it can evict flows a bit faster.

The idea of sealing the thread store is that its members can be accessed w/o holding a lock to the whole store at runtime.

Some checks can be done w/o holding a lock: - seeing if the flow matches the packet - if the hash row needs a timeout check This patch skips taking a lock in these conditions.

codecov · 2024-11-04T10:56:23Z

Codecov Report

Attention: Patch coverage is 90.27778% with 14 lines in your changes missing coverage. Please review.

Project coverage is 83.36%. Comparing base (3a7eef8) to head (b1ea592).
Report is 2 commits behind head on master.

Additional details and impacted files

@@            Coverage Diff             @@
##           master   #12084      +/-   ##
==========================================
- Coverage   83.42%   83.36%   -0.07%     
==========================================
  Files         910      910              
  Lines      257642   257611      -31     
==========================================
- Hits       214949   214747     -202     
- Misses      42693    42864     +171

Flag	Coverage Δ
fuzzcorpus	`61.54% <43.16%> (-0.11%)`	⬇️
livemode	`19.46% <46.04%> (+0.05%)`	⬆️
pcap	`44.42% <84.89%> (-0.06%)`	⬇️
suricata-verify	`62.75% <89.20%> (-0.01%)`	⬇️
unittests	`59.34% <19.71%> (-0.03%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

suricata-qa · 2024-11-04T13:30:05Z

Information:

ERROR: QA failed on SURI_TLPW2_autofp_suri_time.

ERROR: QA failed on SURI_TLPR1_alerts_cmp.

field	baseline	test	%
	SURI_TLPW1_stats_chk
.app_layer.flow.dhcp	563	600	106.57%
	SURI_TLPR1_stats_chk
.app_layer.flow.ftp	32307	33405	103.4%
.app_layer.flow.dcerpc_tcp	40	42	105.0%

Pipeline 23246

victorjulien · 2024-11-04T14:49:39Z

Passed my QA. Ran this PR with SV PR OISF/suricata-verify#2116. Local pipeline 5127, run 623.

inashivb · 2024-11-05T06:49:01Z

Information:

ERROR: QA failed on SURI_TLPW2_autofp_suri_time.

ERROR: QA failed on SURI_TLPR1_alerts_cmp.
field baseline test %
SURI_TLPW1_stats_chk
.app_layer.flow.dhcp 563 600 106.57%
SURI_TLPR1_stats_chk
.app_layer.flow.ftp 32307 33405 103.4%
.app_layer.flow.dcerpc_tcp 40 42 105.0%

Pipeline 23246

Interesting deviations.
Q1: Are you able to explain all the deviations?
OR
Q2: Does this need a rerun?

I think I can explain the change in flow count and alert count theoretically. But, refraining from verifying until I get a response on the questions above.

suricata-qa · 2024-11-05T11:25:04Z

Information:

ERROR: QA failed on SURI_TLPW2_autofp_suri_time.

ERROR: QA failed on SURI_TLPR1_alerts_cmp.

field	baseline	test	%
	SURI_TLPW1_stats_chk
.app_layer.flow.dhcp	563	600	106.57%
	SURI_TLPR1_stats_chk
.app_layer.flow.dcerpc_tcp	40	42	105.0%

Pipeline 23250

inashivb · 2024-11-07T07:41:59Z

src/output-eve-stream.c

@@ -157,6 +157,7 @@ static OutputInitResult EveStreamLogInitCtxSub(ConfNode *conf, OutputCtx *parent
        ctx->trigger_flags |= SetFlag(conf, "state-update", STREAM_PKT_FLAG_STATE_UPDATE);
        ctx->trigger_flags |=
                SetFlag(conf, "spurious-retransmission", STREAM_PKT_FLAG_SPURIOUS_RETRANSMISSION);
+        ctx->trigger_flags |= SetFlag(conf, "tcp-port-reuse", STREAM_PKT_FLAG_TCP_PORT_REUSE);


Q: Why is it called "port" reuse?

inashivb · 2024-11-07T08:02:01Z

src/flow-manager.c

@@ -182,16 +185,20 @@ void FlowDisableFlowManagerThread(void)
 */
 static bool FlowManagerFlowTimeout(Flow *f, SCTime_t ts, uint32_t *next_ts, const bool emerg)
 {
-    uint32_t flow_times_out_at = f->timeout_at;
+    SCTime_t timesout_at; // = f->lastts;


About the comment: why?

inashivb · 2024-11-07T08:32:49Z

src/flow-worker.c

+    /* update time */
+    if (!(PKT_IS_PSEUDOPKT(p))) {
+        TimeSetByThread(tv->id, p->ts);
+    }
+


Could we merge it w the else if condition above?

inashivb · 2024-11-07T08:35:11Z

src/tm-threads.c

@@ -2266,7 +2266,7 @@ void TmThreadsGetMinimalTimestamp(struct timeval *ts)
        if (t->type != TVT_PPT)
            continue;
        if (SCTIME_CMP_NEQ(t->pktts, nullts)) {
-            SCTime_t sys_sec_stamp = SCTIME_ADD_SECS(t->sys_sec_stamp, 1);


inashivb · 2024-11-07T08:57:28Z

src/flow-hash.c

+    if (TimeModeIsLive()) {
+        if (SCTIME_CMP_LT(pktts, timesout_at)) {
+            return false;
+        }
+    } else {
+        if (ftid == f->thread_id[0] || f->thread_id[0] == 0) {
+            /* do the timeout check */
+            if (SCTIME_CMP_LT(pktts, timesout_at)) {
+                return false;
+            }


We seem to do the same thing in both the blocks? Can we merge them? Then it becomes similar to flow manager..

catenacyber · 2024-11-28T14:30:28Z

Is there a redmine ticket to do for this ?

victorjulien added 16 commits November 3, 2024 08:04

threads: include name in error message

cf4a3cf

When a thread fails to spawn, include the thread name in the error message.

unix/socket: cleanup start up logic

8f3c6bd

No longer init then deinit part of the engine at startup of the unix socket mode.

eve/flow: log tcp reuse as 'reason'

858453d

flow: improve thread safety during timeout checks

44592ec

Timeout checks would access certain fields w/o locking, which could lead to thread safety issues.

eve/stream: add tcp-port-reuse trigger

b1140ea

time: getter for SCTime_t timestamp of a thread

c80afe7

flow: exact flow timeout

78b8898

Use a more precise calculation for timing out flows, using both the seconds and the micro seconds.

time: thread time update after flow update

9bc1c59

The flow worker needs to get the opportunity to run the flow update before globally making it's current timestamp available. This is to avoid another thread using the time to evict the flow that is about to get a legitimate update.

threads: use sleeping threads for minimum time a bit longer

a516c42

flow: fix fb ts optimization

22683e0

If seconds match a flow can still be timing out.

flow/worker: improve flow timeout time accuracy

5411384

When timing out flows, use the timestamp from the "owning" thread. This avoids problems with threads being out of sync with each other.

flow/manager: in offline mode, use owning threads time

663eefc

As this may mean that a threads ts is a bit ahead of the minimum time the flow manager normally uses, it can evict flows a bit faster.

threads: atomic packet timestamp

ef672b3

threads: seal after setup; unseal at shutdown

2b8351f

The idea of sealing the thread store is that its members can be accessed w/o holding a lock to the whole store at runtime.

threads: align struct to CLS to avoid false sharing

add7b78

flow: skip lock for skippable flows

b1ea592

Some checks can be done w/o holding a lock: - seeing if the flow matches the packet - if the hash row needs a timeout check This patch skips taking a lock in these conditions.

inashivb self-requested a review November 5, 2024 08:02

victorjulien added the waiting for qa label Nov 5, 2024

suricata-qa removed the waiting for qa label Nov 5, 2024

inashivb reviewed Nov 7, 2024

View reviewed changes

ct0br0 mentioned this pull request Nov 18, 2024

Dataset set postmatch 5576 v13 #12126

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Flow timeout timing/v14 #12084

Flow timeout timing/v14 #12084

victorjulien commented Nov 4, 2024

codecov bot commented Nov 4, 2024 •

edited

Loading

suricata-qa commented Nov 4, 2024

victorjulien commented Nov 4, 2024

inashivb commented Nov 5, 2024

suricata-qa commented Nov 5, 2024

inashivb Nov 7, 2024

inashivb Nov 7, 2024

inashivb Nov 7, 2024

inashivb Nov 7, 2024

inashivb Nov 7, 2024

catenacyber commented Nov 28, 2024

Flow timeout timing/v14 #12084

Are you sure you want to change the base?

Flow timeout timing/v14 #12084

Conversation

victorjulien commented Nov 4, 2024

codecov bot commented Nov 4, 2024 • edited Loading

Codecov Report

suricata-qa commented Nov 4, 2024

victorjulien commented Nov 4, 2024

inashivb commented Nov 5, 2024

suricata-qa commented Nov 5, 2024

inashivb Nov 7, 2024

Choose a reason for hiding this comment

inashivb Nov 7, 2024

Choose a reason for hiding this comment

inashivb Nov 7, 2024

Choose a reason for hiding this comment

inashivb Nov 7, 2024

Choose a reason for hiding this comment

inashivb Nov 7, 2024

Choose a reason for hiding this comment

catenacyber commented Nov 28, 2024

codecov bot commented Nov 4, 2024 •

edited

Loading