Merge remote-tracking branch 'origin/topic/awelzel/no-more-segment-profiler'

* origin/topic/awelzel/no-more-segment-profiler:
  segment_profiling: Remove SegmentProfiler and load_sample event
This commit is contained in:
Arne Welzel 2024-01-03 12:24:36 +01:00
commit d01b0bafdb
18 changed files with 45 additions and 281 deletions

27
CHANGES
View file

@ -1,3 +1,30 @@
6.2.0-dev.307 | 2024-01-03 12:25:03 +0100
* segment_profiling: Remove SegmentProfiler and load_sample event (Arne Welzel, Corelight)
While it seems interesting functionality, this hasn't been documented,
maintained or knowingly leveraged for many years.
There are various other approaches today, too:
* We track the number of event handler invocations regardless of
profiling. It's possible to approximate a load_sample event by
comparing the result of two get_event_stats() calls. Or, visualize
the corresponding counters in a Prometheus setup to get an idea of
event/s broken down by event names.
* HookCallFunction() allows to intercept script execution, including
measuring the time execution takes.
* The global call_stack and g_frame_stack can be used from plugins
(and even external processes) to walk the Zeek script stack at certain
points to implement a sampling profiler.
* USDT probes or more plugin hooks will likely be preferred over Zeek
builtin functionality in the future.
Relates to #3458
6.2.0-dev.305 | 2024-01-03 09:38:17 +0000
* Avoid extra copies in threading_field_to_data (Dominik Charousset)

5
NEWS
View file

@ -23,6 +23,9 @@ Breaking Changes
SOURCES ...
)
- The "segment_profiling" functionality and ``load_sample`` event have been removed
without deprecation. This functionality was unmaintained and not known to be used.
New Functionality
-----------------
@ -98,7 +101,7 @@ New Functionality
Note, the message argument can currently still be specified as a Zeek identifier
referring to a script-level string value. If used, this is disambiguated behind
the scenes for the first variant. Specifying ``msg`` as a Zeek identifier has
been deprecated with the new event support and will be removed in the future.
been deprecated with the new event support and will be removed in the future.
Note that matches for signatures with custom events will not be recorded in
``signatures.log``. This log is based on the generation of ``signature_match()``

View file

@ -1 +1 @@
6.2.0-dev.305
6.2.0-dev.307

View file

@ -4384,11 +4384,6 @@ type signature_state: record {
payload_size: count; ##< Payload size of the first matching packet of current endpoint.
};
# Type used to report load samples via :zeek:see:`load_sample`. For now, it's a
# set of names (event names, source file names, and perhaps ``<source file, line
# number>``), which were seen during the sample.
type load_sample_info: set[string];
## A BitTorrent peer.
##
## .. zeek:see:: bittorrent_peer_set
@ -5025,27 +5020,21 @@ const log_rotate_base_time = "0:00" &redef;
## Write profiling info into this file in regular intervals. The easiest way to
## activate profiling is loading :doc:`/scripts/policy/misc/profiling.zeek`.
##
## .. zeek:see:: profiling_interval expensive_profiling_multiple segment_profiling
## .. zeek:see:: profiling_interval expensive_profiling_multiple
global profiling_file: file &redef;
## Update interval for profiling (0 disables). The easiest way to activate
## profiling is loading :doc:`/scripts/policy/misc/profiling.zeek`.
##
## .. zeek:see:: profiling_file expensive_profiling_multiple segment_profiling
## .. zeek:see:: profiling_file expensive_profiling_multiple
const profiling_interval = 0 secs &redef;
## Multiples of :zeek:see:`profiling_interval` at which (more expensive) memory
## profiling is done (0 disables).
##
## .. zeek:see:: profiling_interval profiling_file segment_profiling
## .. zeek:see:: profiling_interval profiling_file
const expensive_profiling_multiple = 0 &redef;
## If true, then write segment profiling information (very high volume!)
## in addition to profiling statistics.
##
## .. zeek:see:: profiling_interval expensive_profiling_multiple profiling_file
const segment_profiling = F &redef;
## Output modes for packet profiling information.
##
## .. zeek:see:: pkt_profile_mode pkt_profile_freq pkt_profile_file
@ -5071,14 +5060,6 @@ const pkt_profile_freq = 0.0 &redef;
## .. zeek:see:: pkt_profile_modes pkt_profile_freq pkt_profile_mode
global pkt_profile_file: file &redef;
## Rate at which to generate :zeek:see:`load_sample` events. As all
## events, the event is only generated if you've also defined a
## :zeek:see:`load_sample` handler. Units are inverse number of packets; e.g.,
## a value of 20 means "roughly one in every 20 packets".
##
## .. zeek:see:: load_sample
global load_sample_freq = 20 &redef;
## Whether to attempt to automatically detect SYN/FIN/RST-filtered trace
## and not report missing segments for such connections.
## If this is enabled, then missing data at the end of connections may not

View file

@ -120,8 +120,6 @@ void EventMgr::Drain() {
if ( event_queue_flush_point )
Enqueue(event_queue_flush_point, Args{});
detail::SegmentProfiler prof(detail::segment_logger, "draining-events");
PLUGIN_HOOK_VOID(HOOK_DRAIN_EVENTS, HookDrainEvents());
draining = true;

View file

@ -308,11 +308,6 @@ bool ScriptFunc::IsPure() const {
}
ValPtr ScriptFunc::Invoke(zeek::Args* args, Frame* parent) const {
SegmentProfiler prof(segment_logger, location);
if ( sample_logger )
sample_logger->FunctionSeen(this);
auto [handled, hook_result] =
PLUGIN_HOOK_WITH_RESULT(HOOK_CALL_FUNCTION, HookCallFunction(this, parent, args), empty_hook_result);
@ -366,9 +361,6 @@ ValPtr ScriptFunc::Invoke(zeek::Args* args, Frame* parent) const {
if ( body.disabled )
continue;
if ( sample_logger )
sample_logger->LocationSeen(body.stmts->GetLocationInfo());
// Fill in the rest of the frame with the function's arguments.
for ( auto j = 0u; j < args->size(); ++j ) {
const auto& arg = (*args)[j];
@ -715,11 +707,6 @@ ValPtr BuiltinFunc::Invoke(Args* args, Frame* parent) const {
if ( spm )
spm->StartInvocation(this);
SegmentProfiler prof(segment_logger, Name());
if ( sample_logger )
sample_logger->FunctionSeen(this);
auto [handled, hook_result] =
PLUGIN_HOOK_WITH_RESULT(HOOK_CALL_FUNCTION, HookCallFunction(this, parent, args), empty_hook_result);

View file

@ -168,12 +168,9 @@ int other_addr_anonymization;
double profiling_interval;
int expensive_profiling_multiple;
int segment_profiling;
int pkt_profile_mode;
double pkt_profile_freq;
int load_sample_freq;
int packet_filter_default;
int sig_max_group_size;
@ -317,13 +314,10 @@ void init_net_var() {
expensive_profiling_multiple = id::find_val("expensive_profiling_multiple")->AsCount();
profiling_interval = id::find_val("profiling_interval")->AsInterval();
segment_profiling = id::find_val("segment_profiling")->AsBool();
pkt_profile_mode = id::find_val("pkt_profile_mode")->InternalInt();
pkt_profile_freq = id::find_val("pkt_profile_freq")->AsDouble();
load_sample_freq = id::find_val("load_sample_freq")->AsCount();
dpd_reassemble_first_packets = id::find_val("dpd_reassemble_first_packets")->AsBool();
dpd_buffer_size = id::find_val("dpd_buffer_size")->AsCount();
dpd_max_packets = id::find_val("dpd_max_packets")->AsCount();

View file

@ -71,10 +71,8 @@ extern double connection_status_update_interval;
extern double profiling_interval;
extern int expensive_profiling_multiple;
extern int segment_profiling;
extern int pkt_profile_mode;
extern double pkt_profile_freq;
extern int load_sample_freq;
extern int packet_filter_default;

View file

@ -217,8 +217,6 @@ void init_run(const std::optional<std::string>& interface, const std::optional<s
}
void expire_timers() {
zeek::detail::SegmentProfiler prof(zeek::detail::segment_logger, "expiring-timers");
current_dispatched +=
zeek::detail::timer_mgr->Advance(network_time, zeek::detail::max_timer_expires - current_dispatched);
}
@ -241,32 +239,9 @@ void dispatch_packet(Packet* pkt, iosource::PktSrc* pkt_src) {
processing_start_time = t;
expire_timers();
zeek::detail::SegmentProfiler* sp = nullptr;
if ( load_sample ) {
static uint32_t load_freq = 0;
if ( load_freq == 0 )
load_freq = uint32_t(0xffffffff) / uint32_t(zeek::detail::load_sample_freq);
if ( uint32_t(util::detail::random_number() & 0xffffffff) < load_freq ) {
// Drain the queued timer events so they're not
// charged against this sample.
event_mgr.Drain();
zeek::detail::sample_logger = std::make_shared<zeek::detail::SampleLogger>();
sp = new zeek::detail::SegmentProfiler(zeek::detail::sample_logger, "load-samp");
}
}
packet_mgr->ProcessPacket(pkt);
event_mgr.Drain();
if ( sp ) {
delete sp;
zeek::detail::sample_logger = nullptr;
}
processing_start_time = 0.0; // = "we're not processing now"
current_dispatched = 0;

View file

@ -1,5 +1,9 @@
#include "zeek/Stats.h"
#include <sys/resource.h>
#include <sys/time.h>
#include <sys/types.h>
#include "zeek/Conn.h"
#include "zeek/DNS_Mgr.h"
#include "zeek/Event.h"
@ -53,7 +57,7 @@ void ProfileTimer::Dispatch(double t, bool is_expire) {
timer_mgr->Add(new ProfileTimer(run_state::network_time + interval, logger, interval));
}
ProfileLogger::ProfileLogger(zeek::File* arg_file, double interval) : SegmentStatsReporter() {
ProfileLogger::ProfileLogger(zeek::File* arg_file, double interval) {
file = arg_file;
log_count = 0;
timer_mgr->Add(new ProfileTimer(1, this, interval));
@ -264,64 +268,6 @@ void ProfileLogger::Log() {
}
}
void ProfileLogger::SegmentProfile(const char* name, const Location* loc, double dtime, int dmem) {
if ( name )
file->Write(util::fmt("%.06f segment-%s dt=%.06f dmem=%d\n", run_state::network_time, name, dtime, dmem));
else if ( loc )
file->Write(util::fmt("%.06f segment-%s:%d dt=%.06f dmem=%d\n", run_state::network_time,
loc->filename ? loc->filename : "nofile", loc->first_line, dtime, dmem));
else
file->Write(util::fmt("%.06f segment-XXX dt=%.06f dmem=%d\n", run_state::network_time, dtime, dmem));
}
SampleLogger::SampleLogger() {
static TableType* load_sample_info = nullptr;
if ( ! load_sample_info )
load_sample_info = id::find_type("load_sample_info")->AsTableType();
load_samples = new TableVal({NewRef{}, load_sample_info});
}
SampleLogger::~SampleLogger() { Unref(load_samples); }
void SampleLogger::FunctionSeen(const Func* func) {
auto idx = make_intrusive<StringVal>(func->Name());
load_samples->Assign(std::move(idx), nullptr);
}
void SampleLogger::LocationSeen(const Location* loc) {
auto idx = make_intrusive<StringVal>(loc->filename);
load_samples->Assign(std::move(idx), nullptr);
}
void SampleLogger::SegmentProfile(const char* /* name */, const Location* /* loc */, double dtime, int dmem) {
if ( load_sample )
event_mgr.Enqueue(load_sample, IntrusivePtr{NewRef{}, load_samples},
make_intrusive<IntervalVal>(dtime, Seconds), val_mgr->Int(dmem));
}
void SegmentProfiler::Init() { getrusage(RUSAGE_SELF, &initial_rusage); }
void SegmentProfiler::Report() {
struct rusage final_rusage;
getrusage(RUSAGE_SELF, &final_rusage);
double start_time = double(initial_rusage.ru_utime.tv_sec) + double(initial_rusage.ru_utime.tv_usec) / 1e6 +
double(initial_rusage.ru_stime.tv_sec) + double(initial_rusage.ru_stime.tv_usec) / 1e6;
double stop_time = double(final_rusage.ru_utime.tv_sec) + double(final_rusage.ru_utime.tv_usec) / 1e6 +
double(final_rusage.ru_stime.tv_sec) + double(final_rusage.ru_stime.tv_usec) / 1e6;
int start_mem = initial_rusage.ru_maxrss * 1024;
int stop_mem = initial_rusage.ru_maxrss * 1024;
double dtime = stop_time - start_time;
int dmem = stop_mem - start_mem;
reporter->SegmentProfile(name, loc, dtime, dmem);
}
PacketProfiler::PacketProfiler(unsigned int mode, double freq, File* arg_file) {
update_mode = mode;
update_freq = freq;

View file

@ -4,103 +4,31 @@
#include "zeek/zeek-config.h"
#include <sys/resource.h>
#include <sys/time.h>
#include <sys/types.h>
#include <cstdint>
#include <memory>
namespace zeek {
class File;
class Func;
class TableVal;
namespace detail {
class Location;
// Object called by SegmentProfiler when it is done and reports its
// cumulative CPU/memory statistics.
class SegmentStatsReporter {
public:
SegmentStatsReporter() {}
virtual ~SegmentStatsReporter() {}
virtual void SegmentProfile(const char* name, const Location* loc, double dtime, int dmem) = 0;
};
// A SegmentProfiler tracks how much CPU and memory is consumed
// across its lifetime.
//
// ### This needs porting to Linux. It could also be improved by
// better efforts at measuring its own overhead.
class SegmentProfiler {
public:
// The constructor takes some way of identifying the segment.
SegmentProfiler(std::shared_ptr<SegmentStatsReporter> arg_reporter, const char* arg_name)
: reporter(std::move(arg_reporter)), name(arg_name), loc() {
if ( reporter )
Init();
}
SegmentProfiler(std::shared_ptr<SegmentStatsReporter> arg_reporter, const Location* arg_loc)
: reporter(std::move(arg_reporter)), name(), loc(arg_loc) {
if ( reporter )
Init();
}
~SegmentProfiler() {
if ( reporter )
Report();
}
protected:
void Init();
void Report();
std::shared_ptr<SegmentStatsReporter> reporter;
const char* name;
const Location* loc;
struct rusage initial_rusage;
};
class ProfileLogger final : public SegmentStatsReporter {
class ProfileLogger final {
public:
ProfileLogger(zeek::File* file, double interval);
~ProfileLogger() override;
~ProfileLogger();
void Log();
zeek::File* File() { return file; }
protected:
void SegmentProfile(const char* name, const Location* loc, double dtime, int dmem) override;
private:
zeek::File* file;
unsigned int log_count;
};
// Generates load_sample() events.
class SampleLogger final : public SegmentStatsReporter {
public:
SampleLogger();
~SampleLogger() override;
// These are called to report that a given function or location
// has been seen during the sampling.
void FunctionSeen(const Func* func);
void LocationSeen(const Location* loc);
protected:
void SegmentProfile(const char* name, const Location* loc, double dtime, int dmem) override;
TableVal* load_samples;
};
extern std::shared_ptr<ProfileLogger> profiling_logger;
extern std::shared_ptr<ProfileLogger> segment_logger;
extern std::shared_ptr<SampleLogger> sample_logger;
// Connection statistics.
extern uint64_t killed_by_inactivity;

View file

@ -558,20 +558,6 @@ event net_weird%(name: string, addl: string%);
event file_weird%(name: string, f: fa_file, addl: string, source: string%);
event file_weird%(name: string, f: fa_file, addl: string%);
## Generated regularly for the purpose of profiling Zeek's processing. This event
## is raised for every :zeek:id:`load_sample_freq` packet. For these packets,
## Zeek records script-level functions executed during their processing as well
## as further internal locations. By sampling the processing in this form, one
## can understand where Zeek spends its time.
##
## samples: A set with functions and locations seen during the processing of
## the sampled packet.
##
## CPU: The CPU time spent on processing the sampled packet.
##
## dmem: The difference in memory usage caused by processing the sampled packet.
event load_sample%(samples: load_sample_info, CPU: interval, dmem: int%);
## Generated when a signature matches. Zeek's signature engine provides
## high-performance pattern matching separately from the normal script
## processing. If a signature with an ``event`` action matches, this event is

View file

@ -101,7 +101,6 @@ void Manager::ProcessPacket(Packet* packet) {
DBG_LOG(DBG_PACKET_ANALYSIS, "Analyzing packet %ld, ts=%.3f...", ++counter, packet->time);
#endif
zeek::detail::SegmentProfiler prof(detail::segment_logger, "dispatching-packet");
if ( pkt_profiler )
pkt_profiler->ProfilePkt(zeek::run_state::processing_start_time, packet->cap_len);

View file

@ -1,5 +1,7 @@
%%{ // C segment
#include <sys/resource.h>
#include "zeek/util.h"
#include "zeek/threading/Manager.h"
#include "zeek/broker/Manager.h"

View file

@ -183,8 +183,6 @@ std::vector<std::string> zeek::detail::zeek_script_prefixes;
zeek::detail::Stmt* zeek::detail::stmts = nullptr;
zeek::EventRegistry* zeek::event_registry = nullptr;
std::shared_ptr<zeek::detail::ProfileLogger> zeek::detail::profiling_logger;
std::shared_ptr<zeek::detail::ProfileLogger> zeek::detail::segment_logger;
std::shared_ptr<zeek::detail::SampleLogger> zeek::detail::sample_logger;
zeek::detail::FragmentManager* zeek::detail::fragment_mgr = nullptr;
@ -993,9 +991,6 @@ SetupResult setup(int argc, char** argv, Options* zopts) {
if ( profiling_interval > 0 ) {
const auto& profiling_file = id::find_val("profiling_file");
profiling_logger = std::make_shared<ProfileLogger>(profiling_file->AsFile(), profiling_interval);
if ( segment_profiling )
segment_logger = profiling_logger;
}
if ( ! run_state::reading_live && ! run_state::reading_traces &&

View file

@ -2,7 +2,6 @@
0.000000 zeek_init
XXXXXXXXXX.XXXXXX network_time_init
XXXXXXXXXX.XXXXXX Broker::log_flush
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_connection
[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=0, num_bytes_ip=0, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=0, state=0, num_pkts=0, num_bytes_ip=0, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=0 secs, service={\x0a\x0a}, history=D, uid=CHhAvVGS1DHFjwGM9, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks=<uninitialized>, smtp=<uninitialized>, smtp_state=<uninitialized>]
@ -21,9 +20,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=76, cap_len=76, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=62, id=9482, DF=F, MF=F, offset=0, ttl=128, p=17, sum=65420, src=10.10.1.4, dst=10.10.1.1], ip6=<uninitialized>, tcp=<uninitialized>, udp=[sport=56166/udp, dport=53/udp, ulen=42], icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=0, num_bytes_ip=0, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=34.0 msecs 24.953842 usecs, service={\x0a\x0a}, history=Dd, uid=CHhAvVGS1DHFjwGM9, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks=<uninitialized>, smtp=<uninitialized>, smtp_state=<uninitialized>]
@ -268,7 +264,6 @@ XXXXXXXXXX.XXXXXX tcp_packet
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=60, cap_len=60, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=40, id=8675, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17585, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727269, ack=2126795706, hl=20, dl=0, reserved=0, flags=16, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -340,9 +335,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=191, cap_len=191, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=177, id=8676, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17447, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727269, ack=2126795706, hl=20, dl=137, reserved=0, flags=24, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=21, 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=4, num_bytes_ip=486, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=1.0 sec 39.0 msecs 682.865143 usecs, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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=<uninitialized>, rcptto=<uninitialized>, date=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=250 HELP, path=[74.53.140.153, 10.10.1.4], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=F, process_smtp_headers=T, entity_count=0, entity=<uninitialized>, fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=F, trans_rcpt_to_seen=F, invalid_transactions=0, analyzer_id=6, mime_depth=0]]
@ -428,7 +420,6 @@ XXXXXXXXXX.XXXXXX smtp_request
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=84, cap_len=84, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=70, id=9513, DF=T, MF=F, offset=0, ttl=128, p=6, sum=62380, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126795718, ack=2934727424, hl=20, dl=30, reserved=0, flags=24, win=65199], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -459,10 +450,6 @@ XXXXXXXXXX.XXXXXX smtp_reply
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=72, cap_len=72, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=58, id=8678, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17564, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727424, ack=2126795748, hl=20, dl=18, reserved=0, flags=24, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -492,9 +479,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=72, cap_len=72, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=58, id=9518, DF=T, MF=F, offset=0, ttl=128, p=6, sum=62387, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126795748, ack=2934727442, hl=20, dl=18, reserved=0, flags=24, win=65181], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX Broker::log_flush
XXXXXXXXXX.XXXXXX new_packet
@ -589,7 +573,6 @@ XXXXXXXXXX.XXXXXX smtp_reply
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=62, cap_len=62, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=48, id=8680, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17572, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727472, ack=2126795802, hl=20, dl=8, reserved=0, flags=24, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -619,9 +602,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=93, cap_len=93, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=79, id=9528, DF=T, MF=F, offset=0, ttl=128, p=6, sum=62356, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126795802, ack=2934727480, hl=20, dl=39, reserved=0, flags=24, win=65143], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=144, 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=8, num_bytes_ip=720, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=2.0 secs 790.0 msecs 662.050247 usecs, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=250 OK, path=[74.53.140.153, 10.10.1.4], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=T, process_smtp_headers=T, entity_count=0, entity=<uninitialized>, fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=0]]
@ -685,7 +665,6 @@ XXXXXXXXXX.XXXXXX raw_packet
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX Broker::log_flush
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=XXXXXXXXXX.XXXXXX, duration=3.0 secs 132.0 msecs 632.97081 usecs, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=250 Accepted, path=[74.53.140.153, 10.10.1.4], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=T, process_smtp_headers=T, entity_count=1, entity=[filename=<uninitialized>], fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=1]]
[1] p: pkt_hdr = [ip=[hl=20, tos=96, len=96, id=8682, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17522, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727494, ack=2126795847, hl=20, dl=56, reserved=0, flags=24, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
@ -715,9 +694,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=110, cap_len=110, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=96, id=8682, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17522, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727494, ack=2126795847, hl=20, dl=56, reserved=0, flags=24, win=5840], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=1610, 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=10, num_bytes_ip=870, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=3.0 secs 163.0 msecs 697.004318 usecs, service={\x0aSMTP\x0a}, history=ShAdDa, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=354 Enter message, ending with "." on a line by itself, path=[74.53.140.153, 10.10.1.4], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=T, process_smtp_headers=T, entity_count=1, entity=[filename=<uninitialized>], fuids=[]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=1]]
@ -2934,7 +2910,6 @@ XXXXXXXXXX.XXXXXX tcp_packet
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=60, cap_len=60, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=40, id=8684, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17576, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727550, ack=2126798751, hl=20, dl=0, reserved=0, flags=16, win=11616], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -2958,9 +2933,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=1506, cap_len=1506, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=1492, id=9558, DF=T, MF=F, offset=0, ttl=128, p=6, sum=60913, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126800203, ack=2934727550, hl=20, dl=1452, reserved=0, flags=16, win=65073], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=7410, state=4, num_pkts=17, num_bytes_ip=12486, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=12, num_bytes_ip=950, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=3.0 secs 940.0 msecs 768.003464 usecs, service={\x0aSMTP\x0a}, history=ShAdDaT, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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" <gurpartap@patriots.in>, to={\x0a<raj_deol2002in@yahoo.co.in>\x0a}, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<000301ca4581$ef9e57f0$cedb07d0$@in>, in_reply_to=<uninitialized>, subject=SMTP, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, 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, process_smtp_headers=F, entity_count=5, entity=[filename=NEWS.txt], fuids=[FmFp351N5nhsMmAfQg, Fqrb1K5DWEfgy4WU2, FEFYSd1s8Onn9LynKj]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=5]]
@ -3937,7 +3909,6 @@ XXXXXXXXXX.XXXXXX smtp_data
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=1506, cap_len=1506, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=1492, id=9560, DF=T, MF=F, offset=0, ttl=128, p=6, sum=60911, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126803107, ack=2934727550, hl=20, dl=1452, reserved=0, flags=24, win=65073], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -4341,12 +4312,8 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=1506, cap_len=1506, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=1492, id=9561, DF=T, MF=F, offset=0, ttl=128, p=6, sum=60910, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126804559, ack=2934727550, hl=20, dl=1452, reserved=0, flags=16, win=65073], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX Broker::log_flush
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=10314, state=4, num_pkts=20, num_bytes_ip=16962, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=13, num_bytes_ip=990, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=4.0 secs 305.0 msecs 548.906326 usecs, service={\x0aSMTP\x0a}, history=ShAdDaT, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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" <gurpartap@patriots.in>, to={\x0a<raj_deol2002in@yahoo.co.in>\x0a}, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<000301ca4581$ef9e57f0$cedb07d0$@in>, in_reply_to=<uninitialized>, subject=SMTP, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, 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, process_smtp_headers=F, entity_count=5, entity=[filename=NEWS.txt], fuids=[FmFp351N5nhsMmAfQg, Fqrb1K5DWEfgy4WU2, FEFYSd1s8Onn9LynKj]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=5]]
[1] p: pkt_hdr = [ip=[hl=20, tos=96, len=40, id=8686, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17574, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727550, ack=2126801655, hl=20, dl=0, reserved=0, flags=16, win=17424], udp=<uninitialized>, icmp=<uninitialized>]
@ -4364,9 +4331,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=60, cap_len=60, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=40, id=8686, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17574, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727550, ack=2126801655, hl=20, dl=0, reserved=0, flags=16, win=17424], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=11766, state=4, num_pkts=20, num_bytes_ip=16962, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=462, state=4, num_pkts=14, num_bytes_ip=1030, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=4.0 secs 305.0 msecs 582.046509 usecs, service={\x0aSMTP\x0a}, history=ShAdDaT, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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" <gurpartap@patriots.in>, to={\x0a<raj_deol2002in@yahoo.co.in>\x0a}, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<000301ca4581$ef9e57f0$cedb07d0$@in>, in_reply_to=<uninitialized>, subject=SMTP, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, 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, process_smtp_headers=F, entity_count=5, entity=[filename=NEWS.txt], fuids=[FmFp351N5nhsMmAfQg, Fqrb1K5DWEfgy4WU2, FEFYSd1s8Onn9LynKj]], smtp_state=[helo=GP, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=T, trans_rcpt_to_seen=T, invalid_transactions=0, analyzer_id=6, mime_depth=5]]
@ -6044,7 +6008,6 @@ XXXXXXXXXX.XXXXXX connection_EOF
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=54, cap_len=54, src=00:e0:1c:3c:17:c2, dst=00:1f:33:d9:81:60, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=40, id=9574, DF=T, MF=F, offset=0, ttl=128, p=6, sum=62349, src=10.10.1.4, dst=74.53.140.153], ip6=<uninitialized>, tcp=[sport=1470/tcp, dport=25/tcp, seq=2126810402, ack=2934727578, hl=20, dl=0, reserved=0, flags=17, win=65045], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -6076,9 +6039,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=102, cap_len=102, src=00:1f:33:d9:81:60, dst=00:e0:1c:3c:17:c2, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=96, len=88, id=8695, DF=T, MF=F, offset=0, ttl=50, p=6, sum=17517, src=74.53.140.153, dst=10.10.1.4], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=1470/tcp, seq=2934727578, ack=2126810402, hl=20, dl=48, reserved=0, flags=24, win=34848], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=27, num_bytes_ip=21633, flow_label=0, l2_addr=00:e0:1c:3c:17:c2], resp=[size=538, state=5, num_pkts=23, num_bytes_ip=1466, flow_label=0, l2_addr=00:1f:33:d9:81:60], start_time=XXXXXXXXXX.XXXXXX, duration=7.0 secs 576.0 msecs 952.934265 usecs, service={\x0aSMTP\x0a}, history=ShAdDaTFf, uid=ClEkJM2Vm5giqnMf4h, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, 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=<uninitialized>, rcptto=<uninitialized>, date=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=221 xc90.websitewelcome.com closing connection, path=[74.53.140.153, 10.10.1.4], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=F, process_smtp_headers=T, entity_count=0, entity=<uninitialized>, fuids=[]], smtp_state=[helo=GP, messages_transferred=1, pending_messages=<uninitialized>, trans_mail_from_seen=F, trans_rcpt_to_seen=F, invalid_transactions=0, analyzer_id=6, mime_depth=5]]
@ -6530,7 +6490,6 @@ XXXXXXXXXX.XXXXXX smtp_reply
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=101, cap_len=101, src=00:08:ca:cc:ad:4c, dst=58:b0:35:86:54:8d, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=87, id=51483, DF=T, MF=F, offset=0, ttl=64, p=6, sum=58729, src=192.168.133.102, dst=192.168.133.100], ip6=<uninitialized>, tcp=[sport=25/tcp, dport=49648/tcp, seq=2131788255, ack=3976465341, hl=32, dl=35, reserved=0, flags=24, win=227], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -6573,9 +6532,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=66, cap_len=66, src=58:b0:35:86:54:8d, dst=00:08:ca:cc:ad:4c, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=52, id=57836, DF=T, MF=F, offset=0, ttl=64, p=6, sum=52411, src=192.168.133.100, dst=192.168.133.102], ip6=<uninitialized>, tcp=[sport=49648/tcp, dport=25/tcp, seq=3976465341, ack=2131788290, hl=32, dl=0, reserved=0, flags=16, win=4116], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
[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=24, state=4, num_pkts=3, num_bytes_ip=168, flow_label=0, l2_addr=58:b0:35:86:54:8d], resp=[size=35, state=4, num_pkts=2, num_bytes_ip=147, flow_label=0, l2_addr=00:08:ca:cc:ad:4c], start_time=XXXXXXXXXX.XXXXXX, duration=26.0 msecs 411.056519 usecs, service={\x0a\x0a}, history=ShAdD, uid=CmES5u32sYpV7JYN, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks={\x0a\x09SMTP::finalize_smtp\x0a\x09{ \x0a\x09if (SMTP::c?$smtp) \x0a\x09\x09SMTP::smtp_message(SMTP::c);\x0a\x0a\x09}\x0a}, smtp=[ts=XXXXXXXXXX.XXXXXX, uid=CmES5u32sYpV7JYN, id=[orig_h=192.168.133.100, orig_p=49648/tcp, resp_h=192.168.133.102, resp_p=25/tcp], trans_depth=1, helo=<uninitialized>, mailfrom=<uninitialized>, rcptto=<uninitialized>, date=<uninitialized>, from=<uninitialized>, to=<uninitialized>, cc=<uninitialized>, reply_to=<uninitialized>, msg_id=<uninitialized>, in_reply_to=<uninitialized>, subject=<uninitialized>, x_originating_ip=<uninitialized>, first_received=<uninitialized>, second_received=<uninitialized>, last_reply=220 uprise ESMTP SubEthaSMTP null, path=[192.168.133.102, 192.168.133.100], user_agent=<uninitialized>, tls=F, process_received_from=T, has_client_activity=F, process_smtp_headers=T, entity_count=0, entity=<uninitialized>, fuids=[]], smtp_state=[helo=<uninitialized>, messages_transferred=0, pending_messages=<uninitialized>, trans_mail_from_seen=F, trans_rcpt_to_seen=F, invalid_transactions=0, analyzer_id=<uninitialized>, mime_depth=0]]
@ -8171,7 +8127,6 @@ XXXXXXXXXX.XXXXXX tcp_options
XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=66, cap_len=66, src=58:b0:35:86:54:8d, dst=cc:b2:55:f4:62:92, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=52, id=6886, DF=T, MF=F, offset=0, ttl=64, p=6, sum=18327, src=192.168.133.100, dst=74.125.71.189], ip6=<uninitialized>, tcp=[sport=49336/tcp, dport=443/tcp, seq=1584252430, ack=3980080343, hl=32, dl=0, reserved=0, flags=16, win=4093], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_packet
@ -8214,9 +8169,6 @@ XXXXXXXXXX.XXXXXX raw_packet
[0] p: raw_pkt_hdr = [l2=[encap=LINK_ETHERNET, len=66, cap_len=66, src=58:b0:35:86:54:8d, dst=cc:b2:55:f4:62:92, vlan=<uninitialized>, inner_vlan=<uninitialized>, eth_type=2048, proto=L3_IPV4], ip=[hl=20, tos=0, len=52, id=3407, DF=T, MF=F, offset=0, ttl=64, p=6, sum=21806, src=192.168.133.100, dst=74.125.71.189], ip6=<uninitialized>, tcp=[sport=49336/tcp, dport=443/tcp, seq=1584252430, ack=3980080343, hl=32, dl=0, reserved=0, flags=16, win=4093], udp=<uninitialized>, icmp=<uninitialized>]
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX load_sample
[2] dmem: int = 0
XXXXXXXXXX.XXXXXX event_queue_flush_point
XXXXXXXXXX.XXXXXX new_connection_contents
[0] c: connection = [id=[orig_h=192.168.133.100, orig_p=49153/tcp, resp_h=17.172.238.21, resp_p=5223/tcp], orig=[size=714, state=3, 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=XXXXXXXXXX.XXXXXX, duration=0 secs, service={\x0a\x0a}, history=D, uid=C37jN32gN3y3AZzyf6, tunnel=<uninitialized>, vlan=<uninitialized>, inner_vlan=<uninitialized>, dpd=<uninitialized>, dpd_state=<uninitialized>, service_violation={\x0a\x0a}, conn=<uninitialized>, extract_orig=F, extract_resp=F, thresholds=<uninitialized>, removal_hooks=<uninitialized>, smtp=<uninitialized>, smtp_state=<uninitialized>]

View file

@ -1,7 +1,7 @@
# @TEST-EXEC: zeek -b -r $TRACES/smtp.trace policy/misc/dump-events %INPUT >all-events.log
# @TEST-EXEC: zeek -b -r $TRACES/smtp.trace policy/misc/dump-events %INPUT DumpEvents::include_args=F >all-events-no-args.log
# @TEST-EXEC: zeek -b -r $TRACES/smtp.trace policy/misc/dump-events %INPUT DumpEvents::include=/smtp_/ >smtp-events.log
# @TEST-EXEC: zeek -b -r $TRACES/smtp.trace policy/misc/dump-events %INPUT DumpEvents::dump_all_events=T | grep -v "CPU: interval\|samples: load_sample_info\|path: string" > really-all-events.log
# @TEST-EXEC: zeek -b -r $TRACES/smtp.trace policy/misc/dump-events %INPUT DumpEvents::dump_all_events=T | grep -v "CPU: interval\|path: string" > really-all-events.log
#
# @TEST-EXEC: btest-diff all-events.log
# @TEST-EXEC: btest-diff all-events-no-args.log

View file

@ -3,13 +3,6 @@
@load policy/misc/stats
event load_sample(samples: load_sample_info, CPU: interval, dmem: int)
{
# This output not part of baseline as it varies, but guess this test
# should still exist to cover potential memory leaks.
print CPU;
}
event zeek_init()
{
# Various fields will be unstable for use in baseline, so use one that is.