Merge branch 'topic/dopheide/known-services' of https://github.com/dopheide-esnet/zeek

- Updated the logic significantly: still filters out ICMP from being
  considered an active service (like before) and adds a new
  "Known::service_udp_requires_response" option (defaults to true) for
  whether to require UDP server response before being considered an
  active service.

* 'topic/dopheide/known-services' of https://github.com/dopheide-esnet/zeek:
  Log services with unknown protocols

CHANGES

@@ -1,4 +1,21 @@
 
+3.2.0-dev.573 | 2020-05-29 17:13:36 -0700
+
+  * Add "Known::service_udp_requires_response" option (Jon Siwek, Corelight)
+
+    Determines whether to require UDP server response before considering
+    an active service to log in known_services.log.
+
+  * Update known-services.zeek logic for "active" TCP services (Jon Siwek, Corelight)
+
+    To better check for only endpoints that either have observed a TCP handshake
+    or else assumed to have done one in the past (partial connections, missed
+    the handshake, but now see data/acks from server)
+
+  * Log services with unknown protocol names (Michael Dopheide)
+
+  * GH-989: Fix crash on using some deprecated environment variables (Jon Siwek, Corelight)
+
 3.2.0-dev.570 | 2020-05-28 14:49:10 -0700
 
   * Add negotiation flags parameter to some RDP events (Anthony Kasza, Corelight)

VERSION

@@ -1 +1 @@
-3.2.0-dev.570
+3.2.0-dev.573

doc

@@ -1 +1 @@
-Subproject commit 098ae808d176ba487fbb9ff57899abb6882ae0d8
+Subproject commit 89ed0528fda6f4648ccdd5402a21a1573c7fa3b6

scripts/policy/protocols/conn/known-services.zeek

@@ -1,7 +1,10 @@
-##! This script logs and tracks services.  In the case of this script, a service
+##! This script logs and tracks active services.  For this script, an active
-##! is defined as an IP address and port which has responded to and fully 
+##! service is defined as an IP address and port of a server for which
-##! completed a TCP handshake with another host.  If a protocol is detected
+##! a TCP handshake (SYN+ACK) is observed, assumed to have been done in the
-##! during the session, the protocol will also be logged.
+##! past (started seeing packets mid-connection, but the server is actively
+##! sending data), or sent at least one UDP packet.
+##! If a protocol name is found/known for service, that will be logged,
+##! but services whose names can't be determined are also still logged.
 
 @load base/utils/directions-and-hosts
 @load base/frameworks/cluster
@@ -32,7 +35,10 @@ export {
 	## with keys uniformly distributed over proxy nodes in cluster
 	## operation.
 	const use_service_store = T &redef;
-	
+
+	## Require UDP server to respond before considering it an "active service".
+	option service_udp_requires_response = T;
+
 	## The hosts whose services should be tracked and logged.
 	## See :zeek:type:`Host` for possible choices.
 	option service_tracking = LOCAL_HOSTS;
@@ -206,10 +212,37 @@ event service_info_commit(info: ServicesInfo)
 	event known_service_add(info);
 	}
 
+function has_active_service(c: connection): bool
+	{
+	local proto = get_port_transport_proto(c$id$resp_p);
+
+	switch ( proto ) {
+	case tcp:
+		# Not a service unless the TCP server did a handshake (SYN+ACK).
+		if ( c$resp$state == TCP_ESTABLISHED ||
+			 c$resp$state == TCP_CLOSED ||
+			 c$resp$state == TCP_PARTIAL ||
+		     /h/ in c$history )
+			return T;
+		return F;
+	case udp:
+		# Not a service unless UDP server has sent something (or the option
+		# to not care about that is set).
+		if ( Known::service_udp_requires_response )
+			return c$resp$state == UDP_ACTIVE;
+		return T;
+	case icmp:
+		# ICMP is not considered a service.
+		return F;
+	default:
+		# Unknown/other transport not considered a service for now.
+		return F;
+	}
+	}
+
 function known_services_done(c: connection)
 	{
 	local id = c$id;
-	c$known_services_done = T;
 
 	if ( ! addr_matches_host(id$resp_h, service_tracking) )
 		return;
@@ -225,6 +258,15 @@ function known_services_done(c: connection)
 			return;
 		}
 
+	if ( ! has_active_service(c) )
+		# If we're here during a protocol_confirmation, it's still premature
+		# to declare there's an actual service, so wait for the connection
+		# removal to check again (to get more timely reporting we'd have
+		# schedule some recurring event to poll for handshake/activity).
+		return;
+
+	c$known_services_done = T;
+
 	# Drop services starting with "-" (confirmed-but-then-violated protocol)
 	local tempservs: set[string];
 		for (s in c$service)
@@ -239,11 +281,15 @@ function known_services_done(c: connection)
 	# If no protocol was detected, wait a short time before attempting to log
 	# in case a protocol is detected on another connection.
 	if ( |c$service| == 0 )
+		{
+		# Add an empty service so the service loops will work later
+		add info$service[""];
 		schedule 5min { service_info_commit(info) };
-	else 
+		}
+	else
 		event service_info_commit(info);
 	}
-	
+
 event protocol_confirmation(c: connection, atype: Analyzer::Tag, aid: count) &priority=-5
 	{
 	known_services_done(c);
@@ -255,12 +301,6 @@ event successful_connection_remove(c: connection) &priority=-5
 	if ( c$known_services_done )
 		return;
 
-	if ( c$resp$state != TCP_ESTABLISHED && c$resp$state != UDP_ACTIVE )
-		return;
-
-	if ( |c$service| == 0 )
-		return;
-
 	known_services_done(c);
 	}
 

testing/btest/Baseline/core.tunnels.teredo-known-services/known_services.log

@@ -0,0 +1,10 @@
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	known_services
+#open	2020-05-29-22-30-46
+#fields	ts	host	port_num	port_proto	service
+#types	time	addr	port	enum	set[string]
+1258567272.036419	192.168.1.1	53	udp	DNS
+#close	2020-05-29-22-30-46

testing/btest/Baseline/scripts.policy.protocols.conn.known-services/knownservices-all.log

@@ -3,13 +3,14 @@
 #empty_field	(empty)
 #unset_field	-
 #path	known_services
-#open	2019-06-15-23-46-49
+#open	2020-05-29-22-23-37
 #fields	ts	host	port_num	port_proto	service
 #types	time	addr	port	enum	set[string]
 1308930691.089263	172.16.238.131	22	tcp	SSH
 1308930694.550308	172.16.238.131	80	tcp	HTTP
+1308930703.068148	172.16.238.2	53	udp	DNS
 1308930716.462556	74.125.225.81	80	tcp	HTTP
 1308930718.361665	172.16.238.131	21	tcp	FTP
 1308930726.889624	141.142.192.39	22	tcp	SSH
-1308930727.236071	69.50.219.51	123	udp	NTP
+1308930728.226254	69.50.219.51	123	udp	NTP
-#close	2019-06-15-23-46-49
+#close	2020-05-29-22-23-37

testing/btest/Baseline/scripts.policy.protocols.conn.known-services/knownservices-local.log

@@ -3,10 +3,11 @@
 #empty_field	(empty)
 #unset_field	-
 #path	known_services
-#open	2014-04-01-23-16-20
+#open	2020-05-29-22-19-22
 #fields	ts	host	port_num	port_proto	service
 #types	time	addr	port	enum	set[string]
-1308930691.049431	172.16.238.131	22	tcp	SSH
+1308930691.089263	172.16.238.131	22	tcp	SSH
 1308930694.550308	172.16.238.131	80	tcp	HTTP
+1308930703.068148	172.16.238.2	53	udp	DNS
 1308930718.361665	172.16.238.131	21	tcp	FTP
-#close	2014-04-01-23-16-20
+#close	2020-05-29-22-19-22

testing/btest/core/tunnels/teredo-known-services.test

@@ -1,7 +1,4 @@
 # @TEST-EXEC: zeek -r $TRACES/tunnels/false-teredo.pcap base/frameworks/dpd base/protocols/tunnels protocols/conn/known-services Tunnel::delay_teredo_confirmation=T "Site::local_nets+={192.168.1.0/24}"
-# @TEST-EXEC: test ! -e known_services.log
+# @TEST-EXEC: btest-diff known_services.log
-
-# The first case using Tunnel::delay_teredo_confirmation=T doesn't produce
-# a known services.log since valid Teredo encapsulations from both endpoints
-# of a connection is never witnessed and a protocol_confirmation never issued.
 
+# Expect known_services.log to NOT indicate any service using teredo.

testing/external/commit-hash.zeek-testing

@@ -1 +1 @@
-b8d14675f2662204995b924cdd8ffa9454e0a06c
+f035d3c81512c5a6faf1175ff60148a1b40bfed4

testing/external/commit-hash.zeek-testing-private

@@ -1 +1 @@
-8ef47172c5f941a1b6fed0941899a5fbd2df06db
+74de2295ad7bb95b9a4b8c11bc3be1234eb31c00