A lot of changes to SMB analyzer.

- Add beginning of infrastructure for pipe support in SMB2.
 - Improve identification of non-file tree mappings.
 - Stop passing pipe data to the file analysis framework.
 - Reduce log volume in smb_files.log by watching for repeated
   files being seen so that you don't end up with nearly
   the exact same log line over and over and over.
 - Lots of little whitespace and indentation changes.

scripts/base/protocols/smb/main.bro

@@ -10,19 +10,42 @@ export {
 	};
 	
 	## Abstracted actions for SMB file actions.
-	type FileAction: enum {
+	type Action: enum {
 		FILE_READ,
 		FILE_WRITE,
 		FILE_OPEN,
 		FILE_CLOSE,
 		FILE_UNKNOWN,
+
+		PIPE_READ,
+		PIPE_WRITE,
+		PIPE_OPEN,
+		PIPE_CLOSE,
+
+		PRINT_READ,
+		PRINT_WRITE,
+		PRINT_OPEN,
+		PRINT_CLOSE,
+
+		UNKNOWN_READ,
+		UNKNOWN_WRITE,
+		UNKNOWN_OPEN,
+		UNKNOWN_CLOSE,
 	};
 
 	## The file actions which are logged.
-	const logged_file_actions: set[FileAction] = {
+	const logged_file_actions: set[Action] = {
 		FILE_OPEN,
 		FILE_READ,
 		FILE_WRITE,
+
+		PIPE_OPEN,
+		PIPE_CLOSE,
+
+		PRINT_OPEN,
+		PRINT_CLOSE,
+
+		UNKNOWN_OPEN,
 	} &redef;
 
 	## The server response statuses which are *not* logged.
@@ -42,7 +65,7 @@ export {
 		fuid			: string  &log &optional;
 		
 		## Action this log record represents.
-		action			: FileAction  &log &default=FILE_UNKNOWN;
+		action			: Action  &log &optional;
 		## Path pulled from the tree this file was transferred to or from.
 		path			: string  &log &optional;
 		## Filename if one was seen.
@@ -69,7 +92,7 @@ export {
 		## File system of the tree.
 		native_file_system  : string &log &optional;
 		## If this is SMB2, a share type will be included.
-		share_type			: string &log &optional;
+		share_type          : string &log &default="UNKNOWN";
 	};
 
 	## This record is for the smb_cmd.log
@@ -130,6 +153,11 @@ export {
 		uid_map      : table[count] of string    &optional;
 		## Pipe map to retrieve UUID based on the file ID of a pipe.
 		pipe_map     : table[count] of string    &optional;
+
+		## A set of recent files to avoid logging the same
+		## files over and over in the smb files log.
+		## This only applies to files seen in a single connection.
+		recent_files : set[string] &default=string_set() &read_expire=3min;
 	};
 	
 	redef record connection += {
@@ -154,7 +182,7 @@ export {
 	const set_current_file: function(smb_state: State, file_id: count) &redef;
 
 	## This is an internally used function.
-	const write_file_log: function(f: FileInfo) &redef;
+	const write_file_log: function(state: State) &redef;
 }
 
 redef record FileInfo += {
@@ -191,12 +219,33 @@ function set_current_file(smb_state: State, file_id: count)
 	smb_state$current_file = smb_state$fid_map[file_id];
 	}
 
-function write_file_log(f: FileInfo)
+function write_file_log(state: State)
 	{
+	local f = state$current_file;
 	if ( f?$name && 
 	     f$name !in pipe_names &&
 	     f$action in logged_file_actions )
 		{
+		# Everything in this if statement is to avoid overlogging
+		# of the same data from a single connection based on recently
+		# seen files in the SMB::State $recent_files field.
+		if ( f?$times )
+			{
+			local file_ident = cat(f$action,
+			                       f?$fuid ? f$fuid : "",
+			                       f?$name ? f$name : "",
+			                       f?$path ? f$path : "",
+			                       f$size,
+			                       f$times);
+			if ( file_ident in state$recent_files )
+				{
+				# We've already seen this file and don't want to log it again.
+				return;
+				}
+			else
+				add state$recent_files[file_ident];
+			}
+		
 		Log::write(FILES_LOG, f);
 		}
 	}
@@ -211,7 +260,7 @@ event file_state_remove(f: fa_file) &priority=-5
 		local c = f$conns[id];
 		if ( c?$smb_state && c$smb_state?$current_file)
 			{
-			write_file_log(c$smb_state$current_file);
+			write_file_log(c$smb_state);
 			}
 		return;
 		}

scripts/base/protocols/smb/pipe.bro

@@ -6,25 +6,18 @@ export {
 	};
 
 	type ATSvcInfo: record {
-	## Time of the request
+		ts       : time    &log; ##< Time of the request
-	ts	: time &log;
+		uid      : string  &log; ##< UID of the connection
-	## UID of the connection
+		id       : conn_id &log; ##< Connection info
-	uid	: string &log;
+		command  : string  &log; ##< Command (add, enum, delete, etc.)
-	## Connection info
+		arg      : string  &log; ##< Argument
-	id	: conn_id &log;
+		server   : string  &log; ##< Server the command was issued to
-	## Command (add, enum, delete, etc.)
+		result   : string  &log &optional; ##< Result of the command
-	command : string &log;
-	## Argument
-	arg	: string &log;
-	## Server the command was issued to
-	server	: string &log;
-	## Result of the command
-	result	: string &log &optional;
 	};
 }
 
-redef record connection += {
+redef record SMB::State += {
-	smb_atsvc: ATSvcInfo &optional;
+	pipe_atsvc: ATSvcInfo &optional;
 };
 
 event bro_init() &priority=5
@@ -32,28 +25,28 @@ event bro_init() &priority=5
 	Log::create_stream(ATSVC_LOG, [$columns=ATSvcInfo]);
 	}
 
-event smb_atsvc_job_add(c: connection, server: string, job: string)
+event smb_atsvc_job_add(c: connection, server: string, job: string) &priority=5
 	{
-	local info: ATSvcInfo;
+	local info = ATSvcInfo($ts=network_time(),
-	info$ts = network_time();
+	                       $uid = c$uid,
-	info$uid = c$uid;
+	                       $id = c$id,
-	info$id = c$id;
+	                       $command = "Add job",
-	info$command = "Add job";
+	                       $arg = job,
-	info$arg = job;
+	                       $server = server);
-	info$server = server;
+	c$smb_state$pipe_atsvc = info;
-
-	c$smb_atsvc = info;
 	}
 
-event smb_atsvc_job_id(c: connection, id: count, status: count)
+event smb_atsvc_job_id(c: connection, id: count, status: count) &priority=5
 	{
-	if ( !c?$smb_atsvc )
+	if ( c$smb_state?$pipe_atsvc )
-		return;
+		c$smb_state$pipe_atsvc$result = (status==0) ? "success" : "failed";
-	if ( status == 0 )
+	}
-		c$smb_atsvc$result = "success";
+
-	else
+event smb_atsvc_job_id(c: connection, id: count, status: count) &priority=-5
-		c$smb_atsvc$result = "failed";
+	{
-
+	if ( c$smb_state?$pipe_atsvc )
-	Log::write(ATSVC_LOG, c$smb_atsvc);
+		{
-	delete c$smb_atsvc;
+		Log::write(ATSVC_LOG, c$smb_state$pipe_atsvc);
+		delete c$smb_state$pipe_atsvc;
+		}
 	}

scripts/base/protocols/smb/smb1-main.bro

@@ -168,7 +168,7 @@ event smb1_nt_create_andx_response(c: connection, hdr: SMB1::Header, file_id: co
 	
 	c$smb_state$current_file = c$smb_state$fid_map[file_id];
 	
-	SMB::write_file_log(c$smb_state$current_file);
+	SMB::write_file_log(c$smb_state);
 	}
 
 event smb1_read_andx_request(c: connection, hdr: SMB1::Header, file_id: count, offset: count, length: count) &priority=5
@@ -237,7 +237,7 @@ event smb1_close_request(c: connection, hdr: SMB1::Header, file_id: count) &prio
 		
 		delete c$smb_state$fid_map[file_id];
 
-		SMB::write_file_log(fl);
+		SMB::write_file_log(c$smb_state);
 		}
 	else
 		{

scripts/base/protocols/smb/smb2-main.bro

@@ -114,16 +114,29 @@ event smb2_tree_connect_response(c: connection, hdr: SMB2::Header, response: SMB
 
 event smb2_create_request(c: connection, hdr: SMB2::Header, name: string) &priority=5
 	{
-	local tmp_file: SMB::FileInfo = [$ts=network_time(), $uid=c$uid, $id=c$id];
+	local tmp_file: SMB::FileInfo = [$ts=network_time(), $uid=c$uid, $id=c$id, $name=name];
+
+	switch ( c$smb_state$current_cmd$referenced_tree$share_type )
+		{
+		case "DISK":
+			tmp_file$action = SMB::FILE_OPEN;
+			break;
+		case "PIPE":
+			tmp_file$action = SMB::PIPE_OPEN;
+			break;
+		case "PRINT":
+			tmp_file$action = SMB::PRINT_OPEN;
+			break;
+		default:
+			tmp_file$action = SMB::UNKNOWN_OPEN;
+			break;
+		}
 	c$smb_state$current_cmd$referenced_file = tmp_file;
-	c$smb_state$current_cmd$referenced_file$name = name;
-	c$smb_state$current_cmd$referenced_file$action = SMB::FILE_OPEN;
 	c$smb_state$current_file = c$smb_state$current_cmd$referenced_file;
 	}
 
 event smb2_create_response(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, file_size: count, times: SMB::MACTimes, attrs: SMB2::FileAttrs) &priority=5
 	{
-	c$smb_state$current_cmd$referenced_file$action = SMB::FILE_OPEN;
 	c$smb_state$current_cmd$referenced_file$fid = file_id$persistent+file_id$volatile;
 	c$smb_state$current_cmd$referenced_file$size = file_size;
 
@@ -137,7 +150,7 @@ event smb2_create_response(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID
 	
 	c$smb_state$current_file = c$smb_state$fid_map[file_id$persistent+file_id$volatile];
 
-	SMB::write_file_log(c$smb_state$current_file);
+	SMB::write_file_log(c$smb_state);
 	}
 
 event smb2_set_info_request(c: connection, hdr: SMB2::Header, request: SMB2::SetInfoRequest) &priority=5
@@ -148,7 +161,22 @@ event smb2_set_info_request(c: connection, hdr: SMB2::Header, request: SMB2::Set
 event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=5
 	{
 	SMB::set_current_file(c$smb_state, file_id$persistent+file_id$volatile);
+
+	switch ( c$smb_state$current_cmd$referenced_tree$share_type )
+		{
+		case "DISK":
 			c$smb_state$current_file$action = SMB::FILE_READ;
+			break;
+		case "PIPE":
+			c$smb_state$current_file$action = SMB::PIPE_READ;
+			break;
+		case "PRINT":
+			c$smb_state$current_file$action = SMB::PRINT_READ;
+			break;
+		default:
+			c$smb_state$current_file$action = SMB::UNKNOWN_OPEN;
+			break;
+		}
 	}
 
 event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=-5
@@ -157,13 +185,28 @@ event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, o
 		c$smb_state$current_file$path = c$smb_state$current_tree$path;
 
 	# TODO - Why is this commented out?
-	#write_file_log(c$smb_state$current_file);
+	#write_file_log(c$smb_state);
 	}
 
 event smb2_write_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=5
 	{
 	SMB::set_current_file(c$smb_state, file_id$persistent+file_id$volatile);
+
+	switch ( c$smb_state$current_cmd$referenced_tree$share_type )
+		{
+		case "DISK":
 			c$smb_state$current_file$action = SMB::FILE_WRITE;
+			break;
+		case "PIPE":
+			c$smb_state$current_file$action = SMB::PIPE_WRITE;
+			break;
+		case "PRINT":
+			c$smb_state$current_file$action = SMB::PRINT_WRITE;
+			break;
+		default:
+			c$smb_state$current_file$action = SMB::UNKNOWN_WRITE;
+			break;
+		}
 	}
 
 event smb2_write_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=-5
@@ -172,13 +215,28 @@ event smb2_write_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID,
 		c$smb_state$current_file$path = c$smb_state$current_tree$path;
 
 	# TODO - Why is this commented out?
-	#write_file_log(c$smb_state$current_file);
+	#write_file_log(c$smb_state);
 	}
 
 event smb2_close_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID) &priority=5
 	{
 	SMB::set_current_file(c$smb_state, file_id$persistent+file_id$volatile);
+
+	switch ( c$smb_state$current_cmd$referenced_tree$share_type )
+		{
+		case "DISK":
 			c$smb_state$current_file$action = SMB::FILE_CLOSE;
+			break;
+		case "PIPE":
+			c$smb_state$current_file$action = SMB::PIPE_CLOSE;
+			break;
+		case "PRINT":
+			c$smb_state$current_file$action = SMB::PRINT_CLOSE;
+			break;
+		default:
+			c$smb_state$current_file$action = SMB::UNKNOWN_CLOSE;
+			break;
+		}
 	}
 
 event smb2_close_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID) &priority=-5
@@ -191,7 +249,7 @@ event smb2_close_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID)
 			fl$path = c$smb_state$current_tree$path;
 		delete c$smb_state$fid_map[file_id$persistent+file_id$volatile];
 
-		SMB::write_file_log(fl);
+		SMB::write_file_log(c$smb_state);
 		}
 	else
 		{

src/analyzer/protocol/smb/SMB.cc

@@ -161,11 +161,6 @@ void Contents_SMB::DeliverStream(int len, const u_char* data, bool orig)
 		case WAIT_FOR_HDR:
 			{
 			// We have the 4 bytes header now
-
-			// This does not abide the spec, but we've seen it 
-			// in real traffic.
-			if (data[1] > 2)
-				Conn()->Weird(fmt("NetBIOS session flags > 2: %d", data[1]));
 			msg_len = 0;
 			msg_type = data[0];
 			for ( int i = 1; i < 4; i++)

src/analyzer/protocol/smb/smb-pipe.pac

@@ -8,6 +8,9 @@
 %}
 
 refine connection SMB_Conn += {
+	%member{
+		map<uint16,bool> tree_is_pipe_map;
+	%}
 
 	function get_tree_is_pipe(tree_id: uint16): bool
 		%{
@@ -22,10 +25,6 @@ refine connection SMB_Conn += {
 		return true;
 		%}
 
-	%member{
-		map<uint16,bool> tree_is_pipe_map;
-	%}
-
 	function proc_smb_pipe_message(val: SMB_Pipe_message, header: SMB_Header): bool
 		%{
 		switch ( ${val.rpc_header.PTYPE} ) {
@@ -84,12 +83,10 @@ type SMB_Pipe_message(header: SMB_Header, byte_count: uint16) = record {
 } &byteorder = littleendian;
 
 type SMB_RAP_message(unicode: bool, byte_count: uint16) = record { 
-
 	rap_code   : uint16;
 	param_desc : SMB_string(unicode, offsetof(param_desc));
 	data_desc  : SMB_string(unicode, offsetof(data_desc));
 	data       : bytestring &restofdata; 
-
 } &byteorder = littleendian;
 
 type AT_SVC_Request(unicode: bool, opnum: uint8) = record {

src/analyzer/protocol/smb/smb1-com-transaction.pac

@@ -10,8 +10,11 @@ refine connection SMB_Conn += {
 	function proc_smb1_transaction_request(header: SMB_Header, val: SMB1_transaction_request): bool
 		%{
 		if ( smb1_transaction_request )
-			BifEvent::generate_smb1_transaction_request(bro_analyzer(), bro_analyzer()->Conn(), BuildHeaderVal(header), \
+			BifEvent::generate_smb1_transaction_request(bro_analyzer(), 
-														 smb_string2stringval(${val.name}), ${val.sub_cmd});
+			                                            bro_analyzer()->Conn(),
+			                                            BuildHeaderVal(header),
+			                                            smb_string2stringval(${val.name}), 
+			                                            ${val.sub_cmd});
 		return true;
 		%}
 
@@ -24,8 +27,11 @@ refine connection SMB_Conn += {
 	function proc_smb1_transaction_setup(header: SMB_Header, val: SMB1_transaction_setup): bool
 		%{
 		if ( smb1_transaction_setup )
-			BifEvent::generate_smb1_transaction_setup(bro_analyzer(), bro_analyzer()->Conn(), BuildHeaderVal(header), \
+			BifEvent::generate_smb1_transaction_setup(bro_analyzer(), 
-													  ${val.op_code}, ${val.file_id});
+			                                          bro_analyzer()->Conn(),
+			                                          BuildHeaderVal(header),
+			                                          ${val.op_code},
+			                                          ${val.file_id});
 		return true;
 		%}
 
@@ -38,8 +44,8 @@ type SMB1_transaction_data(header: SMB_Header, count: uint16, sub_cmd: uint16,
 #	SMB_MAILSLOT_LANMAN -> lanman   : SMB_MailSlot_message(header.unicode, count);
 #	SMB_RAP             -> rap      : SMB_Pipe_message(header.unicode, count);
 	SMB_PIPE            -> pipe     : SMB_Pipe_message(header, count);
-	SMB_UNKNOWN         -> unknown  : bytestring &restofdata;
+	SMB_UNKNOWN         -> unknown  : bytestring &restofdata &transient;
-#	default             -> data     : bytestring &restofdata;
+	default             -> data     : bytestring &restofdata &transient;
 };
 
 type SMB1_transaction_setup(header: SMB_Header) = record {
@@ -79,7 +85,6 @@ type SMB1_transaction_request(header: SMB_Header) = record {
 	proc : bool = $context.connection.proc_smb1_transaction_request(header, this);
 };
 
-
 type SMB1_transaction_response(header: SMB_Header) = record {
 	word_count          : uint8;
 	total_param_count   : uint16;
@@ -99,10 +104,8 @@ type SMB1_transaction_response(header: SMB_Header) = record {
 	pad0                : padding to param_offset - SMB_Header_length;
 	parameters          : bytestring &length = param_count;
 	pad1                : padding to data_offset - SMB_Header_length;
-	handle_response	    : case $context.connection.get_tree_is_pipe(header.tid) of {
+	data                : SMB1_transaction_data(header, data_count, 0, is_tree_a_pipe ? SMB_PIPE : SMB_UNKNOWN)[data_count>0 ? 1 : 0];
-		true -> pipe_data : SMB1_transaction_data(header, data_count, 0, SMB_PIPE);
-		false -> unk_data : SMB1_transaction_data(header, data_count, 0, SMB_UNKNOWN);
-	};
 } &let {
 	proc : bool = $context.connection.proc_smb1_transaction_response(header, this);
+	is_tree_a_pipe: bool = $context.connection.get_tree_is_pipe(header.tid);
 };

src/analyzer/protocol/smb/smb1-com-tree-connect-andx.pac

@@ -13,7 +13,7 @@ refine connection SMB_Conn += {
 
 	function proc_smb1_tree_connect_andx_response(header: SMB_Header, val: SMB1_tree_connect_andx_response): bool
 		%{
-		set_tree_is_pipe(${header.tid}, strcmp((const char*) smb_string2stringval(${val.service})->Bytes(), "IPC") == 0);
+		set_tree_is_pipe(${header.tid}, strncmp((const char*) smb_string2stringval(${val.service})->Bytes(), "IPC", 3) == 0);
 		if ( smb1_tree_connect_andx_response )
 			BifEvent::generate_smb1_tree_connect_andx_response(bro_analyzer(),
 			                                                   bro_analyzer()->Conn(),

src/analyzer/protocol/smb/smb2-com-read.pac

@@ -25,7 +25,7 @@ refine connection SMB_Conn += {
 
 	function proc_smb2_read_response(h: SMB2_Header, val: SMB2_read_response) : bool
 		%{
-		if ( ${val.data_len} > 0 )
+		if ( ! ${val.is_pipe} && ${val.data_len} > 0 )
 			{
 			uint64 offset = smb2_read_offsets[${h.message_id}];
 			smb2_read_offsets.erase(${h.message_id});
@@ -67,7 +67,13 @@ type SMB2_read_response(header: SMB2_Header) = record {
 	data_remaining    : uint32;
 	reserved          : uint32;
 	pad               : padding to data_offset - header.head_length;
-	data              : bytestring &length=data_len;
+	pipe_file_switch  : case is_pipe of {
+		# The SMB_Pipe_message type doesn't support smb2 pipes yet.
+		#true  -> pipe_data : SMB_Pipe_message(header, data_len) &length=data_len;
+		false -> data      : bytestring &length=data_len;
+	};
 } &let {
+	is_pipe: bool = $context.connection.get_tree_is_pipe(header.tree_id);
+
 	proc: bool = $context.connection.proc_smb2_read_response(header, this);
 };

src/analyzer/protocol/smb/smb2-com-tree-connect.pac

@@ -13,10 +13,11 @@ refine connection SMB_Conn += {
 
 	function proc_smb2_tree_connect_response(header: SMB2_Header, val: SMB2_tree_connect_response): bool
 		%{
+		set_tree_is_pipe(${header.tree_id}, ${val.share_type} == SMB2_SHARE_TYPE_PIPE);
+
 		if ( smb2_tree_connect_response )
 			{
 			RecordVal* resp = new RecordVal(BifType::Record::SMB2::TreeConnectResponse);
-
 			resp->Assign(0, new Val(${val.share_type}, TYPE_COUNT));
 
 			BifEvent::generate_smb2_tree_connect_response(bro_analyzer(),

src/analyzer/protocol/smb/smb2-com-write.pac

@@ -12,7 +12,7 @@ refine connection SMB_Conn += {
 			                                      ${val.data_len});
 			}
 
-		if ( ${val.data}.length() > 0 )
+		if ( ! ${val.is_pipe} && ${val.data}.length() > 0 )
 			{
 			file_mgr->DataIn(${val.data}.begin(), ${val.data_len}, ${val.offset},
 			                 bro_analyzer()->GetAnalyzerTag(),
@@ -43,8 +43,14 @@ type SMB2_write_request(header: SMB2_Header) = record {
 	channel_info_len    : uint16; # ignore
 	flags               : uint32;
 	pad                 : padding to data_offset - header.head_length;
-	data              : bytestring &length=data_len;
+	pipe_file_switch    : case is_pipe of {
+		# The SMB_Pipe_message type doesn't support smb2 pipes yet.
+		#true  -> pipe_data : SMB_Pipe_message(header, data_len) &length=data_len;
+		default -> data      : bytestring &length=data_len;
+	};
 } &let {
+	is_pipe: bool = $context.connection.get_tree_is_pipe(header.tree_id);
+
 	proc : bool = $context.connection.proc_smb2_write_request(header, this);
 };
 

src/analyzer/protocol/smb/smb2-protocol.pac

@@ -23,6 +23,12 @@ enum smb2_commands {
 	SMB2_OPLOCK_BREAK       = 18,
 };
 
+enum smb2_share_types {
+	SMB2_SHARE_TYPE_DISK = 0x01,
+	SMB2_SHARE_TYPE_PIPE = 0x02,
+	SMB2_SHARE_TYPE_PRINT = 0x03,
+};
+
 type SMB2_PDU(is_orig: bool) = record {
 	header     : SMB2_Header(is_orig);
 	message    : case header.status of {