Merge remote-tracking branch 'origin/topic/seth/radius-script-refactor'

* origin/topic/seth/radius-script-refactor:
  Rework the RADIUS base script.

CHANGES

@@ -1,4 +1,13 @@
 
+2.5-70 | 2017-02-20 00:20:02 -0500
+
+  * Rework the RADIUS base script.
+
+    Fixes BIT-1769 which improves logging behavior when replies aren't 
+    seen.  Also added a `framed_addr` field to indicate if the radius 
+    server is hinting at an address for the client and a `ttl` field to
+    show how quickly the server is responding. (Seth Hall)
+
 2.5-68 | 2017-02-18 13:59:05 -0500
 
   * Refactored base krb scripts. (Seth Hall)

VERSION

@@ -1 +1 @@
-2.5-68
+2.5-70

scripts/base/protocols/radius/main.bro

@@ -10,117 +10,138 @@ export {
 
 	type Info: record {
 		## Timestamp for when the event happened.
-		ts		: time    &log;
+		ts           : time     &log;
 		## Unique ID for the connection.
-		uid		: string  &log;
+		uid          : string   &log;
 		## The connection's 4-tuple of endpoint addresses/ports.
-		id		: conn_id &log;
+		id           : conn_id  &log;
 		## The username, if present.
-		username	: string &log &optional;
+		username     : string   &log &optional;
 		## MAC address, if present.
-		mac		: string &log &optional;
-		## Remote IP address, if present.
-		remote_ip       : addr &log &optional;
+		mac          : string   &log &optional;
+		## The address given to the network access server, if
+		## present.  This is only a hint from the RADIUS server
+		## and the network access server is not required to honor 
+		## the address.
+		framed_addr  : addr     &log &optional;
+		## Remote IP address, if present.  This is collected
+		## from the Tunnel-Client-Endpoint attribute.
+		remote_ip    : addr     &log &optional;
 		## Connect info, if present.
-		connect_info	: string &log &optional;
+		connect_info : string   &log &optional;
+		## Reply message from the server challenge. This is 
+		## frequently shown to the user authenticating.
+		reply_msg    : string   &log &optional;
 		## Successful or failed authentication.
-		result		: string &log &optional;
-		## Whether this has already been logged and can be ignored.
-		logged		: bool &optional;
+		result       : string   &log &optional;
+		## The duration between the first request and
+		## either the "Access-Accept" message or an error.
+		## If the field is empty, it means that either
+		## the request or response was not seen.
+		ttl          : interval &log &optional;
 
+		## Whether this has already been logged and can be ignored.
+		logged       : bool     &default=F;
 	};
 
-	## The amount of time we wait for an authentication response before
-	## expiring it.
-	const expiration_interval = 10secs &redef;
-
-	## Logs an authentication attempt if we didn't see a response in time.
-	##
-	## t: A table of Info records.
-	##
-	## idx: The index of the connection$radius table corresponding to the
-	##      radius authentication about to expire.
-	##
-	## Returns: 0secs, which when this function is used as an
-	##          :bro:attr:`&expire_func`, indicates to remove the element at
-	##          *idx* immediately.
-	global expire: function(t: table[count] of Info, idx: count): interval;
-
 	## Event that can be handled to access the RADIUS record as it is sent on
-	## to the loggin framework.
+	## to the logging framework.
 	global log_radius: event(rec: Info);
 }
 
 redef record connection += {
-	radius: table[count] of Info &optional &write_expire=expiration_interval &expire_func=expire;
+	radius: Info &optional;
 };
 
 const ports = { 1812/udp };
+redef likely_server_ports += { ports };
 
 event bro_init() &priority=5
 	{
 	Log::create_stream(RADIUS::LOG, [$columns=Info, $ev=log_radius, $path="radius"]);
 	Analyzer::register_for_ports(Analyzer::ANALYZER_RADIUS, ports);
 	}
 
-event radius_message(c: connection, result: RADIUS::Message)
+event radius_message(c: connection, result: RADIUS::Message) &priority=5
 	{
-	local info: Info;
-
-	if ( c?$radius && result$trans_id in c$radius )
-		info = c$radius[result$trans_id];
-	else
+	if ( ! c?$radius )
 		{
-		c$radius = table();
-		info$ts  = network_time();
-		info$uid = c$uid;
-		info$id  = c$id;
+		c$radius = Info($ts  = network_time(),
+		                $uid = c$uid,
+		                $id  = c$id);
 		}
 
-	switch ( RADIUS::msg_types[result$code] ) {
+	switch ( RADIUS::msg_types[result$code] )
+		{
 		case "Access-Request":
-			if ( result?$attributes ) {
+			if ( result?$attributes )
+				{
 				# User-Name
-				if ( ! info?$username && 1 in result$attributes )
-					info$username = result$attributes[1][0];
+				if ( ! c$radius?$username && 1 in result$attributes )
+					c$radius$username = result$attributes[1][0];
 
 				# Calling-Station-Id (we expect this to be a MAC)
-				if ( ! info?$mac && 31 in result$attributes )
-					info$mac = normalize_mac(result$attributes[31][0]);
+				if ( ! c$radius?$mac && 31 in result$attributes )
+					c$radius$mac = normalize_mac(result$attributes[31][0]);
 
 				# Tunnel-Client-EndPoint (useful for VPNs)
-				if ( ! info?$remote_ip && 66 in result$attributes )
-					info$remote_ip = to_addr(result$attributes[66][0]);
+				if ( ! c$radius?$remote_ip && 66 in result$attributes )
+					c$radius$remote_ip = to_addr(result$attributes[66][0]);
 
 				# Connect-Info
-				if ( ! info?$connect_info && 77 in result$attributes )
-					info$connect_info = result$attributes[77][0];
-			}
+				if ( ! c$radius?$connect_info && 77 in result$attributes )
+					c$radius$connect_info = result$attributes[77][0];
+				}
+			break;
+
+		case "Access-Challenge":
+			if ( result?$attributes )
+				{
+				# Framed-IP-Address
+				if ( ! c$radius?$framed_addr && 8 in result$attributes )
+					c$radius$framed_addr = raw_bytes_to_v4_addr(result$attributes[8][0]);
 
+				if ( ! c$radius?$reply_msg && 18 in result$attributes )
+					c$radius$reply_msg = result$attributes[18][0];
+				}
 			break;
 
 		case "Access-Accept":
-			info$result = "success";
+			c$radius$result = "success";
 			break;
 
 		case "Access-Reject":
-			info$result = "failed";
+			c$radius$result = "failed";
 			break;
+
+		# TODO: Support RADIUS accounting. (add port 1813/udp above too)
+		#case "Accounting-Request":
+		#	break;
+		#
+		#case "Accounting-Response":
+		#	break;
+		}
 	}
 
-	if ( info?$result && ! info?$logged )
+event radius_message(c: connection, result: RADIUS::Message) &priority=-5
+	{
+	if ( c$radius?$result )
 		{
-		info$logged = T;
-		Log::write(RADIUS::LOG, info);
-		}
+		local ttl = network_time() - c$radius$ts;
+		if ( ttl != 0secs )
+			c$radius$ttl = ttl;
 
-	c$radius[result$trans_id] = info;
-	}
+		Log::write(RADIUS::LOG, c$radius);
 
+		delete c$radius;
+		}
+	}
 
-function expire(t: table[count] of Info, idx: count): interval
-	 {
-	 t[idx]$result = "unknown";
-	 Log::write(RADIUS::LOG, t[idx]);
-	 return 0secs;
-	 }
+event connection_state_remove(c: connection) &priority=-5
+	{
+	if ( c?$radius && ! c$radius$logged )
+		{
+		c$radius$result = "unknown";
+		Log::write(RADIUS::LOG, c$radius);
+		}
+	}

testing/btest/Baseline/scripts.base.protocols.radius.auth/radius.log

@@ -3,8 +3,8 @@
 #empty_field	(empty)
 #unset_field	-
 #path	radius
-#open	2016-07-13-16-16-47
-#fields	ts	uid	id.orig_h	id.orig_p	id.resp_h	id.resp_p	username	mac	remote_ip	connect_info	result
-#types	time	string	addr	port	addr	port	string	string	addr	string	string
-1217631137.916736	CHhAvVGS1DHFjwGM9	10.0.0.1	1645	10.0.0.100	1812	John.McGuirk	00:14:22:e9:54:5e	-	-	success
-#close	2016-07-13-16-16-47
+#open	2017-02-20-04-53-55
+#fields	ts	uid	id.orig_h	id.orig_p	id.resp_h	id.resp_p	username	mac	framed_addr	remote_ip	connect_info	reply_msg	result	ttl
+#types	time	string	addr	port	addr	port	string	string	addr	addr	string	string	string	interval
+1217631137.872968	CHhAvVGS1DHFjwGM9	10.0.0.1	1645	10.0.0.100	1812	John.McGuirk	00:14:22:e9:54:5e	255.255.255.254	-	-	Hello, %u	success	0.043882
+#close	2017-02-20-04-53-55

testing/btest/Baseline/scripts.base.protocols.radius.radius-multiple-attempts/radius.log

@@ -0,0 +1,16 @@
+#separator \x09
+#set_separator	,
+#empty_field	(empty)
+#unset_field	-
+#path	radius
+#open	2017-02-20-04-56-31
+#fields	ts	uid	id.orig_h	id.orig_p	id.resp_h	id.resp_p	username	mac	framed_addr	remote_ip	connect_info	reply_msg	result	ttl
+#types	time	string	addr	port	addr	port	string	string	addr	addr	string	string	string	interval
+1440447766.440305	CHhAvVGS1DHFjwGM9	127.0.0.1	53031	127.0.0.1	1812	steve	-	172.16.3.33	-	-	-	failed	1.005906
+1440447839.947454	ClEkJM2Vm5giqnMf4h	127.0.0.1	65443	127.0.0.1	1812	steve	-	172.16.3.33	-	-	-	success	0.000779
+1440447848.196115	C4J4Th3PJpwUYZZ6gc	127.0.0.1	57717	127.0.0.1	1812	steve	-	-	-	-	-	success	0.000275
+1440447860.613743	CtPZjS20MLrsMUOJi2	127.0.0.1	64691	127.0.0.1	1812	steve	-	-	-	-	-	success	0.000273
+1440447880.931272	CUM0KZ3MLUfNB0cl11	127.0.0.1	52178	127.0.0.1	1812	steve	-	-	-	-	-	failed	1.001459
+1440447904.122012	CmES5u32sYpV7JYN	127.0.0.1	62956	127.0.0.1	1812	steve	-	-	-	-	-	unknown	-
+1440448190.335333	CP5puj4I8PtEU4qzYg	127.0.0.1	53127	127.0.0.1	1812	steve	-	-	-	-	-	success	0.000517
+#close	2017-02-20-04-56-31

testing/btest/scripts/base/protocols/radius/radius-multiple-attempts.test

@@ -0,0 +1,6 @@
+# Test a more complicated radius session with multiple attempts
+
+# @TEST-EXEC: bro -b -C -r $TRACES/radius/radius_localhost.pcapng %INPUT
+# @TEST-EXEC: btest-diff radius.log
+
+@load base/protocols/radius