diff --git a/scripts/base/frameworks/broker/main.zeek b/scripts/base/frameworks/broker/main.zeek index d3fefd8939..b058a8a9bf 100644 --- a/scripts/base/frameworks/broker/main.zeek +++ b/scripts/base/frameworks/broker/main.zeek @@ -379,6 +379,17 @@ export { module Broker; +event Broker::log_flush() &priority=10 + { + Broker::flush_logs(); + schedule Broker::log_batch_interval { Broker::log_flush() }; + } + +event zeek_init() + { + schedule Broker::log_batch_interval { Broker::log_flush() }; + } + event retry_listen(a: string, p: port, retry: interval) { listen(a, p, retry); diff --git a/src/broker/Manager.cc b/src/broker/Manager.cc index 129f6ad525..29564a386f 100644 --- a/src/broker/Manager.cc +++ b/src/broker/Manager.cc @@ -131,7 +131,6 @@ Manager::Manager(bool arg_reading_pcaps) after_zeek_init = false; peer_count = 0; log_batch_size = 0; - log_batch_interval = 0; log_topic_func = nullptr; vector_of_data_type = nullptr; log_id_type = nullptr; @@ -147,7 +146,6 @@ void Manager::InitPostScript() DBG_LOG(DBG_BROKER, "Initializing"); log_batch_size = get_option("Broker::log_batch_size")->AsCount(); - log_batch_interval = get_option("Broker::log_batch_interval")->AsInterval(); default_log_topic_prefix = get_option("Broker::default_log_topic_prefix")->AsString()->CheckString(); log_topic_func = get_option("Broker::log_topic")->AsFunc(); @@ -580,8 +578,7 @@ bool Manager::PublishLogWrite(EnumVal* stream, EnumVal* writer, string path, int auto& pending_batch = lb.msgs[topic]; pending_batch.emplace_back(msg.move_data()); - if ( lb.message_count >= log_batch_size || - (network_time - lb.last_flush >= log_batch_interval ) ) + if ( lb.message_count >= log_batch_size ) statistics.num_logs_outgoing += lb.Flush(bstate->endpoint, log_batch_size); return true; @@ -608,7 +605,6 @@ size_t Manager::LogBuffer::Flush(broker::endpoint& endpoint, size_t log_batch_si } auto rval = message_count; - last_flush = network_time; message_count = 0; return rval; } @@ -619,8 +615,9 @@ size_t Manager::FlushLogBuffers() auto rval = 0u; for ( auto& lb : log_buffers ) - rval += lb.Flush(bstate->endpoint, log_batch_interval); + rval += lb.Flush(bstate->endpoint, log_batch_size); + statistics.num_logs_outgoing += rval; return rval; } diff --git a/src/broker/Manager.h b/src/broker/Manager.h index 5f98177a09..0cbde06090 100644 --- a/src/broker/Manager.h +++ b/src/broker/Manager.h @@ -354,7 +354,6 @@ private: struct LogBuffer { // Indexed by topic string. std::unordered_map msgs; - double last_flush; size_t message_count; size_t Flush(broker::endpoint& endpoint, size_t batch_size); @@ -389,7 +388,6 @@ private: int peer_count; size_t log_batch_size; - double log_batch_interval; Func* log_topic_func; VectorType* vector_of_data_type; EnumType* log_id_type; diff --git a/testing/btest/Baseline/broker.remote_log_batch/recv.recv.out b/testing/btest/Baseline/broker.remote_log_batch/recv.recv.out new file mode 100644 index 0000000000..e69de29bb2 diff --git a/testing/btest/Baseline/broker.remote_log_batch/recv.test.log b/testing/btest/Baseline/broker.remote_log_batch/recv.test.log new file mode 100644 index 0000000000..c2196df246 --- /dev/null +++ b/testing/btest/Baseline/broker.remote_log_batch/recv.test.log @@ -0,0 +1,11 @@ +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open 2020-02-05-20-53-15 +#fields msg num +#types string count +ping 0 +ping 1 +#close 2020-02-05-20-53-16 diff --git a/testing/btest/Baseline/broker.remote_log_batch/send.send.out b/testing/btest/Baseline/broker.remote_log_batch/send.send.out new file mode 100644 index 0000000000..c2520da821 --- /dev/null +++ b/testing/btest/Baseline/broker.remote_log_batch/send.send.out @@ -0,0 +1 @@ +Broker::peer_added, 127.0.0.1 diff --git a/testing/btest/Baseline/broker.remote_log_batch/send.test.log b/testing/btest/Baseline/broker.remote_log_batch/send.test.log new file mode 100644 index 0000000000..c2196df246 --- /dev/null +++ b/testing/btest/Baseline/broker.remote_log_batch/send.test.log @@ -0,0 +1,11 @@ +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path test +#open 2020-02-05-20-53-15 +#fields msg num +#types string count +ping 0 +ping 1 +#close 2020-02-05-20-53-16 diff --git a/testing/btest/Baseline/language.paraglob-serialization/recv.recv.out b/testing/btest/Baseline/language.paraglob-serialization/recv.recv.out index bd6ae96cfa..4d6b544da5 100644 --- a/testing/btest/Baseline/language.paraglob-serialization/recv.recv.out +++ b/testing/btest/Baseline/language.paraglob-serialization/recv.recv.out @@ -9,4 +9,3 @@ is_remote should be T, and is, T receiver got ping number: 3 [*, *ello, hello] is_remote should be T, and is, T -[num_peers=1, num_stores=0, num_pending_queries=0, num_events_incoming=4, num_events_outgoing=3, num_logs_incoming=0, num_logs_outgoing=1, num_ids_incoming=0, num_ids_outgoing=0] diff --git a/testing/btest/Baseline/plugins.hooks/output b/testing/btest/Baseline/plugins.hooks/output index dde704c5af..8fc63394a8 100644 --- a/testing/btest/Baseline/plugins.hooks/output +++ b/testing/btest/Baseline/plugins.hooks/output @@ -276,7 +276,7 @@ 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) -> 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) -> 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -> -0.000000 MetaHookPost CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T])) -> +0.000000 MetaHookPost CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Broker::LOG)) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Cluster::LOG)) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Config::LOG)) -> @@ -457,7 +457,7 @@ 0.000000 MetaHookPost CallFunction(Log::create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -> -0.000000 MetaHookPost CallFunction(Log::write, , (PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T])) -> +0.000000 MetaHookPost CallFunction(Log::write, , (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) -> 0.000000 MetaHookPost CallFunction(NetControl::check_plugins, , ()) -> 0.000000 MetaHookPost CallFunction(NetControl::init, , ()) -> 0.000000 MetaHookPost CallFunction(Notice::want_pp, , ()) -> @@ -1180,7 +1180,7 @@ 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -0.000000 MetaHookPre CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T])) +0.000000 MetaHookPre CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Broker::LOG)) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Cluster::LOG)) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Config::LOG)) @@ -1361,7 +1361,7 @@ 0.000000 MetaHookPre CallFunction(Log::create_stream, , (Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql])) -0.000000 MetaHookPre CallFunction(Log::write, , (PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T])) +0.000000 MetaHookPre CallFunction(Log::write, , (PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T])) 0.000000 MetaHookPre CallFunction(NetControl::check_plugins, , ()) 0.000000 MetaHookPre CallFunction(NetControl::init, , ()) 0.000000 MetaHookPre CallFunction(Notice::want_pp, , ()) @@ -2083,7 +2083,7 @@ 0.000000 | HookCallFunction Log::__create_stream(Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird]) 0.000000 | HookCallFunction Log::__create_stream(X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509]) 0.000000 | HookCallFunction Log::__create_stream(mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql]) -0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T]) +0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T]) 0.000000 | HookCallFunction Log::add_default_filter(Broker::LOG) 0.000000 | HookCallFunction Log::add_default_filter(Cluster::LOG) 0.000000 | HookCallFunction Log::add_default_filter(Config::LOG) @@ -2264,7 +2264,7 @@ 0.000000 | HookCallFunction Log::create_stream(Weird::LOG, [columns=Weird::Info, ev=Weird::log_weird, path=weird]) 0.000000 | HookCallFunction Log::create_stream(X509::LOG, [columns=X509::Info, ev=X509::log_x509, path=x509]) 0.000000 | HookCallFunction Log::create_stream(mysql::LOG, [columns=MySQL::Info, ev=MySQL::log_mysql, path=mysql]) -0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T]) +0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T]) 0.000000 | HookCallFunction NetControl::check_plugins() 0.000000 | HookCallFunction NetControl::init() 0.000000 | HookCallFunction Notice::want_pp() @@ -2705,27 +2705,35 @@ 0.000000 | HookLoadFile base<...>/xmpp 0.000000 | HookLoadFile base<...>/zeek.bif.zeek 0.000000 | HookLogInit packet_filter 1/1 {ts (time), node (string), filter (string), init (bool), success (bool)} -0.000000 | HookLogWrite packet_filter [ts=1579727603.636084, node=zeek, filter=ip or not ip, init=T, success=T] +0.000000 | HookLogWrite packet_filter [ts=1580932537.132762, node=zeek, filter=ip or not ip, init=T, success=T] 0.000000 | HookQueueEvent NetControl::init() 0.000000 | HookQueueEvent filter_change_tracking() 0.000000 | HookQueueEvent zeek_init() 1362692526.869344 MetaHookPost BroObjDtor() -> +1362692526.869344 MetaHookPost CallFunction(Broker::__flush_logs, , ()) -> +1362692526.869344 MetaHookPost CallFunction(Broker::flush_logs, , ()) -> +1362692526.869344 MetaHookPost CallFunction(Broker::log_flush, , ()) -> 1362692526.869344 MetaHookPost CallFunction(ChecksumOffloading::check, , ()) -> 1362692526.869344 MetaHookPost CallFunction(filter_change_tracking, , ()) -> 1362692526.869344 MetaHookPost CallFunction(get_net_stats, , ()) -> 1362692526.869344 MetaHookPost CallFunction(new_connection, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> 1362692526.869344 MetaHookPost DrainEvents() -> +1362692526.869344 MetaHookPost QueueEvent(Broker::log_flush()) -> false 1362692526.869344 MetaHookPost QueueEvent(ChecksumOffloading::check()) -> false 1362692526.869344 MetaHookPost QueueEvent(filter_change_tracking()) -> false 1362692526.869344 MetaHookPost QueueEvent(new_connection([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> false 1362692526.869344 MetaHookPost SetupAnalyzerTree(1362692526.869344(1362692526.869344) TCP 141.142.228.5:59856 -> 192.150.187.43:80) -> 1362692526.869344 MetaHookPost UpdateNetworkTime(1362692526.869344) -> 1362692526.869344 MetaHookPre BroObjDtor() +1362692526.869344 MetaHookPre CallFunction(Broker::__flush_logs, , ()) +1362692526.869344 MetaHookPre CallFunction(Broker::flush_logs, , ()) +1362692526.869344 MetaHookPre CallFunction(Broker::log_flush, , ()) 1362692526.869344 MetaHookPre CallFunction(ChecksumOffloading::check, , ()) 1362692526.869344 MetaHookPre CallFunction(filter_change_tracking, , ()) 1362692526.869344 MetaHookPre CallFunction(get_net_stats, , ()) 1362692526.869344 MetaHookPre CallFunction(new_connection, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) 1362692526.869344 MetaHookPre DrainEvents() +1362692526.869344 MetaHookPre QueueEvent(Broker::log_flush()) 1362692526.869344 MetaHookPre QueueEvent(ChecksumOffloading::check()) 1362692526.869344 MetaHookPre QueueEvent(filter_change_tracking()) 1362692526.869344 MetaHookPre QueueEvent(new_connection([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) @@ -2733,16 +2741,20 @@ 1362692526.869344 MetaHookPre UpdateNetworkTime(1362692526.869344) 1362692526.869344 | HookBroObjDtor 1362692526.869344 | HookUpdateNetworkTime 1362692526.869344 +1362692526.869344 | HookCallFunction Broker::__flush_logs() +1362692526.869344 | HookCallFunction Broker::flush_logs() +1362692526.869344 | HookCallFunction Broker::log_flush() 1362692526.869344 | HookCallFunction ChecksumOffloading::check() 1362692526.869344 | HookCallFunction filter_change_tracking() 1362692526.869344 | HookCallFunction get_net_stats() 1362692526.869344 | HookCallFunction new_connection([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=]) 1362692526.869344 | HookDrainEvents +1362692526.869344 | HookQueueEvent Broker::log_flush() 1362692526.869344 | HookQueueEvent ChecksumOffloading::check() 1362692526.869344 | HookQueueEvent filter_change_tracking() 1362692526.869344 | HookQueueEvent new_connection([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.0, service={}, history=, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=]) 1362692526.869344 | HookSetupAnalyzerTree 1362692526.869344(1362692526.869344) TCP 141.142.228.5:59856 -> 192.150.187.43:80 -1362692526.869344 | RequestObjDtor ChecksumOffloading::check() +1362692526.869344 | RequestObjDtor Broker::log_flush() 1362692526.939084 MetaHookPost CallFunction(connection_established, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=4, num_pkts=1, num_bytes_ip=64, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=4, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.06974, service={}, history=Sh, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> 1362692526.939084 MetaHookPost DrainEvents() -> 1362692526.939084 MetaHookPost QueueEvent(connection_established([id=[orig_h=141.142.228.5, orig_p=59856<...>/tcp], orig=[size=0, state=4, num_pkts=1, num_bytes_ip=64, flow_label=0, l2_addr=c8:bc:c8:96:d2:a0], resp=[size=0, state=4, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:10:db:88:d2:ef], start_time=1362692526.869344, duration=0.06974, service={}, history=Sh, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> false @@ -3139,6 +3151,9 @@ 1362692527.080828 MetaHookPre UpdateNetworkTime(1362692527.080828) 1362692527.080828 | HookUpdateNetworkTime 1362692527.080828 1362692527.080828 | HookDrainEvents +1362692527.080972 MetaHookPost CallFunction(Broker::__flush_logs, , ()) -> +1362692527.080972 MetaHookPost CallFunction(Broker::flush_logs, , ()) -> +1362692527.080972 MetaHookPost CallFunction(Broker::log_flush, , ()) -> 1362692527.080972 MetaHookPost CallFunction(ChecksumOffloading::check, , ()) -> 1362692527.080972 MetaHookPost CallFunction(Conn::conn_state, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=], tcp)) -> 1362692527.080972 MetaHookPost CallFunction(Conn::determine_service, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=])) -> @@ -3167,6 +3182,7 @@ 1362692527.080972 MetaHookPost DrainEvents() -> 1362692527.080972 MetaHookPost LogInit(Log::WRITER_ASCII, default, true, true, conn(1362692527.080972,0.0,0.0), 21, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), proto (enum), service (string), duration (interval), orig_bytes (count), resp_bytes (count), conn_state (string), local_orig (bool), local_resp (bool), missed_bytes (count), history (string), orig_pkts (count), orig_ip_bytes (count), resp_pkts (count), resp_ip_bytes (count), tunnel_parents (set[string])}) -> 1362692527.080972 MetaHookPost LogWrite(Log::WRITER_ASCII, default, conn(1362692527.080972,0.0,0.0), 21, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), proto (enum), service (string), duration (interval), orig_bytes (count), resp_bytes (count), conn_state (string), local_orig (bool), local_resp (bool), missed_bytes (count), history (string), orig_pkts (count), orig_ip_bytes (count), resp_pkts (count), resp_ip_bytes (count), tunnel_parents (set[string])}, ) -> true +1362692527.080972 MetaHookPost QueueEvent(Broker::log_flush()) -> false 1362692527.080972 MetaHookPost QueueEvent(ChecksumOffloading::check()) -> false 1362692527.080972 MetaHookPost QueueEvent(connection_state_remove([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=])) -> false 1362692527.080972 MetaHookPost QueueEvent(filter_change_tracking()) -> false @@ -3174,6 +3190,9 @@ 1362692527.080972 MetaHookPost QueueEvent(successful_connection_remove([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=])) -> false 1362692527.080972 MetaHookPost QueueEvent(zeek_done()) -> false 1362692527.080972 MetaHookPost UpdateNetworkTime(1362692527.080972) -> +1362692527.080972 MetaHookPre CallFunction(Broker::__flush_logs, , ()) +1362692527.080972 MetaHookPre CallFunction(Broker::flush_logs, , ()) +1362692527.080972 MetaHookPre CallFunction(Broker::log_flush, , ()) 1362692527.080972 MetaHookPre CallFunction(ChecksumOffloading::check, , ()) 1362692527.080972 MetaHookPre CallFunction(Conn::conn_state, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=], tcp)) 1362692527.080972 MetaHookPre CallFunction(Conn::determine_service, , ([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=])) @@ -3202,6 +3221,7 @@ 1362692527.080972 MetaHookPre DrainEvents() 1362692527.080972 MetaHookPre LogInit(Log::WRITER_ASCII, default, true, true, conn(1362692527.080972,0.0,0.0), 21, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), proto (enum), service (string), duration (interval), orig_bytes (count), resp_bytes (count), conn_state (string), local_orig (bool), local_resp (bool), missed_bytes (count), history (string), orig_pkts (count), orig_ip_bytes (count), resp_pkts (count), resp_ip_bytes (count), tunnel_parents (set[string])}) 1362692527.080972 MetaHookPre LogWrite(Log::WRITER_ASCII, default, conn(1362692527.080972,0.0,0.0), 21, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), proto (enum), service (string), duration (interval), orig_bytes (count), resp_bytes (count), conn_state (string), local_orig (bool), local_resp (bool), missed_bytes (count), history (string), orig_pkts (count), orig_ip_bytes (count), resp_pkts (count), resp_ip_bytes (count), tunnel_parents (set[string])}, ) +1362692527.080972 MetaHookPre QueueEvent(Broker::log_flush()) 1362692527.080972 MetaHookPre QueueEvent(ChecksumOffloading::check()) 1362692527.080972 MetaHookPre QueueEvent(connection_state_remove([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=])) 1362692527.080972 MetaHookPre QueueEvent(filter_change_tracking()) @@ -3210,6 +3230,9 @@ 1362692527.080972 MetaHookPre QueueEvent(zeek_done()) 1362692527.080972 MetaHookPre UpdateNetworkTime(1362692527.080972) 1362692527.080972 | HookUpdateNetworkTime 1362692527.080972 +1362692527.080972 | HookCallFunction Broker::__flush_logs() +1362692527.080972 | HookCallFunction Broker::flush_logs() +1362692527.080972 | HookCallFunction Broker::log_flush() 1362692527.080972 | HookCallFunction ChecksumOffloading::check() 1362692527.080972 | HookCallFunction Conn::conn_state([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=], tcp) 1362692527.080972 | HookCallFunction Conn::determine_service([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=]) @@ -3238,6 +3261,7 @@ 1362692527.080972 | HookDrainEvents 1362692527.080972 | HookLogInit conn 1/1 {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), proto (enum), service (string), duration (interval), orig_bytes (count), resp_bytes (count), conn_state (string), local_orig (bool), local_resp (bool), missed_bytes (count), history (string), orig_pkts (count), orig_ip_bytes (count), resp_pkts (count), resp_ip_bytes (count), tunnel_parents (set[string])} 1362692527.080972 | HookLogWrite conn [ts=1362692526.869344, uid=CHhAvVGS1DHFjwGM9, id.orig_h=141.142.228.5, id.orig_p=59856, id.resp_h=192.150.187.43, id.resp_p=80, proto=tcp, service=http, duration=0.211484, 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=] +1362692527.080972 | HookQueueEvent Broker::log_flush() 1362692527.080972 | HookQueueEvent ChecksumOffloading::check() 1362692527.080972 | HookQueueEvent connection_state_remove([id=[orig_h=141.142.228.5, orig_p=59856<...>/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=]) 1362692527.080972 | HookQueueEvent filter_change_tracking() diff --git a/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events-no-args.log b/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events-no-args.log index fef3381aa3..be3c589795 100644 --- a/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events-no-args.log +++ b/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events-no-args.log @@ -1,6 +1,7 @@ 0.000000 zeek_init 0.000000 filter_change_tracking 0.000000 NetControl::init +1254722767.492060 Broker::log_flush 1254722767.492060 ChecksumOffloading::check 1254722767.492060 filter_change_tracking 1254722767.492060 new_connection @@ -19,6 +20,7 @@ 1254722768.219663 smtp_reply 1254722768.224809 protocol_confirmation 1254722768.224809 smtp_request +1254722768.565386 Broker::log_flush 1254722768.566183 smtp_reply 1254722768.566183 smtp_reply 1254722768.566183 smtp_reply @@ -30,6 +32,7 @@ 1254722768.911655 smtp_request 1254722769.253544 smtp_reply 1254722769.254118 smtp_request +1254722769.613798 Broker::log_flush 1254722769.613798 smtp_reply 1254722769.614414 smtp_request 1254722769.956765 smtp_reply @@ -37,6 +40,7 @@ 1254722770.319708 smtp_reply 1254722770.320203 smtp_request 1254722770.320203 mime_begin_entity +1254722770.661679 Broker::log_flush 1254722770.661679 smtp_reply 1254722770.692743 mime_one_header 1254722770.692743 mime_one_header @@ -86,6 +90,7 @@ 1254722770.692804 file_over_new_connection 1254722770.695115 new_connection 1254722771.494181 file_sniff +1254722771.834595 Broker::log_flush 1254722771.858334 mime_end_entity 1254722771.858334 get_file_handle 1254722771.858334 file_state_remove @@ -97,12 +102,15 @@ 1254722771.858334 get_file_handle 1254722771.858334 smtp_request 1254722772.248789 smtp_reply +1254722774.763825 Broker::log_flush 1254722774.763825 smtp_request 1254722775.105467 smtp_reply +1254722776.690444 Broker::log_flush 1254722776.690444 new_connection 1437831776.764391 ChecksumOffloading::check 1437831776.764391 connection_state_remove 1437831776.764391 successful_connection_remove +1437831776.764391 Broker::log_flush 1437831776.764391 connection_state_remove 1437831776.764391 successful_connection_remove 1437831776.764391 connection_state_remove @@ -111,6 +119,7 @@ 1437831776.764391 successful_connection_remove 1437831776.764391 filter_change_tracking 1437831776.764391 new_connection +1437831787.856895 Broker::log_flush 1437831787.856895 new_connection 1437831787.861602 connection_established 1437831787.867142 smtp_reply @@ -155,9 +164,11 @@ 1437831787.905375 get_file_handle 1437831787.905375 smtp_request 1437831787.914113 smtp_reply +1437831798.533593 Broker::log_flush 1437831798.533593 new_connection 1437831799.262632 new_connection 1437831799.461152 new_connection +1437831799.610433 Broker::log_flush 1437831799.610433 connection_established 1437831799.611764 ssl_extension_server_name 1437831799.611764 ssl_extension @@ -216,6 +227,7 @@ 1437831800.045701 ssl_plaintext_data 1437831800.045701 ssl_established 1437831800.217854 net_done +1437831800.217854 Broker::log_flush 1437831800.217854 filter_change_tracking 1437831800.217854 connection_state_remove 1437831800.217854 successful_connection_remove diff --git a/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events.log b/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events.log index 8dfac88201..9fd035b9bd 100644 --- a/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events.log +++ b/testing/btest/Baseline/scripts.policy.misc.dump-events/all-events.log @@ -1,6 +1,7 @@ 0.000000 zeek_init 0.000000 filter_change_tracking 0.000000 NetControl::init +1254722767.492060 Broker::log_flush 1254722767.492060 ChecksumOffloading::check 1254722767.492060 filter_change_tracking 1254722767.492060 new_connection @@ -91,6 +92,7 @@ [2] command: string = EHLO [3] arg: string = GP +1254722768.565386 Broker::log_flush 1254722768.566183 smtp_reply [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=9, state=4, num_pkts=3, num_bytes_ip=137, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=318, state=4, num_pkts=3, num_bytes_ip=309, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=1.037137, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=, rcptto=, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=220 and/or bulk e-mail., path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=F, entity=, fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=0], socks=, ssh=, syslog=] [1] is_orig: bool = F @@ -173,6 +175,7 @@ [2] command: string = ** [3] arg: string = cHVuamFiQDEyMw== +1254722769.613798 Broker::log_flush 1254722769.613798 smtp_reply [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=69, state=4, num_pkts=6, num_bytes_ip=317, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=384, state=4, num_pkts=6, num_bytes_ip=602, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=2.084752, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=, rcptto=, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=334 UGFzc3dvcmQ6, path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=F, entity=, fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=0], socks=, ssh=, syslog=] [1] is_orig: bool = F @@ -218,6 +221,7 @@ 1254722770.320203 mime_begin_entity [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=150, state=4, num_pkts=8, num_bytes_ip=472, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=406, state=4, num_pkts=9, num_bytes_ip=774, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=2.791157, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=gurpartap@patriots.in, rcptto={\x0araj_deol2002in@yahoo.co.in\x0a}, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=250 Accepted, path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=T, entity=, fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=0], socks=, ssh=, syslog=] +1254722770.661679 Broker::log_flush 1254722770.661679 smtp_reply [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=150, state=4, num_pkts=9, num_bytes_ip=518, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=9, num_bytes_ip=774, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=3.132633, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=gurpartap@patriots.in, rcptto={\x0araj_deol2002in@yahoo.co.in\x0a}, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=250 Accepted, path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=T, entity=[filename=], fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=1], socks=, ssh=, syslog=] [1] is_orig: bool = F @@ -417,6 +421,7 @@ [0] f: fa_file = [id=FL9Y0d45OI4LpS6fmh, parent_id=, source=SMTP, is_orig=T, conns={\x0a\x09[[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp]] = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=4530, state=4, num_pkts=11, num_bytes_ip=3518, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=10, num_bytes_ip=870, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=3.163758, service={\x0aSMTP\x0a\x09}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=gurpartap@patriots.in, rcptto={\x0araj_deol2002in@yahoo.co.in\x0a\x09}, date=Mon, 5 Oct 2009 11:36:07 +0530, from="Gurpartap Singh" , to={\x0a\x0a\x09}, cc=, reply_to=, msg_id=<000301ca4581$ef9e57f0$cedb07d0$@in>, in_reply_to=, subject=SMTP, x_originating_ip=, first_received=, second_received=, last_reply=354 Enter message, ending with "." on a line by itself, path=[74.53.140.153, 10.10.1.4], user_agent=Microsoft Office Outlook 12.0, tls=F, process_received_from=T, has_client_activity=T, entity=[filename=NEWS.txt], fuids=[Fel9gs4OtNEV6gUJZ5, Ft4M3f2yMvLlmwtbq9, FL9Y0d45OI4LpS6fmh]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=5], socks=, ssh=, syslog=]\x0a}, last_active=1254722771.494181, seen_bytes=4027, total_bytes=, missing_bytes=0, overflow_bytes=0, timeout_interval=2.0 mins, bof_buffer_size=4096, bof_buffer=Version 4.9.9.1\x0d\x0a* Many bug fixes\x0d\x0a* Improved editor\x0d\x0a\x0d\x0aVersion 4.9.9.0\x0d\x0a* Support for latest Mingw compiler system builds\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.9\x0d\x0a* New code tooltip display\x0d\x0a* Improved Indent/Unindent and Remove Comment\x0d\x0a* Improved automatic indent\x0d\x0a* Added support for the "interface" keyword\x0d\x0a* WebUpdate should now report installation problems from PackMan\x0d\x0a* New splash screen and association icons\x0d\x0a* Improved installer\x0d\x0a* Many bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.7\x0d\x0a* Added support for GCC > 3.2\x0d\x0a* Debug variables are now resent during next debug session\x0d\x0a* Watched Variables not in correct context are now kept and updated when it is needed\x0d\x0a* Added new compiler/linker options: \x0d\x0a - Strip executable\x0d\x0a - Generate instructions for a specific machine (i386, i486, i586, i686, pentium, pentium-mmx, pentiumpro, pentium2, pentium3, pentium4, \x0d\x0a k6, k6-2, k6-3, athlon, athlon-tbird, athlon-4, athlon-xp, athlon-mp, winchip-c6, winchip2, k8, c3 and c3-2)\x0d\x0a - Enable use of processor specific built-in functions (mmmx, sse, sse2, pni, 3dnow)\x0d\x0a* "Default" button in Compiler Options is back\x0d\x0a* Error messages parsing improved\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.5\x0d\x0a* Added the possibility to modify the value of a variable during debugging (right click on a watch variable and select "Modify value")\x0d\x0a* During Dev-C++ First Time COnfiguration window, users can now choose between using or not class browser and code completion features.\x0d\x0a* Many bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.4\x0d\x0a* Added the possibility to specify an include directory for the code completion cache to be created at Dev-C++ first startup\x0d\x0a* Improved code completion cache\x0d\x0a* WebUpdate will now backup downloaded DevPaks in Dev-C++\Packages directory, and Dev-C++ executable in devcpp.exe.BACKUP\x0d\x0a* Big speed up in function parameters listing while editing\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.3\x0d\x0a* On Dev-C++ first time configuration dialog, a code completion cache of all the standard \x0d\x0a include files can now be generated.\x0d\x0a* Improved WebUpdate module\x0d\x0a* Many bug fixes\x0d\x0a\x0d\x0aVersion 4.9.8.2\x0d\x0a* New debug feature for DLLs: attach to a running process\x0d\x0a* New project option: Use custom Makefile. \x0d\x0a* New WebUpdater module.\x0d\x0a* Allow user to specify an alternate configuration file in Environment Options \x0d\x0a (still can be overriden by using "-c" command line parameter).\x0d\x0a* Lots of bug fixes.\x0d\x0a\x0d\x0aVersion 4.9.8.1\x0d\x0a* When creating a DLL, the created static lib respects now the project-defined output directory\x0d\x0a\x0d\x0aVersion 4.9.8.0\x0d\x0a* Changed position of compiler/linker parameters in Project Options.\x0d\x0a* Improved help file\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.9\x0d\x0a* Resource errors are now reported in the Resource sheet\x0d\x0a* Many bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.8\x0d\x0a* Made whole bottom report control floating instead of only debug output.\x0d\x0a* Many bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.7\x0d\x0a* Printing settings are now saved\x0d\x0a* New environment options : "watch variable under mouse" and "Report watch errors"\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.6\x0d\x0a* Debug variable browser\x0d\x0a* Added possibility to include in a Template the Project's directories (include, libs and ressources)\x0d\x0a* Changed tint of Class browser pictures colors to match the New Look style\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.5\x0d\x0a* Bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.4\x0d\x0a* When compiling with debugging symbols, an extra definition is passed to the\x0d\x0a compiler: -D__DEBUG__\x0d\x0a* Each project creates a _private.h file containing version\x0d\x0a information definitions\x0d\x0a* When compiling the current file only, no dependency checks are performed\x0d\x0a* ~300% Speed-up in class parser\x0d\x0a* Added "External programs" in Tools/Environment Options (for units "Open with")\x0d\x0a* Added "Open with" in project units context menu\x0d\x0a* Added "Classes" toolbar\x0d\x0a* Fixed pre-compilation dependency checks to work correctly\x0d\x0a* Added new file menu entry: Save Project As\x0d\x0a* Bug-fix for double quotes in devcpp.cfg file read by vUpdate\x0d\x0a* Other bug fixes\x0d\x0a\x0d\x0aVersion 4.9.7.3\x0d\x0a* When adding debugging symbols on request, remove "-s" option from linker\x0d\x0a* Compiling progress window\x0d\x0a* Environment options : "Show progress window" and "Auto-close progress , info=[ts=1254722770.692804, fuid=FL9Y0d45OI4LpS6fmh, tx_hosts={\x0a\x0910.10.1.4\x0a}, rx_hosts={\x0a\x0974.53.140.153\x0a}, conn_uids={\x0aClEkJM2Vm5giqnMf4h\x0a}, source=SMTP, depth=5, analyzers={\x0a\x0a}, mime_type=, filename=NEWS.txt, duration=0 secs, local_orig=, is_orig=T, seen_bytes=0, total_bytes=, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, x509=, extracted=, extracted_cutoff=, extracted_size=], ftp=, http=, irc=, pe=] [1] meta: fa_metadata = [mime_type=text/plain, mime_types=[[strength=-20, mime=text/plain]], inferred=T] +1254722771.834595 Broker::log_flush 1254722771.858334 mime_end_entity [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=14699, state=4, num_pkts=23, num_bytes_ip=21438, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=15, num_bytes_ip=1070, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=4.329288, service={\x0aSMTP\x0a}, history=ShAdDaT, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722768.219663, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=1, helo=GP, mailfrom=gurpartap@patriots.in, rcptto={\x0araj_deol2002in@yahoo.co.in\x0a}, date=Mon, 5 Oct 2009 11:36:07 +0530, from="Gurpartap Singh" , to={\x0a\x0a}, cc=, reply_to=, msg_id=<000301ca4581$ef9e57f0$cedb07d0$@in>, in_reply_to=, subject=SMTP, x_originating_ip=, first_received=, second_received=, last_reply=354 Enter message, ending with "." on a line by itself, path=[74.53.140.153, 10.10.1.4], user_agent=Microsoft Office Outlook 12.0, tls=F, process_received_from=T, has_client_activity=T, entity=[filename=NEWS.txt], fuids=[Fel9gs4OtNEV6gUJZ5, Ft4M3f2yMvLlmwtbq9, FL9Y0d45OI4LpS6fmh]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=, mime_depth=5], socks=, ssh=, syslog=] @@ -470,6 +475,7 @@ [4] msg: string = OK id=1Mugho-0003Dg-Un [5] cont_resp: bool = F +1254722774.763825 Broker::log_flush 1254722774.763825 smtp_request [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=14705, state=4, num_pkts=25, num_bytes_ip=21547, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=490, state=4, num_pkts=22, num_bytes_ip=1378, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=7.234779, service={\x0aSMTP\x0a}, history=ShAdDaT, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722772.248789, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=2, helo=GP, mailfrom=, rcptto=, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=, path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=F, entity=, fuids=[]], smtp_state=[helo=GP, messages_transferred=1, pending_messages=, mime_depth=5], socks=, ssh=, syslog=] [1] is_orig: bool = T @@ -484,6 +490,7 @@ [4] msg: string = xc90.websitewelcome.com closing connection [5] cont_resp: bool = F +1254722776.690444 Broker::log_flush 1254722776.690444 new_connection [0] c: connection = [id=[orig_h=10.10.1.20, orig_p=138/udp, resp_h=10.10.1.255, resp_p=138/udp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:02:3f:ec:61:11], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=ff:ff:ff:ff:ff:ff], start_time=1254722776.690444, duration=0.0, service={\x0a\x0a}, history=, uid=CtPZjS20MLrsMUOJi2, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] @@ -494,6 +501,7 @@ 1437831776.764391 successful_connection_remove [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=56166/udp, resp_h=10.10.1.1, resp_p=53/udp], orig=[size=34, state=1, num_pkts=1, num_bytes_ip=62, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=100, state=1, num_pkts=1, num_bytes_ip=128, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.49206, duration=0.034025, service={\x0aDNS\x0a}, history=Dd, uid=CHhAvVGS1DHFjwGM9, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, conn=[ts=1254722767.49206, uid=CHhAvVGS1DHFjwGM9, id=[orig_h=10.10.1.4, orig_p=56166/udp, resp_h=10.10.1.1, resp_p=53/udp], proto=udp, service=dns, duration=0.034025, orig_bytes=34, resp_bytes=100, conn_state=SF, local_orig=, local_resp=, missed_bytes=0, history=Dd, orig_pkts=1, orig_ip_bytes=62, resp_pkts=1, resp_ip_bytes=128, tunnel_parents=], extract_orig=F, extract_resp=F, thresholds=, dce_rpc=, dce_rpc_state=, dce_rpc_backing=, dhcp=, dnp3=, dns=, dns_state=[pending_query=, pending_queries=, pending_replies=], ftp=, ftp_data_reuse=F, ssl=, http=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] +1437831776.764391 Broker::log_flush 1437831776.764391 connection_state_remove [0] c: connection = [id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], orig=[size=14705, state=5, num_pkts=28, num_bytes_ip=21673, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=538, state=5, num_pkts=25, num_bytes_ip=1546, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=1254722767.529046, duration=7.576953, service={\x0aSMTP\x0a}, history=ShAdDaTFf, uid=ClEkJM2Vm5giqnMf4h, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=[ts=1254722772.248789, uid=ClEkJM2Vm5giqnMf4h, id=[orig_h=10.10.1.4, orig_p=1470/tcp, resp_h=74.53.140.153, resp_p=25/tcp], trans_depth=2, helo=GP, mailfrom=, rcptto=, date=, from=, to=, cc=, reply_to=, msg_id=, in_reply_to=, subject=, x_originating_ip=, first_received=, second_received=, last_reply=221 xc90.websitewelcome.com closing connection, path=[74.53.140.153, 10.10.1.4], user_agent=, tls=F, process_received_from=T, has_client_activity=F, entity=, fuids=[]], smtp_state=[helo=GP, messages_transferred=1, pending_messages=, mime_depth=5], socks=, ssh=, syslog=] @@ -516,6 +524,7 @@ 1437831776.764391 new_connection [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49285/tcp, resp_h=66.196.121.26, resp_p=5050/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=cc:b2:55:f4:62:92], start_time=1437831776.764391, duration=0.0, service={\x0a\x0a}, history=, uid=CUM0KZ3MLUfNB0cl11, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] +1437831787.856895 Broker::log_flush 1437831787.856895 new_connection [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49648/tcp, resp_h=192.168.133.102, resp_p=25/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:08:ca:cc:ad:4c], start_time=1437831787.856895, duration=0.0, service={\x0a\x0a}, history=, uid=CmES5u32sYpV7JYN, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] @@ -751,6 +760,7 @@ [4] msg: string = Ok [5] cont_resp: bool = F +1437831798.533593 Broker::log_flush 1437831798.533593 new_connection [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49336/tcp, resp_h=74.125.71.189, resp_p=443/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=cc:b2:55:f4:62:92], start_time=1437831798.533593, duration=0.0, service={\x0a\x0a}, history=^, uid=CP5puj4I8PtEU4qzYg, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] @@ -760,6 +770,7 @@ 1437831799.461152 new_connection [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49655/tcp, resp_h=17.167.150.73, resp_p=443/tcp], orig=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=cc:b2:55:f4:62:92], start_time=1437831799.461152, duration=0.0, service={\x0a\x0a}, history=, uid=C3eiCBGOLw3VtHfOj, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] +1437831799.610433 Broker::log_flush 1437831799.610433 connection_established [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49655/tcp, resp_h=17.167.150.73, resp_p=443/tcp], orig=[size=0, state=4, num_pkts=1, num_bytes_ip=64, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=0, state=4, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=cc:b2:55:f4:62:92], start_time=1437831799.461152, duration=0.149281, service={\x0a\x0a}, history=Sh, uid=C3eiCBGOLw3VtHfOj, tunnel=, vlan=, inner_vlan=, successful=F, dpd=, dpd_state=, 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=, http_state=, irc=, krb=, modbus=, mysql=, ntlm=, ntp=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smb_state=, smtp=, smtp_state=, socks=, ssh=, syslog=] @@ -1044,6 +1055,7 @@ 1437831800.217854 net_done [0] t: time = 1437831800.217854 +1437831800.217854 Broker::log_flush 1437831800.217854 filter_change_tracking 1437831800.217854 connection_state_remove [0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49655/tcp, resp_h=17.167.150.73, resp_p=443/tcp], orig=[size=2249, state=4, num_pkts=15, num_bytes_ip=2873, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=3653, state=4, num_pkts=13, num_bytes_ip=4185, flow_label=0, l2_addr=cc:b2:55:f4:62:92], start_time=1437831799.461152, duration=0.756702, service={\x0aSSL\x0a}, history=ShADda, uid=C3eiCBGOLw3VtHfOj, tunnel=, vlan=, inner_vlan=, successful=T, dpd=, dpd_state=, 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=[ts=1437831799.611764, uid=C3eiCBGOLw3VtHfOj, id=[orig_h=192.168.133.100, orig_p=49655/tcp, resp_h=17.167.150.73, resp_p=443/tcp], version_num=771, version=TLSv12, cipher=TLS_RSA_WITH_RC4_128_MD5, curve=, server_name=p31-keyvalueservice.icloud.com, session_id=, resumed=F, client_ticket_empty_session_seen=F, client_key_exchange_seen=T, server_appdata=0, client_appdata=F, last_alert=, next_protocol=, analyzer_id=, established=T, logged=T, delay_tokens=, cert_chain=[[ts=1437831799.764576, fuid=F1vce92FT1oRjKI328, tx_hosts={\x0a\x0917.167.150.73\x0a}, rx_hosts={\x0a\x09192.168.133.100\x0a}, conn_uids={\x0aC3eiCBGOLw3VtHfOj\x0a}, source=SSL, depth=0, analyzers={\x0aMD5,\x0aSHA1,\x0aX509\x0a}, mime_type=application/x-x509-user-cert, filename=, duration=0 secs, local_orig=, is_orig=F, seen_bytes=1406, total_bytes=, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=1bf9696d9f337805383427e88781d001, sha1=f5ccb1a724133607548b00d8eb402efca3076d58, sha256=, x509=[ts=1437831799.764576, id=F1vce92FT1oRjKI328, certificate=[version=3, serial=053FCE9BA6805B00, subject=C=US,ST=California,O=Apple Inc.,OU=management:idms.group.506364,CN=*.icloud.com, issuer=C=US,O=Apple Inc.,OU=Certification Authority,CN=Apple IST CA 2 - G1, cn=*.icloud.com, not_valid_before=1424184331.0, not_valid_after=1489848331.0, key_alg=rsaEncryption, sig_alg=sha256WithRSAEncryption, key_type=rsa, key_length=2048, exponent=65537, curve=], handle=, extensions=[[name=Authority Information Access, short_name=authorityInfoAccess, oid=1.3.6.1.5.5.7.1.1, critical=F, value=OCSP - URI:http://ocsp.apple.com/ocsp04-appleistca2g101\x0a], [name=X509v3 Subject Key Identifier, short_name=subjectKeyIdentifier, oid=2.5.29.14, critical=F, value=8E:51:A1:0E:0A:9B:1C:04:F7:59:D3:69:2E:23:16:91:0E:AD:06:FB], [name=X509v3 Basic Constraints, short_name=basicConstraints, oid=2.5.29.19, critical=T, value=CA:FALSE], [name=X509v3 Authority Key Identifier, short_name=authorityKeyIdentifier, oid=2.5.29.35, critical=F, value=keyid:D8:7A:94:44:7C:90:70:90:16:9E:DD:17:9C:01:44:03:86:D6:2A:29\x0a], [name=X509v3 Certificate Policies, short_name=certificatePolicies, oid=2.5.29.32, critical=F, value=Policy: 1.2.840.113635.100.5.11.4\x0a User Notice:\x0a Explicit Text: Reliance on this certificate by any party assumes acceptance of any applicable terms and conditions of use and/or certification practice statements.\x0a CPS: http://www.apple.com/certificateauthority/rpa\x0a], [name=X509v3 CRL Distribution Points, short_name=crlDistributionPoints, oid=2.5.29.31, critical=F, value=\x0aFull Name:\x0a URI:http://crl.apple.com/appleistca2g1.crl\x0a], [name=X509v3 Key Usage, short_name=keyUsage, oid=2.5.29.15, critical=T, value=Digital Signature, Key Encipherment], [name=X509v3 Extended Key Usage, short_name=extendedKeyUsage, oid=2.5.29.37, critical=F, value=TLS Web Server Authentication, TLS Web Client Authentication], [name=X509v3 Subject Alternative Name, short_name=subjectAltName, oid=2.5.29.17, critical=F, value=DNS:*.icloud.com]], san=[dns=[*.icloud.com], uri=, email=, ip=, other_fields=F], basic_constraints=[ca=F, path_len=]], extracted=, extracted_cutoff=, extracted_size=], [ts=1437831799.764576, fuid=Fxp53s3wA5G3zdEJg8, tx_hosts={\x0a\x0917.167.150.73\x0a}, rx_hosts={\x0a\x09192.168.133.100\x0a}, conn_uids={\x0aC3eiCBGOLw3VtHfOj\x0a}, source=SSL, depth=0, analyzers={\x0aMD5,\x0aSHA1,\x0aX509\x0a}, mime_type=application/x-x509-ca-cert, filename=, duration=0 secs, local_orig=, is_orig=F, seen_bytes=1092, total_bytes=, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=48f0e38385112eeca5fc9ffd402eaecd, sha1=8e8321ca08b08e3726fe1d82996884eeb5f0d655, sha256=, x509=[ts=1437831799.764576, id=Fxp53s3wA5G3zdEJg8, certificate=[version=3, serial=023A74, subject=C=US,O=Apple Inc.,OU=Certification Authority,CN=Apple IST CA 2 - G1, issuer=CN=GeoTrust Global CA,O=GeoTrust Inc.,C=US, cn=Apple IST CA 2 - G1, not_valid_before=1402933322.0, not_valid_after=1653061322.0, key_alg=rsaEncryption, sig_alg=sha256WithRSAEncryption, key_type=rsa, key_length=2048, exponent=65537, curve=], handle=, extensions=[[name=X509v3 Authority Key Identifier, short_name=authorityKeyIdentifier, oid=2.5.29.35, critical=F, value=keyid:C0:7A:98:68:8D:89:FB:AB:05:64:0C:11:7D:AA:7D:65:B8:CA:CC:4E\x0a], [name=X509v3 Subject Key Identifier, short_name=subjectKeyIdentifier, oid=2.5.29.14, critical=F, value=D8:7A:94:44:7C:90:70:90:16:9E:DD:17:9C:01:44:03:86:D6:2A:29], [name=X509v3 Basic Constraints, short_name=basicConstraints, oid=2.5.29.19, critical=T, value=CA:TRUE, pathlen:0], [name=X509v3 Key Usage, short_name=keyUsage, oid=2.5.29.15, critical=T, value=Certificate Sign, CRL Sign], [name=X509v3 CRL Distribution Points, short_name=crlDistributionPoints, oid=2.5.29.31, critical=F, value=\x0aFull Name:\x0a URI:http://g.symcb.com/crls/gtglobal.crl\x0a], [name=Authority Information Access, short_name=authorityInfoAccess, oid=1.3.6.1.5.5.7.1.1, critical=F, value=OCSP - URI:http://g.symcd.com\x0a], [name=X509v3 Certificate Policies, short_name=certificatePolicies, oid=2.5.29.32, critical=F, value=Policy: 2.16.840.1.113733.1.7.54\x0a CPS: http://www.geotrust.com/resources/cps\x0a]], san=, basic_constraints=[ca=T, path_len=0]], extracted=, extracted_cutoff=, extracted_size=]], cert_chain_fuids=[F1vce92FT1oRjKI328, Fxp53s3wA5G3zdEJg8], client_cert_chain=[], client_cert_chain_fuids=[], subject=C=US,ST=California,O=Apple Inc.,OU=management:idms.group.506364,CN=*.icloud.com, issuer=C=US,O=Apple Inc.,OU=Certification Authority,CN=Apple IST CA 2 - G1, client_subject=, client_issuer=, server_depth=0, client_depth=0], http=, http_state=, 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/broker/remote_event.zeek b/testing/btest/broker/remote_event.zeek index cdf74e15f3..bfe30be1b7 100644 --- a/testing/btest/broker/remote_event.zeek +++ b/testing/btest/broker/remote_event.zeek @@ -87,7 +87,6 @@ event ping(msg: string, n: count) if ( n == events_to_recv ) { - print get_broker_stats(); terminate(); return; } @@ -96,4 +95,9 @@ event ping(msg: string, n: count) Broker::publish("zeek/event/my_topic", e); } +event zeek_done() + { + print get_broker_stats(); + } + @TEST-END-FILE diff --git a/testing/btest/broker/remote_event_any.zeek b/testing/btest/broker/remote_event_any.zeek index ac6721335c..6a6492bb98 100644 --- a/testing/btest/broker/remote_event_any.zeek +++ b/testing/btest/broker/remote_event_any.zeek @@ -92,7 +92,6 @@ event ping(msg: string, n: any) if ( (n as count) == events_to_recv ) { - print get_broker_stats(); terminate(); return; } @@ -104,4 +103,9 @@ event ping(msg: string, n: any) Broker::publish("zeek/event/my_topic", pong, msg, n); } +event zeek_done() + { + print get_broker_stats(); + } + @TEST-END-FILE diff --git a/testing/btest/broker/remote_event_ssl_auth.zeek b/testing/btest/broker/remote_event_ssl_auth.zeek index 7ffdae0bda..49307ac081 100644 --- a/testing/btest/broker/remote_event_ssl_auth.zeek +++ b/testing/btest/broker/remote_event_ssl_auth.zeek @@ -247,7 +247,6 @@ event ping(msg: string, n: count) if ( n == events_to_recv ) { - print get_broker_stats(); terminate(); return; } @@ -256,4 +255,9 @@ event ping(msg: string, n: count) Broker::publish("zeek/event/my_topic", e); } +event zeek_done() + { + print get_broker_stats(); + } + @TEST-END-FILE diff --git a/testing/btest/broker/remote_log_batch.zeek b/testing/btest/broker/remote_log_batch.zeek new file mode 100644 index 0000000000..46accc3da4 --- /dev/null +++ b/testing/btest/broker/remote_log_batch.zeek @@ -0,0 +1,105 @@ +# @TEST-PORT: BROKER_PORT + +# @TEST-EXEC: btest-bg-run recv "zeek -B broker -b ../recv.zeek >recv.out" +# @TEST-EXEC: btest-bg-run send "zeek -B broker -b ../send.zeek >send.out" + +# @TEST-EXEC: btest-bg-wait 45 +# @TEST-EXEC: btest-diff recv/recv.out +# @TEST-EXEC: btest-diff recv/test.log +# @TEST-EXEC: btest-diff send/send.out +# @TEST-EXEC: btest-diff send/test.log + +@TEST-START-FILE common.zeek + +redef exit_only_after_terminate = T; + +module Test; + +export { + redef enum Log::ID += { LOG }; + + type Info: record { + msg: string &log; + nolog: string &default="no"; + num: count &log; + }; +} + +event zeek_init() &priority=5 + { + Log::create_stream(Test::LOG, [$columns=Test::Info]); + } + +event Broker::peer_lost(endpoint: Broker::EndpointInfo, msg: string) + { + terminate(); + } + +event quit() + { + terminate(); + } + +@TEST-END-FILE + +@TEST-START-FILE recv.zeek + + +@load ./common + +event zeek_init() + { + Broker::subscribe("zeek/"); + Broker::listen("127.0.0.1", to_port(getenv("BROKER_PORT"))); + } + +event Broker::peer_removed(endpoint: Broker::EndpointInfo, msg: string) + { + terminate(); + } + +@TEST-END-FILE + +@TEST-START-FILE send.zeek + +@load ./common + +event zeek_init() + { + Broker::peer("127.0.0.1", to_port(getenv("BROKER_PORT"))); + } + +global n = 0; +global done = F; + +event die() + { + terminate(); + } + +event do_write() + { + Log::write(Test::LOG, [$msg = "ping", $num = n]); + ++n; + + if ( n == 1 ) + schedule .1secs { do_write() }; + else + done = T; + } + +event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string) + { + print "Broker::peer_added", endpoint$network$address; + event do_write(); + } + +module Broker; + +event Broker::log_flush() + { + if ( done ) + Broker::publish("zeek/quit", quit); + } + +@TEST-END-FILE diff --git a/testing/btest/broker/remote_log_types.zeek b/testing/btest/broker/remote_log_types.zeek index 4ea384e5f6..a14a12586d 100644 --- a/testing/btest/broker/remote_log_types.zeek +++ b/testing/btest/broker/remote_log_types.zeek @@ -91,6 +91,8 @@ function foo(i : count) : string return "Bar"; } +global done = F; + event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string) { print "Broker::peer_added", endpoint$network$address; @@ -118,7 +120,15 @@ event Broker::peer_added(endpoint: Broker::EndpointInfo, msg: string) $f=foo ]); - Broker::publish("zeek/", quit_receiver); + done = T; + } + +module Broker; + +event Broker::log_flush() + { + if ( done ) + Broker::publish("zeek/", quit_receiver); } @TEST-END-FILE diff --git a/testing/btest/language/paraglob-serialization.zeek b/testing/btest/language/paraglob-serialization.zeek index c9ffe9df4c..c5d5d516dd 100644 --- a/testing/btest/language/paraglob-serialization.zeek +++ b/testing/btest/language/paraglob-serialization.zeek @@ -88,7 +88,6 @@ event ping(msg: opaque of paraglob, n: count) print "is_remote should be T, and is", is_remote_event(); if ( n > events_to_recv ) { - print get_broker_stats(); terminate(); return; }