Fix the issue with transaction ID reuse in a single DNS connection.

- Each transaction ID within a connection is now maintained as
   a queue of DNS::Info logging records.

 - New function added to the queue.bro script to support
   peeking at the new gettable item in the queue without removing it.

scripts/base/protocols/dns/main.bro

@@ -1,6 +1,7 @@
 ##! Base DNS analysis script which tracks and logs DNS queries along with
 ##! their responses.
 
+@load base/utils/queue
 @load ./consts
 
 module DNS;
@@ -73,19 +74,6 @@ export {
 		total_replies: count           &optional;
 	};
 
-	## A record type which tracks the status of DNS queries for a given
-	## :bro:type:`connection`.
-	type State: record {
-		## Indexed by query id, returns Info record corresponding to
-		## query/response which haven't completed yet.
-		pending: table[count] of Info &optional;
-
-		## This is the list of DNS responses that have completed based on the
-		## number of responses declared and the number received.  The contents
-		## of the set are transaction IDs.
-		finished_answers: set[count] &optional;
-	};
-
 	## An event that can be handled to access the :bro:type:`DNS::Info`
 	## record as it is sent to the logging framework.
 	global log_dns: event(rec: Info);
@@ -102,8 +90,32 @@ export {
 	##
 	## reply: The specific response information according to RR type/class.
 	global do_reply: event(c: connection, msg: dns_msg, ans: dns_answer, reply: string);
+
+	## A hook that is called whenever a session is being set.
+	## This can be used if additional initialization logic needs to happen
+	## when creating a new session value.
+	##
+	## c: The connection involved in the new session
+	## 
+	## msg: The DNS message header information.
+	##
+	## is_query: Indicator for if this is being called for a query or a response.
+	global set_session: hook(c: connection, msg: dns_msg, is_query: bool);
 }
 
+## A record type which tracks the status of DNS queries for a given
+## :bro:type:`connection`.
+type State: record {
+	## Indexed by query id, returns Info record corresponding to
+	## query/response which haven't completed yet.
+	pending: table[count] of Queue::Queue;
+
+	## This is the list of DNS responses that have completed based on the
+	## number of responses declared and the number received.  The contents
+	## of the set are transaction IDs.
+	finished_answers: set[count];
+};
+
 redef record connection += {
 	dns:       Info  &optional;
 	dns_state: State &optional;
@@ -134,14 +146,6 @@ event bro_init() &priority=5
 
 function new_session(c: connection, trans_id: count): Info
 	{
-	if ( ! c?$dns_state )
-		{
-		local state: State;
-		state$pending=table();
-		state$finished_answers=set();
-		c$dns_state = state;
-		}
-
 	local info: Info;
 	info$ts       = network_time();
 	info$id       = c$id;
@@ -151,18 +155,37 @@ function new_session(c: connection, trans_id: count): Info
 	return info;
 	}
 
-function set_session(c: connection, msg: dns_msg, is_query: bool)
+hook set_session(c: connection, msg: dns_msg, is_query: bool) &priority=5
 	{
-	if ( ! c?$dns_state || msg$id !in c$dns_state$pending )
+	if ( ! c?$dns_state )
 		{
-		c$dns_state$pending[msg$id] = new_session(c, msg$id);
+		local state: State;
-		# Try deleting this transaction id from the set of finished answers.
+		c$dns_state = state;
-		# Sometimes hosts will reuse ports and transaction ids and this should
-		# be considered to be a legit scenario (although bad practice).
-		delete c$dns_state$finished_answers[msg$id];
 		}
 
-	c$dns = c$dns_state$pending[msg$id];
+	if ( msg$id !in c$dns_state$pending )
+		c$dns_state$pending[msg$id] = Queue::init();
+	
+	local info: Info;
+	# If this is either a query or this is the reply but
+	# no Info records are in the queue (we missed the query?)
+	# we need to create an Info record and put it in the queue.  
+	if ( is_query ||
+	     Queue::len(c$dns_state$pending[msg$id]) == 0 )
+		{
+		info = new_session(c, msg$id);
+		Queue::put(c$dns_state$pending[msg$id], info);
+		}
+
+	if ( is_query )
+		# If this is a query, assign the newly created info variable
+		# so that the world looks correct to anything else handling
+		# this query.
+		c$dns = info;
+	else
+		# Peek at the next item in the queue for this trans_id and 
+		# assign it to c$dns since this is a response.
+		c$dns = Queue::peek(c$dns_state$pending[msg$id]);
 
 	if ( ! is_query )
 		{
@@ -190,7 +213,7 @@ function set_session(c: connection, msg: dns_msg, is_query: bool)
 
 event dns_message(c: connection, is_orig: bool, msg: dns_msg, len: count) &priority=5
 	{
-	set_session(c, msg, is_orig);
+	hook set_session(c, msg, is_orig);
 	}
 
 event DNS::do_reply(c: connection, msg: dns_msg, ans: dns_answer, reply: string) &priority=5
@@ -200,9 +223,6 @@ event DNS::do_reply(c: connection, msg: dns_msg, ans: dns_answer, reply: string)
 		c$dns$AA    = msg$AA;
 		c$dns$RA    = msg$RA;
 
-		if ( msg$id in c$dns_state$finished_answers )
-			event conn_weird("dns_reply_seen_after_done", c, "");
-
 		if ( reply != "" )
 			{
 			if ( ! c$dns?$answers )
@@ -217,7 +237,6 @@ event DNS::do_reply(c: connection, msg: dns_msg, ans: dns_answer, reply: string)
 		if ( c$dns?$answers && c$dns?$total_answers &&
 		     |c$dns$answers| == c$dns$total_answers )
 			{
-			add c$dns_state$finished_answers[c$dns$trans_id];
 			# Indicate this request/reply pair is ready to be logged.
 			c$dns$ready = T;
 			}
@@ -230,7 +249,7 @@ event DNS::do_reply(c: connection, msg: dns_msg, ans: dns_answer, reply: string)
 		{
 		Log::write(DNS::LOG, c$dns);
 		# This record is logged and no longer pending.
-		delete c$dns_state$pending[c$dns$trans_id];
+		Queue::get(c$dns_state$pending[c$dns$trans_id]);
 		delete c$dns;
 		}
 	}
@@ -243,6 +262,7 @@ event dns_request(c: connection, msg: dns_msg, query: string, qtype: count, qcla
 	c$dns$qclass_name = classes[qclass];
 	c$dns$qtype       = qtype;
 	c$dns$qtype_name  = query_types[qtype];
+	c$dns$Z           = msg$Z;
 
 	# Decode netbios name queries
 	# Note: I'm ignoring the name type for now.  Not sure if this should be
@@ -250,8 +270,6 @@ event dns_request(c: connection, msg: dns_msg, query: string, qtype: count, qcla
 	if ( c$id$resp_p == 137/udp )
 		query = decode_netbios_name(query);
 	c$dns$query = query;
-
-	c$dns$Z = msg$Z;
 	}
 
 event dns_A_reply(c: connection, msg: dns_msg, ans: dns_answer, a: addr) &priority=5
@@ -339,6 +357,13 @@ event connection_state_remove(c: connection) &priority=-5
 	# If Bro is expiring state, we should go ahead and log all unlogged
 	# request/response pairs now.
 	for ( trans_id in c$dns_state$pending )
-		Log::write(DNS::LOG, c$dns_state$pending[trans_id]);
+		{
+		local infos: vector of Info;
+		Queue::get_vector(c$dns_state$pending[trans_id], infos);
+		for ( i in infos )
+			{
+			Log::write(DNS::LOG, infos[i]);
+			}
+		}
 	}
 

scripts/base/utils/queue.bro

@@ -19,22 +19,29 @@ export {
 	## s: A :bro:record:`Settings` record configuring the queue.
 	##
 	## Returns: An opaque queue record.
-	global init:       function(s: Settings): Queue;
+	global init:       function(s: Settings &default=[]): Queue;
 
-	## Put a string onto the beginning of a queue.
+	## Put a value onto the beginning of a queue.
 	##
 	## q: The queue to put the value into.
 	##
 	## val: The value to insert into the queue.
 	global put:       function(q: Queue, val: any);
 
-	## Get a string from the end of a queue.
+	## Get a value from the end of a queue.
 	##
-	## q: The queue to get the string from.
+	## q: The queue to get the value from.
 	##
 	## Returns: The value gotten from the queue.
 	global get:        function(q: Queue): any;
 
+	## Peek at the value at the end of the queue without removing it.
+	##
+	## q: The queue to get the value from.
+	##
+	## Returns: The value at the end of the queue.
+	global peek:      function(q: Queue): any;
+
 	## Merge two queue's together.  If any settings are applied
 	## to the queues, the settings from q1 are used for the new
 	## merged queue.
@@ -103,6 +110,11 @@ function get(q: Queue): any
 	return ret;
 	}
 
+function peek(q: Queue): any
+	{
+	return q$vals[q$bottom];
+	}
+
 function merge(q1: Queue, q2: Queue): Queue
 	{
 	local ret = init(q1$settings);

testing/btest/Baseline/core.ipv6-frag/dns.log

@@ -3,9 +3,10 @@
 #empty_field	(empty)
 #unset_field	-
 #path	dns
-#open	2012-10-05-17-47-27
+#open	2013-05-17-14-28-17
 #fields	ts	uid	id.orig_h	id.orig_p	id.resp_h	id.resp_p	proto	trans_id	query	qclass	qclass_name	qtype	qtype_name	rcode	rcode_name	AA	TC	RD	RA	Z	answers	TTLs	rejected
 #types	time	string	addr	port	addr	port	enum	count	string	count	string	count	string	count	string	bool	bool	bool	bool	count	vector[string]	vector[interval]	bool
 1331084278.438444	UWkUyAuUGXf	2001:470:1f11:81f:d138:5f55:6d4:1fe2	51850	2607:f740:b::f93	53	udp	3903	txtpadding_323.n1.netalyzr.icsi.berkeley.edu	1	C_INTERNET	16	TXT	0	NOERROR	T	F	T	F	0	This TXT record should be ignored	1.000000	F
 1331084293.592245	arKYeMETxOg	2001:470:1f11:81f:d138:5f55:6d4:1fe2	51851	2607:f740:b::f93	53	udp	40849	txtpadding_3230.n1.netalyzr.icsi.berkeley.edu	1	C_INTERNET	16	TXT	0	NOERROR	T	F	T	F	0	This TXT record should be ignored	1.000000	F
-#close	2012-10-05-17-47-27
+1331084298.593081	arKYeMETxOg	2001:470:1f11:81f:d138:5f55:6d4:1fe2	51851	2607:f740:b::f93	53	udp	40849	txtpadding_3230.n1.netalyzr.icsi.berkeley.edu	1	C_INTERNET	16	TXT	-	-	F	F	T	F	0	-	-	F
+#close	2013-05-17-14-28-17