Merge remote-tracking branch 'origin/topic/jazoff/avoid-redundant-inactivity-timers'

- Changed the logic significantly to just guarantee there's only ever a
  single inactivity timer per connection

- Updated language.expire_subnet btest which is unduly sensitive to
  timer-related changes

* origin/topic/jazoff/avoid-redundant-inactivity-timers:
  avoid scheduling redundant inactivity timers

CHANGES

@@ -1,4 +1,11 @@
 
+3.2.0-dev.461 | 2020-05-04 17:08:46 -0700
+
+  * Avoid scheduling multiple inactivity timers (Justin Azoff and Jon Siwek, Corelight)
+
+    Also updated language.expire_subnet btest which is unduly sensitive to
+    timer-related changes
+
 3.2.0-dev.459 | 2020-05-01 17:46:20 -0700
 
   * Extend CI config to cover building with libmaxminddb support (Jon Siwek, Corelight)

VERSION

@@ -1 +1 @@
-3.2.0-dev.459
+3.2.0-dev.461

src/Conn.cc

@@ -282,10 +282,6 @@ void Connection::DeleteTimer(double /* t */)
 	}
 
 void Connection::InactivityTimer(double t)
-	{
-	// If the inactivity_timeout is zero, there has been an active
-	// timeout once, but it's disabled now. We do nothing then.
-	if ( inactivity_timeout )
 	{
 	if ( last_time + inactivity_timeout <= t )
 		{
@@ -295,9 +291,7 @@ void Connection::InactivityTimer(double t)
 		}
 	else
 		ADD_TIMER(&Connection::InactivityTimer,
-					last_time + inactivity_timeout, 0,
+		          last_time + inactivity_timeout, 0, TIMER_CONN_INACTIVITY);
-					TIMER_CONN_INACTIVITY);
-		}
 	}
 
 void Connection::RemoveConnectionTimer(double t)
@@ -308,8 +302,17 @@ void Connection::RemoveConnectionTimer(double t)
 
 void Connection::SetInactivityTimeout(double timeout)
 	{
-	// We add a new inactivity timer even if there already is one.  When
+	if ( timeout == inactivity_timeout )
-	// it fires, we always use the current value to check for inactivity.
+		return;
+
+	// First cancel and remove any existing inactivity timer.
+	for ( const auto& timer : timers )
+		if ( timer->Type() == TIMER_CONN_INACTIVITY )
+			{
+			timer_mgr->Cancel(timer);
+			break;
+			}
+
 	if ( timeout )
 		ADD_TIMER(&Connection::InactivityTimer,
 				last_time + timeout, 0, TIMER_CONN_INACTIVITY);

testing/btest/Baseline/language.expire_subnet/expire-nets-output

@@ -0,0 +1,5 @@
+Expired Subnet: 192.168.4.0/24 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Subnet: 192.168.1.0/24 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Subnet: 192.168.0.0/16 --> zero at 15.0 secs 150.0 msecs 681.018829 usecs
+Expired Subnet: 192.168.3.0/24 --> three at 15.0 secs 150.0 msecs 681.018829 usecs
+Expired Subnet: 192.168.2.0/24 --> two at 15.0 secs 150.0 msecs 681.018829 usecs

testing/btest/Baseline/language.expire_subnet/expire-nums-output

@@ -0,0 +1,5 @@
+Expired Num: 4 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Num: 1 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Num: 0 --> zero at 8.0 secs 835.0 msecs 30.078888 usecs
+Expired Num: 2 --> two at 15.0 secs 150.0 msecs 681.018829 usecs
+Expired Num: 3 --> three at 15.0 secs 150.0 msecs 681.018829 usecs

testing/btest/Baseline/language.expire_subnet/output

@@ -14,14 +14,3 @@ Time: 0 secs
 Accessed table nums: two; three
 Accessed table nets: two; zero, three
 Time: 7.0 secs 518.0 msecs 828.15361 usecs
-
-Expired Num: 4 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Num: 1 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Num: 0 --> zero at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Subnet: 192.168.4.0/24 --> four at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Subnet: 192.168.1.0/24 --> one at 8.0 secs 835.0 msecs 30.078888 usecs
-Expired Num: 2 --> two at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Num: 3 --> three at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Subnet: 192.168.0.0/16 --> zero at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Subnet: 192.168.3.0/24 --> three at 15.0 secs 150.0 msecs 681.018829 usecs
-Expired Subnet: 192.168.2.0/24 --> two at 15.0 secs 150.0 msecs 681.018829 usecs

testing/btest/language/expire_subnet.test

@@ -1,8 +1,15 @@
 # @TEST-EXEC: zeek -C -r $TRACES/var-services-std-ports.trace %INPUT >output
 # @TEST-EXEC: btest-diff output
+# @TEST-EXEC: btest-diff expire-nums-output
+# @TEST-EXEC: btest-diff expire-nets-output
 
 redef table_expire_interval = 1sec;
 
+# The order of &expire_func calls between different tables does not have
+# well-defined or expected order, so put their output in different files.
+global expire_nums_out = open("expire-nums-output");
+global expire_nets_out = open("expire-nets-output");
+
 global start_time: time;
 
 function time_past(): interval
@@ -12,13 +19,13 @@ function time_past(): interval
 
 function expire_nums(tbl: table[count] of string, idx: count): interval
 	{
-	print fmt("Expired Num: %s --> %s at %s", idx, tbl[idx], time_past());
+	print expire_nums_out, fmt("Expired Num: %s --> %s at %s", idx, tbl[idx], time_past());
 	return 0sec;
 	}
 
 function expire_nets(tbl: table[subnet] of string, idx: subnet): interval
 	{
-	print fmt("Expired Subnet: %s --> %s at %s", idx, tbl[idx], time_past());
+	print expire_nets_out, fmt("Expired Subnet: %s --> %s at %s", idx, tbl[idx], time_past());
 	return 0sec;
 	}
 
@@ -50,7 +57,6 @@ function execute_test()
 	print fmt("Accessed table nums: %s; %s", num_a, num_b);
 	print fmt("Accessed table nets: %s; %s", net_a, nets_b);
 	print fmt("Time: %s", time_past());
-	print "";
 	}
 
 ### Events ###