Fix handling of HTTP 1xx response codes (addresses #411).

Changed the parser to not treat 1xx response codes as a final answer
to an unanswered request -- a later response is still expected.

The scripting layer will also not finish a request-reply pair when
seeing 1xx's, instead it logs both the 1xx and final response messages
with associated information of the current request as they're seen.

scripts/base/protocols/http/main.bro

@@ -163,8 +163,12 @@ event http_reply(c: connection, version: string, code: count, reason: string) &p
 		local s: State;
 		c$http_state = s;
 		}
-	
+
-	++c$http_state$current_response;
+	# If the last response was an informational 1xx, we're still expecting
+	# the real response to the request, so don't create a new Info record yet.
+	if ( c$http_state$current_response !in c$http_state$pending ||
+	  c$http_state$pending[c$http_state$current_response]$status_code/100 != 1 )
+		++c$http_state$current_response;
 	set_state(c, F, F);
 	
 	c$http$status_code = code;
@@ -246,7 +250,10 @@ event http_message_done(c: connection, is_orig: bool, stat: http_message_stat) &
 	if ( ! is_orig )
 		{
 		Log::write(HTTP::LOG, c$http);
-		delete c$http_state$pending[c$http_state$current_response];
+		# If the response was an informational 1xx, we're still expecting
+		# the real response later, so we'll continue using the same record
+		if ( c$http$status_code/100 != 1 )
+			delete c$http_state$pending[c$http_state$current_response];
 		}
 	}
 

src/HTTP.cc

@@ -1305,7 +1305,9 @@ void HTTP_Analyzer::ReplyMade(const int interrupted, const char* msg)
 	if ( reply_message )
 		reply_message->Done(interrupted, msg);
 
-	if ( ! unanswered_requests.empty() )
+	// 1xx replies do not indicate the final response to a request,
+	// so don't pop an unanswered request in that case.
+	if ( reply_code/100 != 1 && ! unanswered_requests.empty() )
 		{
 		Unref(unanswered_requests.front());
 		unanswered_requests.pop();

testing/btest/Baseline/scripts.base.protocols.http.100-continue/http.log

@@ -0,0 +1,6 @@
+#separator \x09
+#path	http
+#fields	ts	uid	id.orig_h	id.orig_p	id.resp_h	id.resp_p	method	host	uri	referrer	user_agent	request_body_len	request_body_interrupted	response_body_len	response_body_interrupted	status_code	status_msg	filename	tags	username	password	proxied	mime_type	md5	extraction_file
+#types	time	string	addr	port	addr	port	string	string	string	string	string	count	bool	count	bool	count	string	string	table	string	string	table	string	string	file
+1237440095.634312	UWkUyAuUGXf	192.168.3.103	54102	128.146.216.51	80	POST	www.osu.edu	/	-	curl/7.17.1 (i386-apple-darwin8.11.1) libcurl/7.17.1 zlib/1.2.3	-	F	0	F	100	Continue	-	-	-	-	-	-	-	-
+1237440095.634312	UWkUyAuUGXf	192.168.3.103	54102	128.146.216.51	80	POST	www.osu.edu	/	-	curl/7.17.1 (i386-apple-darwin8.11.1) libcurl/7.17.1 zlib/1.2.3	2001	F	60731	F	200	OK	-	-	-	-	-	text/html	-	-

testing/btest/scripts/base/protocols/http/100-continue.bro

@@ -0,0 +1,12 @@
+# This tests that the HTTP analyzer does not generate an unmatched_HTTP_reply
+# weird as a result of seeing both a 1xx response and the real response to
+# a given request.  The http scripts should also be able log such replies
+# in a way that correlates the final response with the request.
+#
+# @TEST-EXEC: bro -r $TRACES/http-100-continue.trace %INPUT
+# @TEST-EXEC: grep -q unmatched_HTTP_reply weird.log && exit 1 || exit 0
+# @TEST-EXEC: btest-diff http.log
+
+# The base analysis scripts are loaded by default.
+#@load base/protocols/http
+