diff --git a/scripts/base/frameworks/logging/main.zeek b/scripts/base/frameworks/logging/main.zeek index fdaa764db8..0a745fd538 100644 --- a/scripts/base/frameworks/logging/main.zeek +++ b/scripts/base/frameworks/logging/main.zeek @@ -298,10 +298,25 @@ export { config: table[string] of string &default=table(); }; - ## A hook type to implement filtering policy. Hook handlers can - ## veto the logging of a record or alter it prior to logging. - ## You can pass arbitrary state into the hook via the - ## filter argument and its config member. + ## A hook type to implement filtering policy. Hook handlers run + ## on each log record. They can implement arbitrary per-record + ## processing, alter the log record, or veto the writing of the + ## given record by breaking from the hook handler. + ## + ## rec: An instance of the stream's ``columns`` type with its + ## fields set to the values to be logged. + ## + ## id: The ID associated with the logging stream the filter + ## belongs to. + type StreamPolicyHook: hook(rec: any, id: ID); + + ## A hook type to implement filtering policy at log filter + ## granularity. Like :zeek:see:`StreamPolicyHook`, these can + ## implement added functionality, alter it prior to logging, or + ## veto the write. These hooks run at log filter granularity, + ## so get a :zeek:see:`Log::Filter` instance as additional + ## argument. You can pass additional state into the hook via the + ## the filter$config table. ## ## rec: An instance of the stream's ``columns`` type with its ## fields set to the values to be logged. @@ -309,8 +324,8 @@ export { ## id: The ID associated with the logging stream the filter ## belongs to. ## - ## filter: The :zeek:type:`Log::Filter` instance that controls - ## the fate of the given log record. + ## filter: The :zeek:type:`Log::Filter` instance that steers + ## the output of the given log record. type PolicyHook: hook(rec: any, id: ID, filter: Filter); # To allow Filters to have a policy hook that refers to @@ -551,6 +566,13 @@ export { ## This table is not meant to be modified by users! Only use it for ## examining which streams are active. global active_streams: table[ID] of Stream = table(); + + ## The global log policy hook. The framework invokes this hook for any + ## log write, prior to iterating over the stream's associated filters. + ## As with filter-specific hooks, breaking from the hook vetoes writing + ## of the given log record. Note that filter-level policy hooks still get + ## invoked after the global hook vetos, but they cannot "un-veto" the write. + global log_stream_policy: Log::StreamPolicyHook; } global all_streams: table[ID] of Stream = table(); diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index ea7040e3ff..1075713431 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -148,6 +148,7 @@ Manager::~Manager() void Manager::InitPostScript() { rotation_format_func = id::find_func("Log::rotation_format_func"); + log_stream_policy_hook = id::find_func("Log::log_stream_policy"); } WriterBackend* Manager::CreateBackend(WriterFrontend* frontend, EnumVal* tag) @@ -722,6 +723,21 @@ bool Manager::Write(EnumVal* id, RecordVal* columns_arg) if ( stream->event ) event_mgr.Enqueue(stream->event, columns); + bool stream_veto = false; + + if ( log_stream_policy_hook ) + { + auto v = log_stream_policy_hook->Invoke(columns, IntrusivePtr{NewRef{}, id}); + if ( v && ! v->AsBool() ) + { + // We recod the fact that this hook is vetoing + // the write, but continue on to the filter- + // level hooks to allow them to run anyway. + // They cannot "un-veto". + stream_veto = true; + } + } + // Send to each of our filters. for ( list::iterator i = stream->filters.begin(); i != stream->filters.end(); ++i ) @@ -743,6 +759,9 @@ bool Manager::Write(EnumVal* id, RecordVal* columns_arg) continue; } + if ( stream_veto ) + continue; + if ( filter->path_func ) { ValPtr path_arg; diff --git a/src/logging/Manager.h b/src/logging/Manager.h index 83740acc44..5a3f85bc2e 100644 --- a/src/logging/Manager.h +++ b/src/logging/Manager.h @@ -299,6 +299,7 @@ private: std::vector streams; // Indexed by stream enum. int rotations_pending; // Number of rotations not yet finished. FuncPtr rotation_format_func; + FuncPtr log_stream_policy_hook; }; } // namespace logging; diff --git a/testing/btest/Baseline/plugins.hooks/output b/testing/btest/Baseline/plugins.hooks/output index 1ca767fd59..9ce4b32274 100644 --- a/testing/btest/Baseline/plugins.hooks/output +++ b/testing/btest/Baseline/plugins.hooks/output @@ -474,6 +474,7 @@ 0.000000 MetaHookPost CallFunction(Log::create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird, policy=Weird::log_policy])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509, policy=X509::log_policy])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql, policy=MySQL::log_policy])) -> +0.000000 MetaHookPost CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T], PacketFilter::LOG)) -> 0.000000 MetaHookPost CallFunction(Log::write, , (PacketFilter::LOG, [ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T])) -> 0.000000 MetaHookPost CallFunction(NetControl::check_plugins, , ()) -> 0.000000 MetaHookPost CallFunction(NetControl::init, , ()) -> @@ -1506,6 +1507,7 @@ 0.000000 MetaHookPre CallFunction(Log::create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird, policy=Weird::log_policy])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509, policy=X509::log_policy])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql, policy=MySQL::log_policy])) +0.000000 MetaHookPre CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T], PacketFilter::LOG)) 0.000000 MetaHookPre CallFunction(Log::write, , (PacketFilter::LOG, [ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T])) 0.000000 MetaHookPre CallFunction(NetControl::check_plugins, , ()) 0.000000 MetaHookPre CallFunction(NetControl::init, , ()) @@ -2537,6 +2539,7 @@ 0.000000 | HookCallFunction Log::create_stream(Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird, policy=Weird::log_policy]) 0.000000 | HookCallFunction Log::create_stream(X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509, policy=X509::log_policy]) 0.000000 | HookCallFunction Log::create_stream(mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql, policy=MySQL::log_policy]) +0.000000 | HookCallFunction Log::log_stream_policy([ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T], PacketFilter::LOG) 0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=XXXXXXXXXX.XXXXXX, node=zeek, filter=ip or not ip, init=T, success=T]) 0.000000 | HookCallFunction NetControl::check_plugins() 0.000000 | HookCallFunction NetControl::init() @@ -3440,6 +3443,8 @@ XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(HTTP::log_policy, , ([ts=XX XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(HTTP::set_state, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=4, num_pkts=3, num_bytes_ip=304, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=4, num_pkts=5, num_bytes_ip=4612, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=140.0 msecs 430.927277 usecs, service={HTTP}, history=ShADad, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={[1] = [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], F)) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::__write, , (Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=])) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::__write, , (HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1])) -> +XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], HTTP::LOG)) -> +XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=], Files::LOG)) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::write, , (Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=])) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::write, , (HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1])) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(cat, , (Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, F, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80)) -> @@ -3471,6 +3476,8 @@ XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(HTTP::log_policy, , ([ts=XX XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(HTTP::set_state, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=4, num_pkts=3, num_bytes_ip=304, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=4, num_pkts=5, num_bytes_ip=4612, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=140.0 msecs 430.927277 usecs, service={HTTP}, history=ShADad, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={[1] = [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], F)) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::__write, , (Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=])) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::__write, , (HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1])) +XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], HTTP::LOG)) +XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=], Files::LOG)) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::write, , (Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=])) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::write, , (HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1])) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(cat, , (Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, F, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80)) @@ -3503,6 +3510,8 @@ XXXXXXXXXX.XXXXXX | HookCallFunction HTTP::log_policy([ts=XXXXXXXXXX.XXXXXX, uid XXXXXXXXXX.XXXXXX | HookCallFunction HTTP::set_state([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=4, num_pkts=3, num_bytes_ip=304, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=4, num_pkts=5, num_bytes_ip=4612, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=140.0 msecs 430.927277 usecs, service={HTTP}, history=ShADad, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={[1] = [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=0, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], F) XXXXXXXXXX.XXXXXX | HookCallFunction Log::__write(Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=]) XXXXXXXXXX.XXXXXX | HookCallFunction Log::__write(HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1]) +XXXXXXXXXX.XXXXXX | HookCallFunction Log::log_stream_policy([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], HTTP::LOG) +XXXXXXXXXX.XXXXXX | HookCallFunction Log::log_stream_policy([ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=], Files::LOG) XXXXXXXXXX.XXXXXX | HookCallFunction Log::write(Files::LOG, [ts=XXXXXXXXXX.XXXXXX, fuid=FMnxxt3xjVcWNS2141, tx_hosts={192.150.187.43}, rx_hosts={141.142.228.5}, conn_uids={CHhAvVGS1DHFjwGM9}, source=HTTP, depth=0, analyzers={}, mime_type=text/plain, filename=, duration=262.975693 usecs, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=]) XXXXXXXXXX.XXXXXX | HookCallFunction Log::write(HTTP::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1]) XXXXXXXXXX.XXXXXX | HookCallFunction cat(Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, F, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80) @@ -3559,6 +3568,7 @@ XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Conn::set_conn, , ([id=[or XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(HTTP::finalize_http, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(HTTP::get_file_handle, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], T)) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::__write, , (Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=])) -> +XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], Conn::LOG)) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(Log::write, , (Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=])) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(cat, , (Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, T, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80)) -> XXXXXXXXXX.XXXXXX MetaHookPost CallFunction(connection_state_remove, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> @@ -3595,6 +3605,7 @@ XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Conn::set_conn, , ([id=[or XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(HTTP::finalize_http, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(HTTP::get_file_handle, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], T)) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::__write, , (Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=])) +XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::log_stream_policy, , ([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], Conn::LOG)) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(Log::write, , (Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=])) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(cat, , (Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, T, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80)) XXXXXXXXXX.XXXXXX MetaHookPre CallFunction(connection_state_remove, , ([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) @@ -3632,6 +3643,7 @@ XXXXXXXXXX.XXXXXX | HookCallFunction Conn::set_conn([id=[orig_h=141.142.228.5, o XXXXXXXXXX.XXXXXX | HookCallFunction HTTP::finalize_http([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=]) XXXXXXXXXX.XXXXXX | HookCallFunction HTTP::get_file_handle([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=], T) XXXXXXXXXX.XXXXXX | HookCallFunction Log::__write(Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=]) +XXXXXXXXXX.XXXXXX | HookCallFunction Log::log_stream_policy([ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=], Conn::LOG) XXXXXXXXXX.XXXXXX | HookCallFunction Log::write(Conn::LOG, [ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], proto=tcp, service=http, duration=211.0 msecs 483.955383 usecs, orig_bytes=136, resp_bytes=5007, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=ShADadFf, orig_pkts=7, orig_ip_bytes=512, resp_pkts=7, resp_ip_bytes=5379, tunnel_parents=]) XXXXXXXXXX.XXXXXX | HookCallFunction cat(Analyzer::ANALYZER_HTTP, XXXXXXXXXX.XXXXXX, T, 1, 1, 141.142.228.5:59856 > 192.150.187.43:80) XXXXXXXXXX.XXXXXX | HookCallFunction connection_state_remove([id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], orig=[size=136, state=5, num_pkts=7, num_bytes_ip=512, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=5007, state=5, num_pkts=7, num_bytes_ip=5379, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=XXXXXXXXXX.XXXXXX, duration=211.0 msecs 483.955383 usecs, service={HTTP}, history=ShADadFf, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, dpd=, dpd_state=, removal_hooks={HTTP::finalize_http{ HTTP::r, HTTP::info{ if (HTTP::c?$http_state) { for ([HTTP::r] in HTTP::c$http_state$pending) { if (0 == HTTP::r) next Log::write(HTTP::LOG, to_any_coerceHTTP::info)}}}}}, conn=, extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=, ftp=, ftp_data_reuse=F, ssl=, http=[ts=XXXXXXXXXX.XXXXXX, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=141.142.228.5, orig_p=59856/tcp, resp_h=192.150.187.43, resp_p=80/tcp], trans_depth=1, method=GET, host=bro.org, uri=<...>/CHANGES.bro-aux.txt, referrer=, version=1.1, user_agent=Wget/1.14 (darwin12.2.0), origin=, request_body_len=0, response_body_len=4705, status_code=200, status_msg=OK, info_code=, info_msg=, tags={}, username=, password=, capture_password=F, proxied=, range_request=F, orig_fuids=, orig_filenames=, orig_mime_types=, resp_fuids=[FMnxxt3xjVcWNS2141], resp_filenames=, resp_mime_types=[text/plain], current_entity=, orig_mime_depth=1, resp_mime_depth=1], http_state=[pending={}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=]) diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/output b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/output new file mode 100644 index 0000000000..84fc0b2c47 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/output @@ -0,0 +1,7 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +Log::log_stream_policy +foo +foo +Log::log_stream_policy +bar +bar diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/test.log b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/test.log new file mode 100644 index 0000000000..b15eb49a38 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-10/test.log @@ -0,0 +1,11 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open XXXX-XX-XX-XX-XX-XX +#fields t status +#types time string +XXXXXXXXXX.XXXXXX bar +#close XXXX-XX-XX-XX-XX-XX diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-11/test.log b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-11/test.log new file mode 100644 index 0000000000..b15eb49a38 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-11/test.log @@ -0,0 +1,11 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open XXXX-XX-XX-XX-XX-XX +#fields t status +#types time string +XXXXXXXXXX.XXXXXX bar +#close XXXX-XX-XX-XX-XX-XX diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-8/test.log b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-8/test.log new file mode 100644 index 0000000000..b15eb49a38 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-8/test.log @@ -0,0 +1,11 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open XXXX-XX-XX-XX-XX-XX +#fields t status +#types time string +XXXXXXXXXX.XXXXXX bar +#close XXXX-XX-XX-XX-XX-XX diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-9/test.log b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-9/test.log new file mode 100644 index 0000000000..85873d1a07 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.hooks-9/test.log @@ -0,0 +1,11 @@ +### BTest baseline data generated by btest-diff. Do not edit. Use "btest -U/-u" to update. Requires BTest >= 0.63. +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open XXXX-XX-XX-XX-XX-XX +#fields t status +#types time string +XXXXXXXXXX.XXXXXX barbaz +#close XXXX-XX-XX-XX-XX-XX diff --git a/testing/btest/scripts/base/frameworks/logging/hooks.zeek b/testing/btest/scripts/base/frameworks/logging/hooks.zeek index 041990e226..fc07505853 100644 --- a/testing/btest/scripts/base/frameworks/logging/hooks.zeek +++ b/testing/btest/scripts/base/frameworks/logging/hooks.zeek @@ -3,13 +3,14 @@ # @TEST-EXEC: zeek -b test.zeek %INPUT # @TEST-EXEC: btest-diff test.log # @TEST-EXEC: test -f other.log && btest-diff other.log || true +# @TEST-EXEC: test -f output && btest-diff output || true @TEST-START-FILE test.zeek # This provides a simple test module harness, used by all of the individual tests below. module Test; export { - # Create a new ID for our log stream + # Create new IDs for our log streams redef enum Log::ID += { LOG, LOG_OTHER }; # Create a corresponding policy hook: @@ -167,3 +168,126 @@ event zeek_init() Log::write(Test::LOG_OTHER, [$t=network_time(), $status="foo"]); Log::write(Test::LOG_OTHER, [$t=network_time(), $status="bar"]); } + +@TEST-START-NEXT + +# Verify that the global policy hook is effective. We have no +# filter-specific hook handlers, only the global one is vetoing +# some entries. + +hook Log::log_stream_policy(rec: any, id: Log::ID) + { + if ( id == Test::LOG ) + { + local r: Test::Info = rec; + + if ( r$status == "foo" ) + break; + } + } + +event zeek_init() + { + Log::write(Test::LOG, [$t=network_time(), $status="foo"]); + Log::write(Test::LOG, [$t=network_time(), $status="bar"]); + } + +@TEST-START-NEXT + +# Verify the combination of global and filter-specific policy hooks. +# The former get invoked first. + +hook Log::log_stream_policy(rec: any, id: Log::ID) + { + if ( id == Test::LOG ) + { + local r: Test::Info = rec; + + if ( r$status == "foo" ) + break; + } + } + +hook Test::log_policy(rec: Test::Info, id: Log::ID, filter: Log::Filter) + { + # Test::log_policy should have blocked this one + if ( rec$status == "foo" ) + rec$status = "foobar"; + + # This just verifies the hook can mod entries. + # It should make it into the log. + if ( rec$status == "bar" ) + rec$status = "barbaz"; + } + +event zeek_init() + { + Log::write(Test::LOG, [$t=network_time(), $status="foo"]); + Log::write(Test::LOG, [$t=network_time(), $status="bar"]); + } + +@TEST-START-NEXT + +# Verify that per write, the global hook gets invoked once and the +# filter-level hooks once per filter, that filter hooks get +# invoked even when the global hook already vetoed, and that they +# do not "un-veto". + +global output = open("output"); + +hook Log::log_stream_policy(rec: any, id: Log::ID) + { + print output, "Log::log_stream_policy"; + + if ( id == Test::LOG ) + { + local r: Test::Info = rec; + + if ( r$status == "foo" ) + break; + } + } + +hook Test::log_policy(rec: Test::Info, id: Log::ID, filter: Log::Filter) + { + print output, rec$status; + } + +event zeek_init() + { + local filter: Log::Filter = [$name="other"]; + Log::add_filter(Test::LOG, filter); + + Log::write(Test::LOG, [$t=network_time(), $status="foo"]); + Log::write(Test::LOG, [$t=network_time(), $status="bar"]); + } + +@TEST-START-NEXT + +# Verify the global policy works on streams with no per-filter hooks, since +# their logic is a bit intertwined. + +module Test; + +export { + redef enum Log::ID += { LOG2 }; +} + +hook Log::log_stream_policy(rec: any, id: Log::ID) + { + if ( id == Test::LOG2 ) + { + local r: Test::Info = rec; + + if ( r$status == "foo" ) + break; + } + } + +event zeek_init() &priority=2 + { + Log::create_stream(Test::LOG2, [$columns=Info, $path="test"]); + + Log::write(Test::LOG2, [$t=network_time(), $status="foo"]); + Log::write(Test::LOG2, [$t=network_time(), $status="bar"]); +}