Fixes to SMB file handling and logging.

There were some cases where the log would be missing a field
or data wouldn't get sent to file analysis.  At least some of
this is fixed now and I get confused a bit less when I look
at the logs now.

Also, I made the default handling "FILE" so that things like
FILE_UNKNOWN wouldn't show up in the logs so regularly.  It's
technically correct that way, but it doesn't look good and it's
correct as FILE often enough that it make sense to make it the
default I think.
This commit is contained in:
Seth Hall 2016-04-01 09:43:13 -04:00
parent 5721db4be7
commit e2dfaf8a5b
8 changed files with 82 additions and 76 deletions

View file

@ -12,14 +12,15 @@ export {
function get_file_handle(c: connection, is_orig: bool): string
{
print "getting a file handle";
print c$smb_state$current_cmd$referenced_file;
if ( ! (c$smb_state?$current_file &&
((c$smb_state$current_file?$name && c$smb_state$current_file$name !in pipe_names) ||
(c$smb_state$current_file?$name ||
c$smb_state$current_file?$path)) )
{
# TODO - figure out what are the cases where this happens.
return "";
}
local current_file = c$smb_state$current_file;
local path_name = current_file?$path ? current_file$path : "";
local file_name = current_file?$name ? current_file$name : "";

View file

@ -16,7 +16,8 @@ export {
FILE_WRITE,
FILE_OPEN,
FILE_CLOSE,
FILE_UNKNOWN,
FILE_DELETE,
FILE_RENAME,
PIPE_READ,
PIPE_WRITE,
@ -91,7 +92,8 @@ export {
service : string &log &optional;
## File system of the tree.
native_file_system : string &log &optional;
## If this is SMB2, a share type will be included.
## If this is SMB2, a share type will be included. For SMB1,
## the type of share will be deduced and included as well.
share_type : string &log &default="UNKNOWN";
};
@ -137,7 +139,7 @@ export {
tree_service : string &log &optional;
## If the command referenced a file, store it here.
referenced_file : FileInfo &optional;
referenced_file : FileInfo &log &optional;
## If the command referenced a tree, store it here.
referenced_tree : TreeInfo &optional;
};
@ -226,7 +228,8 @@ function set_current_file(smb_state: State, file_id: count)
smb_state$fid_map[file_id]$fid = file_id;
}
smb_state$current_file = smb_state$fid_map[file_id];
smb_state$current_cmd$referenced_file = smb_state$fid_map[file_id];
smb_state$current_file = smb_state$current_cmd$referenced_file;
}
function write_file_log(state: State)

View file

@ -31,8 +31,7 @@ event smb1_message(c: connection, hdr: SMB1::Header, is_orig: bool) &priority=5
if ( tid !in smb_state$tid_map )
{
local tmp_tree: SMB::TreeInfo = [$uid=c$uid, $id=c$id];
smb_state$tid_map[tid] = tmp_tree;
smb_state$tid_map[tid] = SMB::TreeInfo($uid=c$uid, $id=c$id);
}
smb_state$current_tree = smb_state$tid_map[tid];
if ( smb_state$current_tree?$path )
@ -47,9 +46,9 @@ event smb1_message(c: connection, hdr: SMB1::Header, is_orig: bool) &priority=5
if ( mid !in smb_state$pending_cmds )
{
local tmp_cmd: SMB::CmdInfo = [$ts=network_time(), $uid=c$uid, $id=c$id, $version="SMB1", $command = SMB1::commands[hdr$command]];
local tmp_cmd = SMB::CmdInfo($ts=network_time(), $uid=c$uid, $id=c$id, $version="SMB1", $command = SMB1::commands[hdr$command]);
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);
tmp_cmd$referenced_file = tmp_file;
tmp_cmd$referenced_tree = smb_state$current_tree;
@ -63,7 +62,7 @@ event smb1_message(c: connection, hdr: SMB1::Header, is_orig: bool) &priority=5
smb_state$current_cmd$rtt = network_time() - smb_state$current_cmd$ts;
smb_state$current_cmd$status = SMB::statuses[hdr$status]$id;
}
}
}
event smb1_message(c: connection, hdr: SMB1::Header, is_orig: bool) &priority=-5
{
@ -116,7 +115,7 @@ event smb1_negotiate_response(c: connection, hdr: SMB1::Header, response: SMB1::
event smb1_tree_connect_andx_request(c: connection, hdr: SMB1::Header, path: string, service: string) &priority=5
{
local tmp_tree: SMB::TreeInfo = [$ts=network_time(), $uid=c$uid, $id=c$id, $path=path, $service=service];
local tmp_tree = SMB::TreeInfo($ts=network_time(), $uid=c$uid, $id=c$id, $path=path, $service=service);
c$smb_state$current_cmd$referenced_tree = tmp_tree;
c$smb_state$current_cmd$argument = path;
@ -125,9 +124,13 @@ event smb1_tree_connect_andx_request(c: connection, hdr: SMB1::Header, path: str
event smb1_tree_connect_andx_response(c: connection, hdr: SMB1::Header, service: string, native_file_system: string) &priority=5
{
c$smb_state$current_cmd$referenced_tree$service = service;
if ( service == "IPC" )
c$smb_state$current_cmd$referenced_tree$share_type = "PIPE";
c$smb_state$current_cmd$tree_service = service;
c$smb_state$current_cmd$referenced_tree$native_file_system = native_file_system;
if ( native_file_system != "" )
c$smb_state$current_cmd$referenced_tree$native_file_system = native_file_system;
c$smb_state$current_tree = c$smb_state$current_cmd$referenced_tree;
c$smb_state$tid_map[hdr$tid] = c$smb_state$current_tree;
@ -146,7 +149,7 @@ event smb1_tree_connect_andx_response(c: connection, hdr: SMB1::Header, service:
event smb1_nt_create_andx_request(c: connection, hdr: SMB1::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);
c$smb_state$current_cmd$referenced_file = tmp_file;
c$smb_state$current_cmd$referenced_file$name = name;

View file

@ -22,29 +22,36 @@ event smb2_message(c: connection, hdr: SMB2::Header, is_orig: bool) &priority=5
local mid = hdr$message_id;
local sid = hdr$session_id;
if ( tid !in smb_state$tid_map )
{
local tmp_tree: SMB::TreeInfo = [$uid=c$uid, $id=c$id];
smb_state$tid_map[tid] = tmp_tree;
}
smb_state$current_tree = smb_state$tid_map[tid];
if ( mid !in smb_state$pending_cmds )
{
local tmp_cmd = SMB::CmdInfo($ts=network_time(), $uid=c$uid, $id=c$id, $version="SMB2", $command = SMB2::commands[hdr$command]);
local tmp_file = SMB::FileInfo($ts=network_time(), $uid=c$uid, $id=c$id);
if ( smb_state$current_tree?$path )
tmp_file$path = smb_state$current_tree$path;
local tmp_cmd = SMB::CmdInfo($ts=network_time(), $uid=c$uid, $id=c$id, $version="SMB2", $command = SMB2::commands[hdr$command]);
tmp_cmd$referenced_file = tmp_file;
tmp_cmd$referenced_tree = smb_state$current_tree;
smb_state$pending_cmds[mid] = tmp_cmd;
}
smb_state$current_cmd = smb_state$pending_cmds[mid];
if ( tid > 0 )
{
if ( smb_state$current_cmd?$referenced_tree )
{
smb_state$tid_map[tid] = smb_state$current_cmd$referenced_tree;
}
else if ( tid !in smb_state$tid_map )
{
local tmp_tree = SMB::TreeInfo($ts=network_time(), $uid=c$uid, $id=c$id);
smb_state$tid_map[tid] = tmp_tree;
}
smb_state$current_cmd$referenced_tree = smb_state$tid_map[tid];
}
else
{
smb_state$current_cmd$referenced_tree = SMB::TreeInfo($ts=network_time(), $uid=c$uid, $id=c$id);
}
smb_state$current_file = smb_state$current_cmd$referenced_file;
smb_state$current_tree = smb_state$current_cmd$referenced_tree;
if ( !is_orig )
{
smb_state$current_cmd$rtt = network_time() - smb_state$current_cmd$ts;
@ -99,16 +106,12 @@ event smb2_negotiate_response(c: connection, hdr: SMB2::Header, response: SMB2::
event smb2_tree_connect_request(c: connection, hdr: SMB2::Header, path: string) &priority=5
{
local tmp_tree = SMB::TreeInfo($ts=network_time(), $uid=c$uid, $id=c$id, $path=path);
c$smb_state$current_cmd$referenced_tree = tmp_tree;
c$smb_state$current_tree$path = path;
}
event smb2_tree_connect_response(c: connection, hdr: SMB2::Header, response: SMB2::TreeConnectResponse) &priority=5
{
c$smb_state$current_cmd$referenced_tree$share_type = SMB2::share_types[response$share_type];
c$smb_state$current_tree = c$smb_state$current_cmd$referenced_tree;
c$smb_state$tid_map[hdr$tree_id] = c$smb_state$current_tree;
c$smb_state$current_tree$share_type = SMB2::share_types[response$share_type];
}
event smb2_tree_connect_response(c: connection, hdr: SMB2::Header, response: SMB2::TreeConnectResponse) &priority=-5
@ -121,42 +124,43 @@ event smb2_create_request(c: connection, hdr: SMB2::Header, name: string) &prior
if ( name == "")
name = "<share_root>";
local tmp_file = SMB::FileInfo($ts=network_time(), $uid=c$uid, $id=c$id, $name=name);
c$smb_state$current_file$name = name;
switch ( c$smb_state$current_cmd$referenced_tree$share_type )
switch ( c$smb_state$current_tree$share_type )
{
case "DISK":
tmp_file$action = SMB::FILE_OPEN;
c$smb_state$current_file$action = SMB::FILE_OPEN;
break;
case "PIPE":
tmp_file$action = SMB::PIPE_OPEN;
c$smb_state$current_file$action = SMB::PIPE_OPEN;
break;
case "PRINT":
tmp_file$action = SMB::PRINT_OPEN;
c$smb_state$current_file$action = SMB::PRINT_OPEN;
break;
default:
tmp_file$action = SMB::UNKNOWN_OPEN;
#c$smb_state$current_file$action = SMB::UNKNOWN_OPEN;
c$smb_state$current_file$action = SMB::FILE_OPEN;
break;
}
c$smb_state$current_cmd$referenced_file = tmp_file;
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$fid = file_id$persistent+file_id$volatile;
c$smb_state$current_cmd$referenced_file$size = file_size;
c$smb_state$current_file$fid = file_id$persistent+file_id$volatile;
c$smb_state$current_file$size = file_size;
if ( c$smb_state$current_tree?$path )
c$smb_state$current_file$path = c$smb_state$current_tree$path;
# I'm seeing negative data from IPC tree transfers
if ( time_to_double(times$modified) > 0.0 )
c$smb_state$current_cmd$referenced_file$times = times;
c$smb_state$current_file$times = times;
# We can identify the file by its file id now so let's stick it
# in the file map.
c$smb_state$fid_map[file_id$persistent+file_id$volatile] = c$smb_state$current_cmd$referenced_file;
c$smb_state$fid_map[file_id$persistent+file_id$volatile] = c$smb_state$current_file;
c$smb_state$current_file = c$smb_state$fid_map[file_id$persistent+file_id$volatile];
SMB::write_file_log(c$smb_state);
}
@ -171,7 +175,7 @@ event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, o
{
SMB::set_current_file(c$smb_state, file_id$persistent+file_id$volatile);
switch ( c$smb_state$current_cmd$referenced_tree$share_type )
switch ( c$smb_state$current_tree$share_type )
{
case "DISK":
c$smb_state$current_file$action = SMB::FILE_READ;
@ -183,25 +187,21 @@ event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, o
c$smb_state$current_file$action = SMB::PRINT_READ;
break;
default:
c$smb_state$current_file$action = SMB::UNKNOWN_OPEN;
#c$smb_state$current_file$action = SMB::UNKNOWN_OPEN;
c$smb_state$current_file$action = SMB::FILE_OPEN;
break;
}
}
event smb2_read_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=-5
{
if ( c$smb_state$current_tree?$path && !c$smb_state$current_file?$path )
c$smb_state$current_file$path = c$smb_state$current_tree$path;
# TODO - Why is this commented out?
#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 )
switch ( c$smb_state$current_tree$share_type )
{
case "DISK":
c$smb_state$current_file$action = SMB::FILE_WRITE;
@ -213,25 +213,21 @@ event smb2_write_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID,
c$smb_state$current_file$action = SMB::PRINT_WRITE;
break;
default:
c$smb_state$current_file$action = SMB::UNKNOWN_WRITE;
#c$smb_state$current_file$action = SMB::UNKNOWN_WRITE;
c$smb_state$current_file$action = SMB::FILE_WRITE;
break;
}
}
event smb2_write_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID, offset: count, length: count) &priority=-5
{
if ( c$smb_state$current_tree?$path && ! c$smb_state$current_file?$path )
c$smb_state$current_file$path = c$smb_state$current_tree$path;
# TODO - Why is this commented out?
#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 )
switch ( c$smb_state$current_tree$share_type )
{
case "DISK":
c$smb_state$current_file$action = SMB::FILE_CLOSE;
@ -243,7 +239,8 @@ event smb2_close_request(c: connection, hdr: SMB2::Header, file_id: SMB2::GUID)
c$smb_state$current_file$action = SMB::PRINT_CLOSE;
break;
default:
c$smb_state$current_file$action = SMB::UNKNOWN_CLOSE;
#c$smb_state$current_file$action = SMB::UNKNOWN_CLOSE;
c$smb_state$current_file$action = SMB::FILE_CLOSE;
break;
}
}

View file

@ -13,7 +13,7 @@ SMB_Analyzer::SMB_Analyzer(Connection *conn)
interp = new binpac::SMB::SMB_Conn(this);
AddSupportAnalyzer(new Contents_SMB(conn, true));
AddSupportAnalyzer(new Contents_SMB(conn, false));
}
}
SMB_Analyzer::~SMB_Analyzer()
{

View file

@ -3,11 +3,12 @@
#empty_field (empty)
#unset_field -
#path smb_files
#open 2016-03-09-09-45-49
#open 2016-04-01-13-33-43
#fields ts uid id.orig_h id.orig_p id.resp_h id.resp_p fuid action path name size times.modified times.accessed times.created times.changed
#types time string addr port addr port string enum string string count time time time time
1403194573.483536 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::UNKNOWN_OPEN - <share_root> 0 1403193605.830790 1403193605.830790 1403193211.405449 1403193605.830790
1403194573.484701 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::UNKNOWN_OPEN - Test 0 1403193632.973276 1403193632.973276 1403193604.628965 1403193632.973276
1403194574.150293 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::UNKNOWN_OPEN - Test\\2009-12 Payroll.xlsx 25940 1403148950.000000 1403193623.046524 1403148950.000000 1403193632.973276
1403194574.232191 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 FyxE5A19VJyangfN54 SMB::UNKNOWN_OPEN - Test\\2009-12 Payroll.xlsx 25940 1403148950.000000 1403193623.046524 1403148950.000000 1403193632.973276
#close 2016-03-09-09-45-49
1403194573.483536 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::FILE_OPEN - <share_root> 0 1403193605.830790 1403193605.830790 1403193211.405449 1403193605.830790
1403194573.484701 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::FILE_OPEN - Test 0 1403193632.973276 1403193632.973276 1403193604.628965 1403193632.973276
1403194574.150293 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 - SMB::FILE_OPEN - Test\\2009-12 Payroll.xlsx 25940 1403148950.000000 1403193623.046524 1403148950.000000 1403193632.973276
1403194574.232191 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 FyxE5A19VJyangfN54 SMB::FILE_OPEN - Test\\2009-12 Payroll.xlsx 25940 1403148950.000000 1403193623.046524 1403148950.000000 1403193632.973276
1403194574.232191 CXWv6p3arKYeMETxOg 192.168.1.78 55770 192.168.1.53 445 FyxE5A19VJyangfN54 SMB::FILE_CLOSE - Test\\2009-12 Payroll.xlsx 25940 1403148950.000000 1403193623.046524 1403148950.000000 1403193632.973276
#close 2016-04-01-13-33-43

View file

@ -3,12 +3,12 @@
#empty_field (empty)
#unset_field -
#path smb_files
#open 2016-03-09-09-45-59
#open 2016-04-01-08-31-01
#fields ts uid id.orig_h id.orig_p id.resp_h id.resp_p fuid action path name size times.modified times.accessed times.created times.changed
#types time string addr port addr port string enum string string count time time time time
1323202695.377459 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN - <share_root> 8192 1323202604.512058 1323202604.512058 1322343963.945297 1323202604.512058
1323202695.432192 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN - WP_SMBPlugin.pdf 0 1323202695.427034 1323202695.427034 1323202695.427034 1323202695.427034
1323202695.377459 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN \\\\10.0.0.12\\smb2 <share_root> 8192 1323202604.512058 1323202604.512058 1322343963.945297 1323202604.512058
1323202695.432192 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN \\\\10.0.0.12\\smb2 WP_SMBPlugin.pdf 0 1323202695.427034 1323202695.427034 1323202695.427034 1323202695.427034
1323202695.432192 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 FUU9mc3Ub5uZdcqg1d SMB::FILE_CLOSE \\\\10.0.0.12\\smb2 WP_SMBPlugin.pdf 0 1323202695.427034 1323202695.427034 1323202695.427034 1323202695.427034
1323202695.599914 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN - <share_root> 8192 1323202695.427034 1323202695.427034 1322343963.945297 1323202695.427034
1323202695.599914 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_OPEN \\\\10.0.0.12\\smb2 <share_root> 8192 1323202695.427034 1323202695.427034 1322343963.945297 1323202695.427034
1323202695.599914 CXWv6p3arKYeMETxOg 10.0.0.11 49208 10.0.0.12 445 - SMB::FILE_CLOSE \\\\10.0.0.12\\smb2 <share_root> 8192 1323202695.427034 1323202695.427034 1322343963.945297 1323202695.427034
#close 2016-03-09-09-45-59
#close 2016-04-01-08-31-01

View file

@ -6,3 +6,4 @@
# @TEST-EXEC: test ! -f weird.log
@load base/protocols/smb