diff --git a/CHANGES b/CHANGES index 958e474be1..5fb3d2e023 100644 --- a/CHANGES +++ b/CHANGES @@ -1,4 +1,14 @@ +2.5-137 | 2017-05-04 11:37:48 -0500 + + * Add plugin hooks for log init and writing: HookLogInit and HookLogWrite. + (Corelight) + + * TLS: Fix compile warning (comparison between signed/unsigned). + + This was introduced with the addition of new TLS1.3 extensions. (Johanna Amann) + + 2.5-134 | 2017-05-01 10:34:34 -0500 * Add rename, unlink, and rmdir bifs. (Corelight) diff --git a/VERSION b/VERSION index 17f728fc54..ee6e94cf3e 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -2.5-134 +2.5-137 diff --git a/src/logging/Manager.cc b/src/logging/Manager.cc index 8c720137e8..66a275736a 100644 --- a/src/logging/Manager.cc +++ b/src/logging/Manager.cc @@ -15,6 +15,8 @@ #include "WriterFrontend.h" #include "WriterBackend.h" #include "logging.bif.h" +#include "../plugin/Plugin.h" +#include "../plugin/Manager.h" #ifdef ENABLE_BROKER #include "broker/Manager.h" @@ -62,6 +64,7 @@ struct Manager::WriterInfo { WriterFrontend* writer; WriterBackend::WriterInfo* info; bool from_remote; + bool hook_initialized; string instantiating_filter; }; @@ -840,12 +843,26 @@ bool Manager::Write(EnumVal* id, RecordVal* columns) path = filter->path = filter->path_val->AsString()->CheckString(); } + WriterBackend::WriterInfo* info = 0; WriterFrontend* writer = 0; if ( w != stream->writers.end() ) { // We know this writer already. writer = w->second->writer; + info = w->second->info; + + if ( ! w->second->hook_initialized ) + { + auto wi = w->second; + wi->hook_initialized = true; + PLUGIN_HOOK_VOID(HOOK_LOG_INIT, + HookLogInit(filter->writer->Type()->AsEnumType()->Lookup(filter->writer->InternalInt()), + wi->instantiating_filter, filter->local, + filter->remote, *wi->info, + filter->num_fields, + filter->fields)); + } } else @@ -874,7 +891,7 @@ bool Manager::Write(EnumVal* id, RecordVal* columns) arg_fields[j] = new threading::Field(*filter->fields[j]); } - WriterBackend::WriterInfo* info = new WriterBackend::WriterInfo; + info = new WriterBackend::WriterInfo; info->path = copy_string(path.c_str()); info->network_time = network_time; @@ -909,6 +926,22 @@ bool Manager::Write(EnumVal* id, RecordVal* columns) threading::Value** vals = RecordToFilterVals(stream, filter, columns); + if ( ! PLUGIN_HOOK_WITH_RESULT(HOOK_LOG_WRITE, + HookLogWrite(filter->writer->Type()->AsEnumType()->Lookup(filter->writer->InternalInt()), + filter->name, *info, + filter->num_fields, + filter->fields, vals), + true) ) + { + DeleteVals(filter->num_fields, vals); + +#ifdef DEBUG + DBG_LOG(DBG_LOGGING, "Hook prevented writing to filter '%s' on stream '%s'", + filter->name.c_str(), stream->name.c_str()); +#endif + return true; + } + // Write takes ownership of vals. assert(writer); writer->Write(filter->num_fields, vals); @@ -1165,6 +1198,7 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, WriterBacken winfo->postprocessor = 0; winfo->info = info; winfo->from_remote = from_remote; + winfo->hook_initialized = false; winfo->instantiating_filter = instantiating_filter; // Search for a corresponding filter for the writer/path pair and use its @@ -1214,6 +1248,15 @@ WriterFrontend* Manager::CreateWriter(EnumVal* id, EnumVal* writer, WriterBacken #endif winfo->writer->Init(num_fields, fields); + if ( ! from_remote ) + { + winfo->hook_initialized = true; + PLUGIN_HOOK_VOID(HOOK_LOG_INIT, + HookLogInit(writer->Type()->AsEnumType()->Lookup(writer->InternalInt()), + instantiating_filter, local, remote, + *winfo->info, num_fields, fields)); + } + InstallRotationTimer(winfo); return winfo->writer; diff --git a/src/plugin/Manager.cc b/src/plugin/Manager.cc index c672614957..104bcfbdd5 100644 --- a/src/plugin/Manager.cc +++ b/src/plugin/Manager.cc @@ -712,7 +712,7 @@ void Manager::HookSetupAnalyzerTree(Connection *conn) const if ( HavePluginForHook(META_HOOK_PRE) ) { - args.push_back(conn); + args.push_back(HookArgument(conn)); MetaHookPre(HOOK_SETUP_ANALYZER_TREE, args); } @@ -739,7 +739,7 @@ void Manager::HookUpdateNetworkTime(double network_time) const if ( HavePluginForHook(META_HOOK_PRE) ) { - args.push_back(network_time); + args.push_back(HookArgument(network_time)); MetaHookPre(HOOK_UPDATE_NETWORK_TIME, args); } @@ -762,7 +762,7 @@ void Manager::HookBroObjDtor(void* obj) const if ( HavePluginForHook(META_HOOK_PRE) ) { - args.push_back(obj); + args.push_back(HookArgument(obj)); MetaHookPre(HOOK_BRO_OBJ_DTOR, args); } @@ -779,6 +779,84 @@ void Manager::HookBroObjDtor(void* obj) const MetaHookPost(HOOK_BRO_OBJ_DTOR, args, HookArgument()); } +void Manager::HookLogInit(const std::string& writer, + const std::string& instantiating_filter, + bool local, bool remote, + const logging::WriterBackend::WriterInfo& info, + int num_fields, + const threading::Field* const* fields) const + { + HookArgumentList args; + + if ( HavePluginForHook(META_HOOK_PRE) ) + { + args.push_back(HookArgument(writer)); + args.push_back(HookArgument(instantiating_filter)); + args.push_back(HookArgument(local)); + args.push_back(HookArgument(remote)); + args.push_back(HookArgument(&info)); + args.push_back(HookArgument(num_fields)); + args.push_back(HookArgument(std::make_pair(num_fields, fields))); + MetaHookPre(HOOK_LOG_INIT, args); + } + + hook_list* l = hooks[HOOK_LOG_INIT]; + + if ( l ) + for ( hook_list::iterator i = l->begin(); i != l->end(); ++i ) + { + Plugin* p = (*i).second; + p->HookLogInit(writer, instantiating_filter, local, remote, info, + num_fields, fields); + } + + if ( HavePluginForHook(META_HOOK_POST) ) + MetaHookPost(HOOK_LOG_INIT, args, HookArgument()); + } + +bool Manager::HookLogWrite(const std::string& writer, + const std::string& filter, + const logging::WriterBackend::WriterInfo& info, + int num_fields, + const threading::Field* const* fields, + threading::Value** vals) const + { + HookArgumentList args; + + if ( HavePluginForHook(META_HOOK_PRE) ) + { + args.push_back(HookArgument(writer)); + args.push_back(HookArgument(filter)); + args.push_back(HookArgument(&info)); + args.push_back(HookArgument(num_fields)); + args.push_back(HookArgument(std::make_pair(num_fields, fields))); + args.push_back(HookArgument(vals)); + MetaHookPre(HOOK_LOG_WRITE, args); + } + + hook_list* l = hooks[HOOK_LOG_WRITE]; + + bool result = true; + + if ( l ) + for ( hook_list::iterator i = l->begin(); i != l->end(); ++i ) + { + Plugin* p = (*i).second; + + if ( ! p->HookLogWrite(writer, filter, info, num_fields, fields, + vals) ) + { + result = false; + break; + } + } + + if ( HavePluginForHook(META_HOOK_POST) ) + MetaHookPost(HOOK_LOG_WRITE, args, HookArgument(result)); + + return result; + } + void Manager::MetaHookPre(HookType hook, const HookArgumentList& args) const { hook_list* l = hooks[HOOK_CALL_FUNCTION]; diff --git a/src/plugin/Manager.h b/src/plugin/Manager.h index 2a394b39ee..9ece86bfed 100644 --- a/src/plugin/Manager.h +++ b/src/plugin/Manager.h @@ -291,6 +291,70 @@ public: */ void HookBroObjDtor(void* obj) const; + /** + * Hook into log initialization. This method will be called when a + * logging writer is created. A writer represents a single logging + * filter. The method is called in the main thread, on the node that + * causes a log line to be written. It will _not_ be called on the logger + * node. The function will be called once for every instantiated writer. + * + * @param writer The name of the writer being instantiated. + * + * @param instantiating_filter Name of the filter causing the + * writer instantiation. + * + * @param local True if the filter is logging locally (writer + * thread will be located in same process). + * + * @param remote True if filter is logging remotely (writer thread + * will be located in different thread, typically + * in manager or logger node). + * + * @param info WriterBackend::WriterInfo with information about the writer. + * + * @param num_fields number of fields in the record being written. + * + * @param fields threading::Field description of the fields being logged. + */ + void HookLogInit(const std::string& writer, + const std::string& instantiating_filter, + bool local, bool remote, + const logging::WriterBackend::WriterInfo& info, + int num_fields, + const threading::Field* const* fields) const; + + /** + * Hook into log writing. This method will be called for each log line + * being written by each writer. Each writer represents a single logging + * filter. The method is called in the main thread, on the node that + * causes a log line to be written. It will _not_ be called on the logger + * node. + * This function allows plugins to modify or skip logging of information. + * Note - once a log line is skipped (by returning false), it will not + * passed on to hooks that have not yet been called. + * + * @param writer The name of the writer. + * + * @param filter Name of the filter being written to. + * + * @param info WriterBackend::WriterInfo with information about the writer. + * + * @param num_fields number of fields in the record being written. + * + * @param fields threading::Field description of the fields being logged. + * + * @param vals threading::Values containing the values being written. Values + * can be modified in the Hook. + * + * @return true if log line should be written, false if log line should be + * skipped and not passed on to the writer. + */ + bool HookLogWrite(const std::string& writer, + const std::string& filter, + const logging::WriterBackend::WriterInfo& info, + int num_fields, const threading::Field* const* fields, + threading::Value** vals) const; + /** * Internal method that registers a freshly instantiated plugin with * the manager. diff --git a/src/plugin/Plugin.cc b/src/plugin/Plugin.cc index b0eb19a628..7af9b9dfee 100644 --- a/src/plugin/Plugin.cc +++ b/src/plugin/Plugin.cc @@ -10,6 +10,8 @@ #include "../Desc.h" #include "../Event.h" +#include "../Conn.h" +#include "threading/SerialTypes.h" using namespace plugin; @@ -24,6 +26,8 @@ const char* plugin::hook_name(HookType h) "UpdateNetworkTime", "BroObjDtor", "SetupAnalyzerTree", + "LogInit", + "LogWrite", // MetaHooks "MetaHookPre", "MetaHookPost", @@ -84,6 +88,11 @@ void HookArgument::Describe(ODesc* d) const d->Add(""); break; + case CONN: + if ( arg.conn ) + arg.conn->Describe(d); + break; + case FUNC_RESULT: if ( func_result.first ) { @@ -145,6 +154,60 @@ void HookArgument::Describe(ODesc* d) const case VOIDP: d->Add(""); break; + + case WRITER_INFO: + { + d->Add(arg.winfo->path); + d->Add("("); + d->Add(arg.winfo->network_time); + d->Add(","); + d->Add(arg.winfo->rotation_interval); + d->Add(","); + d->Add(arg.winfo->rotation_base); + + if ( arg.winfo->config.size() > 0 ) + { + bool first = true; + d->Add("config: {"); + + for ( auto& v: arg.winfo->config ) + { + if ( ! first ) + d->Add(", "); + + d->Add(v.first); + d->Add(": "); + d->Add(v.second); + first = false; + } + + d->Add("}"); + } + + d->Add(")"); + } + break; + + case THREAD_FIELDS: + { + d->Add("{"); + + for ( int i=0; i < tfields.first; i++ ) + { + const threading::Field* f = tfields.second[i]; + + if ( i > 0 ) + d->Add(", "); + + d->Add(f->name); + d->Add(" ("); + d->Add(f->TypeName()); + d->Add(")"); + } + + d->Add("}"); + } + break; } } @@ -319,6 +382,22 @@ void Plugin::HookBroObjDtor(void* obj) { } +void Plugin::HookLogInit(const std::string& writer, + const std::string& instantiating_filter, + bool local, bool remote, + const logging::WriterBackend::WriterInfo& info, + int num_fields, const threading::Field* const* fields) + { + } + +bool Plugin::HookLogWrite(const std::string& writer, const std::string& filter, + const logging::WriterBackend::WriterInfo& info, + int num_fields, const threading::Field* const* fields, + threading::Value** vals) + { + return true; + } + void Plugin::MetaHookPre(HookType hook, const HookArgumentList& args) { } diff --git a/src/plugin/Plugin.h b/src/plugin/Plugin.h index 49fa7cdd84..aabec22bc4 100644 --- a/src/plugin/Plugin.h +++ b/src/plugin/Plugin.h @@ -11,16 +11,21 @@ #include "analyzer/Component.h" #include "file_analysis/Component.h" #include "iosource/Component.h" +#include "logging/WriterBackend.h" // We allow to override this externally for testing purposes. #ifndef BRO_PLUGIN_API_VERSION -#define BRO_PLUGIN_API_VERSION 4 +#define BRO_PLUGIN_API_VERSION 5 #endif class ODesc; class Func; class Event; +namespace threading { +struct Field; +} + namespace plugin { class Manager; @@ -39,7 +44,9 @@ enum HookType { HOOK_DRAIN_EVENTS, //< Activates Plugin::HookDrainEvents() HOOK_UPDATE_NETWORK_TIME, //< Activates Plugin::HookUpdateNetworkTime. HOOK_BRO_OBJ_DTOR, //< Activates Plugin::HookBroObjDtor. - HOOK_SETUP_ANALYZER_TREE, //< Activates Plugin::HookSetupAnalyzerTree + HOOK_SETUP_ANALYZER_TREE, //< Activates Plugin::HookAddToAnalyzerTree + HOOK_LOG_INIT, //< Activates Plugin::HookLogInit + HOOK_LOG_WRITE, //< Activates Plugin::HookLogWrite // Meta hooks. META_HOOK_PRE, //< Activates Plugin::MetaHookPre(). @@ -158,7 +165,8 @@ public: * Type of the argument. */ enum Type { - BOOL, DOUBLE, EVENT, FRAME, FUNC, FUNC_RESULT, INT, STRING, VAL, VAL_LIST, VOID, VOIDP + BOOL, DOUBLE, EVENT, FRAME, FUNC, FUNC_RESULT, INT, STRING, VAL, + VAL_LIST, VOID, VOIDP, WRITER_INFO, CONN, THREAD_FIELDS }; /** @@ -169,57 +177,72 @@ public: /** * Constructor with a boolean argument. */ - HookArgument(bool a) { type = BOOL; arg.bool_ = a; } + explicit HookArgument(bool a) { type = BOOL; arg.bool_ = a; } /** * Constructor with a double argument. */ - HookArgument(double a) { type = DOUBLE; arg.double_ = a; } + explicit HookArgument(double a) { type = DOUBLE; arg.double_ = a; } /** * Constructor with an event argument. */ - HookArgument(const Event* a) { type = EVENT; arg.event = a; } + explicit HookArgument(const Event* a) { type = EVENT; arg.event = a; } + + /** + * Constructor with an connection argument. + */ + explicit HookArgument(const Connection* c) { type = CONN; arg.conn = c; } /** * Constructor with a function argument. */ - HookArgument(const Func* a) { type = FUNC; arg.func = a; } + explicit HookArgument(const Func* a) { type = FUNC; arg.func = a; } /** * Constructor with an integer argument. */ - HookArgument(int a) { type = INT; arg.int_ = a; } + explicit HookArgument(int a) { type = INT; arg.int_ = a; } /** * Constructor with a string argument. */ - HookArgument(const std::string& a) { type = STRING; arg_string = a; } + explicit HookArgument(const std::string& a) { type = STRING; arg_string = a; } /** * Constructor with a Bro value argument. */ - HookArgument(const Val* a) { type = VAL; arg.val = a; } + explicit HookArgument(const Val* a) { type = VAL; arg.val = a; } /** * Constructor with a list of Bro values argument. */ - HookArgument(const val_list* a) { type = VAL_LIST; arg.vals = a; } + explicit HookArgument(const val_list* a) { type = VAL_LIST; arg.vals = a; } /** * Constructor with a void pointer argument. */ - HookArgument(void* p) { type = VOIDP; arg.voidp = p; } + explicit HookArgument(void* p) { type = VOIDP; arg.voidp = p; } /** * Constructor with a function result argument. */ - HookArgument(std::pair fresult) { type = FUNC_RESULT; func_result = fresult; } + explicit HookArgument(std::pair fresult) { type = FUNC_RESULT; func_result = fresult; } /** * Constructor with a Frame argument. */ - HookArgument(Frame* f) { type = FRAME; arg.frame = f; } + explicit HookArgument(Frame* f) { type = FRAME; arg.frame = f; } + + /** + * Constructor with a WriterInfo argument. + */ + explicit HookArgument(const logging::WriterBackend::WriterInfo* i) { type = WRITER_INFO; arg.winfo = i; } + + /** + * Constructor with a threading field argument. + */ + explicit HookArgument(const std::pair fpair) { type = THREAD_FIELDS; tfields = fpair; } /** * Returns the value for a boolen argument. The argument's type must @@ -239,6 +262,12 @@ public: */ const Event* AsEvent() const { assert(type == EVENT); return arg.event; } + /** + * Returns the value for an connection argument. The argument's type must + * match accordingly. + */ + const Connection* AsConnection() const { assert(type == CONN); return arg.conn; } + /** * Returns the value for a function argument. The argument's type must * match accordingly. @@ -275,6 +304,18 @@ public: */ const Frame* AsFrame() const { assert(type == FRAME); return arg.frame; } + /** + * Returns the value for a logging WriterInfo argument. The argument's type must + * match accordingly. + */ + const logging::WriterBackend::WriterInfo* AsWriterInfo() const { assert(type == WRITER_INFO); return arg.winfo; } + + /** + * Returns the value for a threading fields argument. The argument's type must + * match accordingly. + */ + const std::pair AsThreadFields() const { assert(type == THREAD_FIELDS); return tfields; } + /** * Returns the value for a list of Bro values argument. The argument's type must * match accordingly. @@ -305,16 +346,19 @@ private: bool bool_; double double_; const Event* event; + const Connection* conn; const Func* func; const Frame* frame; int int_; const Val* val; const val_list* vals; const void* voidp; + const logging::WriterBackend::WriterInfo* winfo; } arg; // Outside union because these have dtors. std::pair func_result; + std::pair tfields; std::string arg_string; }; @@ -663,6 +707,71 @@ protected: */ virtual void HookBroObjDtor(void* obj); + /** + * Hook into log initialization. This method will be called when a + * logging writer is created. A writer represents a single logging + * filter. The method is called in the main thread, on the node that + * causes a log line to be written. It will _not_ be called on the logger + * node. The function will be called each for every instantiated writer. + * + * @param writer The name of the writer being insantiated. + * + * @param instantiating_filter Name of the filter causing the + * writer instantiation. + * + * @param local True if the filter is logging locally (writer + * thread will be located in same process). + * + * @param remote True if filter is logging remotely (writer thread + * will be located in different thread, typically + * in manager or logger node). + * + * @param info WriterBackend::WriterInfo with information about the writer. + * + * @param num_fields number of fields in the record being written. + * + * @param fields threading::Field description of the fields being logged. + */ + virtual void HookLogInit(const std::string& writer, + const std::string& instantiating_filter, + bool local, bool remote, + const logging::WriterBackend::WriterInfo& info, + int num_fields, + const threading::Field* const* fields); + + /** + * Hook into log writing. This method will be called for each log line + * being written by each writer. Each writer represents a single logging + * filter. The method is called in the main thread, on the node that + * causes a log line to be written. It will _not_ be called on the logger + * node. + * This function allows plugins to modify or skip logging of information. + * Note - once a log line is skipped (by returning false), it will not + * passed on to hooks that have not yet been called. + * + * @param writer The name of the writer. + * + * @param filter Name of the filter being written to. + * + * @param info WriterBackend::WriterInfo with information about the writer. + * + * @param num_fields number of fields in the record being written. + * + * @param fields threading::Field description of the fields being logged. + * + * @param vals threading::Values containing the values being written. Values + * can be modified in the Hook. + * + * @return true if log line should be written, false if log line should be + * skipped and not passed on to the writer. + */ + virtual bool HookLogWrite(const std::string& writer, + const std::string& filter, + const logging::WriterBackend::WriterInfo& info, + int num_fields, + const threading::Field* const* fields, + threading::Value** vals); + // Meta hooks. /** diff --git a/src/threading/Formatter.cc b/src/threading/Formatter.cc index 3f366de90a..b881962732 100644 --- a/src/threading/Formatter.cc +++ b/src/threading/Formatter.cc @@ -22,7 +22,7 @@ Formatter::~Formatter() { } -string Formatter::Render(const threading::Value::addr_t& addr) const +string Formatter::Render(const threading::Value::addr_t& addr) { if ( addr.family == IPv4 ) { @@ -90,7 +90,7 @@ threading::Value::addr_t Formatter::ParseAddr(const string &s) const return val; } -string Formatter::Render(const threading::Value::subnet_t& subnet) const +string Formatter::Render(const threading::Value::subnet_t& subnet) { char l[16]; @@ -104,7 +104,7 @@ string Formatter::Render(const threading::Value::subnet_t& subnet) const return s; } -string Formatter::Render(double d) const +string Formatter::Render(double d) { char buf[256]; modp_dtoa(d, buf, 6); diff --git a/src/threading/Formatter.h b/src/threading/Formatter.h index c8337959bf..c564f3c945 100644 --- a/src/threading/Formatter.h +++ b/src/threading/Formatter.h @@ -87,7 +87,7 @@ public: * * @return An ASCII representation of the address. */ - string Render(const threading::Value::addr_t& addr) const; + static string Render(const threading::Value::addr_t& addr); /** * Convert an subnet value into a string. @@ -98,7 +98,7 @@ public: * * @return An ASCII representation of the subnet. */ - string Render(const threading::Value::subnet_t& subnet) const; + static string Render(const threading::Value::subnet_t& subnet); /** * Convert a double into a string. This renders the double with Bro's @@ -110,7 +110,7 @@ public: * * @return An ASCII representation of the double. */ - string Render(double d) const; + static string Render(double d); /** * Convert a string into a TransportProto. The string must be one of diff --git a/testing/btest/Baseline/plugins.hooks/output b/testing/btest/Baseline/plugins.hooks/output index 420d20ae12..fcf29f2b04 100644 --- a/testing/btest/Baseline/plugins.hooks/output +++ b/testing/btest/Baseline/plugins.hooks/output @@ -247,7 +247,7 @@ 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (Weird::LOG, [columns=, ev=Weird::log_weird, path=weird])) -> 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (X509::LOG, [columns=, ev=X509::log_x509, path=x509])) -> 0.000000 MetaHookPost CallFunction(Log::__create_stream, , (mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql])) -> -0.000000 MetaHookPost CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T])) -> +0.000000 MetaHookPost CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1493067689.952434, node=bro, filter=ip or not ip, init=T, success=T])) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Cluster::LOG)) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Communication::LOG)) -> 0.000000 MetaHookPost CallFunction(Log::add_default_filter, , (Conn::LOG)) -> @@ -377,7 +377,7 @@ 0.000000 MetaHookPost CallFunction(Log::create_stream, , (Weird::LOG, [columns=, ev=Weird::log_weird, path=weird])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (X509::LOG, [columns=, ev=X509::log_x509, path=x509])) -> 0.000000 MetaHookPost CallFunction(Log::create_stream, , (mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql])) -> -0.000000 MetaHookPost CallFunction(Log::write, , (PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T])) -> +0.000000 MetaHookPost CallFunction(Log::write, , (PacketFilter::LOG, [ts=1493067689.952434, node=bro, 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, , ()) -> @@ -712,6 +712,8 @@ 0.000000 MetaHookPost LoadFile(base<...>/weird) -> -1 0.000000 MetaHookPost LoadFile(base<...>/x509) -> -1 0.000000 MetaHookPost LoadFile(base<...>/xmpp) -> -1 +0.000000 MetaHookPost LogInit(Log::WRITER_ASCII, default, true, true, packet_filter(0.0,0.0,0.0), 5, {ts (time), node (string), filter (string), init (bool), success (bool)}) -> +0.000000 MetaHookPost LogWrite(Log::WRITER_ASCII, default, packet_filter(0.0,0.0,0.0), 5, {ts (time), node (string), filter (string), init (bool), success (bool)}, ) -> true 0.000000 MetaHookPost QueueEvent(NetControl::init()) -> false 0.000000 MetaHookPost QueueEvent(bro_init()) -> false 0.000000 MetaHookPost QueueEvent(filter_change_tracking()) -> false @@ -964,7 +966,7 @@ 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (Weird::LOG, [columns=, ev=Weird::log_weird, path=weird])) 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (X509::LOG, [columns=, ev=X509::log_x509, path=x509])) 0.000000 MetaHookPre CallFunction(Log::__create_stream, , (mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql])) -0.000000 MetaHookPre CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T])) +0.000000 MetaHookPre CallFunction(Log::__write, , (PacketFilter::LOG, [ts=1493067689.952434, node=bro, filter=ip or not ip, init=T, success=T])) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Cluster::LOG)) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Communication::LOG)) 0.000000 MetaHookPre CallFunction(Log::add_default_filter, , (Conn::LOG)) @@ -1094,7 +1096,7 @@ 0.000000 MetaHookPre CallFunction(Log::create_stream, , (Weird::LOG, [columns=, ev=Weird::log_weird, path=weird])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (X509::LOG, [columns=, ev=X509::log_x509, path=x509])) 0.000000 MetaHookPre CallFunction(Log::create_stream, , (mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql])) -0.000000 MetaHookPre CallFunction(Log::write, , (PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T])) +0.000000 MetaHookPre CallFunction(Log::write, , (PacketFilter::LOG, [ts=1493067689.952434, node=bro, 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, , ()) @@ -1429,6 +1431,8 @@ 0.000000 MetaHookPre LoadFile(base<...>/weird) 0.000000 MetaHookPre LoadFile(base<...>/x509) 0.000000 MetaHookPre LoadFile(base<...>/xmpp) +0.000000 MetaHookPre LogInit(Log::WRITER_ASCII, default, true, true, packet_filter(0.0,0.0,0.0), 5, {ts (time), node (string), filter (string), init (bool), success (bool)}) +0.000000 MetaHookPre LogWrite(Log::WRITER_ASCII, default, packet_filter(0.0,0.0,0.0), 5, {ts (time), node (string), filter (string), init (bool), success (bool)}, ) 0.000000 MetaHookPre QueueEvent(NetControl::init()) 0.000000 MetaHookPre QueueEvent(bro_init()) 0.000000 MetaHookPre QueueEvent(filter_change_tracking()) @@ -1680,7 +1684,7 @@ 0.000000 | HookCallFunction Log::__create_stream(Weird::LOG, [columns=, ev=Weird::log_weird, path=weird]) 0.000000 | HookCallFunction Log::__create_stream(X509::LOG, [columns=, ev=X509::log_x509, path=x509]) 0.000000 | HookCallFunction Log::__create_stream(mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql]) -0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T]) +0.000000 | HookCallFunction Log::__write(PacketFilter::LOG, [ts=1493067689.952434, node=bro, filter=ip or not ip, init=T, success=T]) 0.000000 | HookCallFunction Log::add_default_filter(Cluster::LOG) 0.000000 | HookCallFunction Log::add_default_filter(Communication::LOG) 0.000000 | HookCallFunction Log::add_default_filter(Conn::LOG) @@ -1810,7 +1814,7 @@ 0.000000 | HookCallFunction Log::create_stream(Weird::LOG, [columns=, ev=Weird::log_weird, path=weird]) 0.000000 | HookCallFunction Log::create_stream(X509::LOG, [columns=, ev=X509::log_x509, path=x509]) 0.000000 | HookCallFunction Log::create_stream(mysql::LOG, [columns=, ev=MySQL::log_mysql, path=mysql]) -0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1488302456.440387, node=bro, filter=ip or not ip, init=T, success=T]) +0.000000 | HookCallFunction Log::write(PacketFilter::LOG, [ts=1493067689.952434, node=bro, 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() @@ -1851,6 +1855,8 @@ 0.000000 | HookLoadFile <...>/bro 0.000000 | HookLoadFile base<...>/bif 0.000000 | HookLoadFile base<...>/bro +0.000000 | HookLogInit packet_filter 1/1 {ts (time), node (string), filter (string), init (bool), success (bool)} +0.000000 | HookLogWrite packet_filter [ts=1493067689.952434, node=bro, filter=ip or not ip, init=T, success=T] 0.000000 | HookQueueEvent NetControl::init() 0.000000 | HookQueueEvent bro_init() 0.000000 | HookQueueEvent filter_change_tracking() @@ -1865,6 +1871,7 @@ 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=, dpd=, 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, 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(ChecksumOffloading::check, , ()) @@ -1877,6 +1884,7 @@ 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=, dpd=, 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=])) +1362692526.869344 MetaHookPre SetupAnalyzerTree(1362692526.869344(1362692526.869344) TCP 141.142.228.5:59856 -> 192.150.187.43:80) 1362692526.869344 MetaHookPre UpdateNetworkTime(1362692526.869344) 1362692526.869344 | HookBroObjDtor 1362692526.869344 | HookUpdateNetworkTime 1362692526.869344 @@ -1890,6 +1898,7 @@ 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=, dpd=, 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, 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.939084 MetaHookPost CallFunction(NetControl::catch_release_seen, , (141.142.228.5)) -> 1362692526.939084 MetaHookPost CallFunction(addr_to_subnet, , (141.142.228.5)) -> @@ -2204,6 +2213,10 @@ 1362692527.009775 MetaHookPost CallFunction(id_string, , ([orig_h=141.142.228.5, orig_p=59856<...>/tcp])) -> 1362692527.009775 MetaHookPost CallFunction(set_file_handle, , (Analyzer::ANALYZER_HTTP1362692526.869344F11141.142.228.5:59856 > 192.150.187.43:80)) -> 1362692527.009775 MetaHookPost DrainEvents() -> +1362692527.009775 MetaHookPost LogInit(Log::WRITER_ASCII, default, true, true, files(1362692527.009775,0.0,0.0), 25, {ts (time), fuid (string), tx_hosts (set[addr]), rx_hosts (set[addr]), conn_uids (set[string]), source (string), depth (count), analyzers (set[string]), mime_type (string), filename (string), duration (interval), local_orig (bool), is_orig (bool), seen_bytes (count), total_bytes (count), missing_bytes (count), overflow_bytes (count), timedout (bool), parent_fuid (string), md5 (string), sha1 (string), sha256 (string), extracted (string), extracted_cutoff (bool), extracted_size (count)}) -> +1362692527.009775 MetaHookPost LogInit(Log::WRITER_ASCII, default, true, true, http(1362692527.009775,0.0,0.0), 29, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), trans_depth (count), method (string), host (string), uri (string), referrer (string), version (string), user_agent (string), request_body_len (count), response_body_len (count), status_code (count), status_msg (string), info_code (count), info_msg (string), tags (set[enum]), username (string), password (string), proxied (set[string]), orig_fuids (vector[string]), orig_filenames (vector[string]), orig_mime_types (vector[string]), resp_fuids (vector[string]), resp_filenames (vector[string]), resp_mime_types (vector[string])}) -> +1362692527.009775 MetaHookPost LogWrite(Log::WRITER_ASCII, default, files(1362692527.009775,0.0,0.0), 25, {ts (time), fuid (string), tx_hosts (set[addr]), rx_hosts (set[addr]), conn_uids (set[string]), source (string), depth (count), analyzers (set[string]), mime_type (string), filename (string), duration (interval), local_orig (bool), is_orig (bool), seen_bytes (count), total_bytes (count), missing_bytes (count), overflow_bytes (count), timedout (bool), parent_fuid (string), md5 (string), sha1 (string), sha256 (string), extracted (string), extracted_cutoff (bool), extracted_size (count)}, ) -> true +1362692527.009775 MetaHookPost LogWrite(Log::WRITER_ASCII, default, http(1362692527.009775,0.0,0.0), 29, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), trans_depth (count), method (string), host (string), uri (string), referrer (string), version (string), user_agent (string), request_body_len (count), response_body_len (count), status_code (count), status_msg (string), info_code (count), info_msg (string), tags (set[enum]), username (string), password (string), proxied (set[string]), orig_fuids (vector[string]), orig_filenames (vector[string]), orig_mime_types (vector[string]), resp_fuids (vector[string]), resp_filenames (vector[string]), resp_mime_types (vector[string])}, ) -> true 1362692527.009775 MetaHookPost QueueEvent(file_sniff([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain]]])) -> false 1362692527.009775 MetaHookPost QueueEvent(file_state_remove([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1], irc=, pe=, u2_events=])) -> false 1362692527.009775 MetaHookPost QueueEvent(get_file_handle(Analyzer::ANALYZER_HTTP, [id=[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=], F)) -> false @@ -2229,6 +2242,10 @@ 1362692527.009775 MetaHookPre CallFunction(id_string, , ([orig_h=141.142.228.5, orig_p=59856<...>/tcp])) 1362692527.009775 MetaHookPre CallFunction(set_file_handle, , (Analyzer::ANALYZER_HTTP1362692526.869344F11141.142.228.5:59856 > 192.150.187.43:80)) 1362692527.009775 MetaHookPre DrainEvents() +1362692527.009775 MetaHookPre LogInit(Log::WRITER_ASCII, default, true, true, files(1362692527.009775,0.0,0.0), 25, {ts (time), fuid (string), tx_hosts (set[addr]), rx_hosts (set[addr]), conn_uids (set[string]), source (string), depth (count), analyzers (set[string]), mime_type (string), filename (string), duration (interval), local_orig (bool), is_orig (bool), seen_bytes (count), total_bytes (count), missing_bytes (count), overflow_bytes (count), timedout (bool), parent_fuid (string), md5 (string), sha1 (string), sha256 (string), extracted (string), extracted_cutoff (bool), extracted_size (count)}) +1362692527.009775 MetaHookPre LogInit(Log::WRITER_ASCII, default, true, true, http(1362692527.009775,0.0,0.0), 29, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), trans_depth (count), method (string), host (string), uri (string), referrer (string), version (string), user_agent (string), request_body_len (count), response_body_len (count), status_code (count), status_msg (string), info_code (count), info_msg (string), tags (set[enum]), username (string), password (string), proxied (set[string]), orig_fuids (vector[string]), orig_filenames (vector[string]), orig_mime_types (vector[string]), resp_fuids (vector[string]), resp_filenames (vector[string]), resp_mime_types (vector[string])}) +1362692527.009775 MetaHookPre LogWrite(Log::WRITER_ASCII, default, files(1362692527.009775,0.0,0.0), 25, {ts (time), fuid (string), tx_hosts (set[addr]), rx_hosts (set[addr]), conn_uids (set[string]), source (string), depth (count), analyzers (set[string]), mime_type (string), filename (string), duration (interval), local_orig (bool), is_orig (bool), seen_bytes (count), total_bytes (count), missing_bytes (count), overflow_bytes (count), timedout (bool), parent_fuid (string), md5 (string), sha1 (string), sha256 (string), extracted (string), extracted_cutoff (bool), extracted_size (count)}, ) +1362692527.009775 MetaHookPre LogWrite(Log::WRITER_ASCII, default, http(1362692527.009775,0.0,0.0), 29, {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), trans_depth (count), method (string), host (string), uri (string), referrer (string), version (string), user_agent (string), request_body_len (count), response_body_len (count), status_code (count), status_msg (string), info_code (count), info_msg (string), tags (set[enum]), username (string), password (string), proxied (set[string]), orig_fuids (vector[string]), orig_filenames (vector[string]), orig_mime_types (vector[string]), resp_fuids (vector[string]), resp_filenames (vector[string]), resp_mime_types (vector[string])}, ) 1362692527.009775 MetaHookPre QueueEvent(file_sniff([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain]]])) 1362692527.009775 MetaHookPre QueueEvent(file_state_remove([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1], irc=, pe=, u2_events=])) 1362692527.009775 MetaHookPre QueueEvent(get_file_handle(Analyzer::ANALYZER_HTTP, [id=[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=], F)) @@ -2255,6 +2272,10 @@ 1362692527.009775 | HookCallFunction id_string([orig_h=141.142.228.5, orig_p=59856<...>/tcp]) 1362692527.009775 | HookCallFunction set_file_handle(Analyzer::ANALYZER_HTTP1362692526.869344F11141.142.228.5:59856 > 192.150.187.43:80) 1362692527.009775 | HookDrainEvents +1362692527.009775 | HookLogInit files 1/1 {ts (time), fuid (string), tx_hosts (set[addr]), rx_hosts (set[addr]), conn_uids (set[string]), source (string), depth (count), analyzers (set[string]), mime_type (string), filename (string), duration (interval), local_orig (bool), is_orig (bool), seen_bytes (count), total_bytes (count), missing_bytes (count), overflow_bytes (count), timedout (bool), parent_fuid (string), md5 (string), sha1 (string), sha256 (string), extracted (string), extracted_cutoff (bool), extracted_size (count)} +1362692527.009775 | HookLogInit http 1/1 {ts (time), uid (string), id.orig_h (addr), id.orig_p (port), id.resp_h (addr), id.resp_p (port), trans_depth (count), method (string), host (string), uri (string), referrer (string), version (string), user_agent (string), request_body_len (count), response_body_len (count), status_code (count), status_msg (string), info_code (count), info_msg (string), tags (set[enum]), username (string), password (string), proxied (set[string]), orig_fuids (vector[string]), orig_filenames (vector[string]), orig_mime_types (vector[string]), resp_fuids (vector[string]), resp_filenames (vector[string]), resp_mime_types (vector[string])} +1362692527.009775 | HookLogWrite files [ts=1362692527.009512, fuid=FakNcS1Jfe01uljb3, tx_hosts=192.150.187.43, rx_hosts=141.142.228.5, conn_uids=CHhAvVGS1DHFjwGM9, source=HTTP, depth=0, analyzers=, mime_type=text/plain, filename=, duration=0.000263, local_orig=, is_orig=F, seen_bytes=4705, total_bytes=4705, missing_bytes=0, overflow_bytes=0, timedout=F, parent_fuid=, md5=, sha1=, sha256=, extracted=, extracted_cutoff=, extracted_size=] +1362692527.009775 | HookLogWrite http [ts=1362692526.939527, uid=CHhAvVGS1DHFjwGM9, id.orig_h=141.142.228.5, id.orig_p=59856, id.resp_h=192.150.187.43, id.resp_p=80, trans_depth=1, method=GET, host=bro.org, uri=<...>/plain] 1362692527.009775 | HookQueueEvent file_sniff([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain]]]) 1362692527.009775 | HookQueueEvent file_state_remove([id=FakNcS1Jfe01uljb3, parent_id=, source=HTTP, is_orig=F, conns={[[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1], irc=, pe=, u2_events=]) 1362692527.009775 | HookQueueEvent get_file_handle(Analyzer::ANALYZER_HTTP, [id=[orig_h=141.142.228.5, orig_p=59856<...>/plain], current_entity=[filename=], orig_mime_depth=1, resp_mime_depth=1]}, current_request=1, current_response=1, trans_depth=1], irc=, krb=, modbus=, mysql=, ntlm=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=], F) @@ -2309,6 +2330,8 @@ 1362692527.080972 MetaHookPost CallFunction(sub_bytes, , (HTTP, 0, 1)) -> 1362692527.080972 MetaHookPost CallFunction(to_lower, , (HTTP)) -> 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(ChecksumOffloading::check()) -> false 1362692527.080972 MetaHookPost QueueEvent(bro_done()) -> 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=])) -> false @@ -2340,6 +2363,8 @@ 1362692527.080972 MetaHookPre CallFunction(sub_bytes, , (HTTP, 0, 1)) 1362692527.080972 MetaHookPre CallFunction(to_lower, , (HTTP)) 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(ChecksumOffloading::check()) 1362692527.080972 MetaHookPre QueueEvent(bro_done()) 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=])) @@ -2372,6 +2397,8 @@ 1362692527.080972 | HookCallFunction sub_bytes(HTTP, 0, 1) 1362692527.080972 | HookCallFunction to_lower(HTTP) 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 ChecksumOffloading::check() 1362692527.080972 | HookQueueEvent bro_done() 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=, radius=, rdp=, rfb=, sip=, sip_state=, snmp=, smtp=, smtp_state=, socks=, ssh=, syslog=]) diff --git a/testing/btest/Baseline/plugins.logging-hooks/output b/testing/btest/Baseline/plugins.logging-hooks/output new file mode 100644 index 0000000000..54330845bc --- /dev/null +++ b/testing/btest/Baseline/plugins.logging-hooks/output @@ -0,0 +1 @@ +1488216470.960453 | HookLogInit ssh 1/1 {b (bool), i (int), e (enum), c (count), p (port), sn (subnet), a (addr), d (double), t (time), iv (interval), s (string), sc (set[count]), ss (set[string]), se (set[string]), vc (vector[count]), ve (vector[string]), f (func)} diff --git a/testing/btest/Baseline/plugins.logging-hooks/ssh.log b/testing/btest/Baseline/plugins.logging-hooks/ssh.log new file mode 100644 index 0000000000..4b62eb8aca --- /dev/null +++ b/testing/btest/Baseline/plugins.logging-hooks/ssh.log @@ -0,0 +1,11 @@ +#separator \x09 +#set_separator , +#empty_field EMPTY +#unset_field - +#path ssh +#open 2017-02-27-17-27-50 +#fields b i e c p sn a d t iv s sc ss se vc ve f +#types bool int enum count port subnet addr double time interval string set[count] set[string] set[string] vector[count] vector[string] func +F -2 SSH::LOG 21 123 10.0.0.0/24 1.2.3.4 3.14 1488216470.960453 100.000000 hurz 2,4,1,3 BB,AA,CC EMPTY 10,20,30 EMPTY SSH::foo\x0a{ \x0aif (0 < SSH::i) \x0a\x09return (Foo);\x0aelse\x0a\x09return (Bar);\x0a\x0a} +T - SSH::LOG 21 123 10.0.0.0/24 1.2.3.4 3.14 1488216470.960453 100.000000 hurz 2,4,1,3 BB,AA,CC EMPTY 10,20,30 EMPTY SSH::foo\x0a{ \x0aif (0 < SSH::i) \x0a\x09return (Foo);\x0aelse\x0a\x09return (Bar);\x0a\x0a} +#close 2017-02-27-17-27-50 diff --git a/testing/btest/plugins/hooks-plugin/src/Plugin.cc b/testing/btest/plugins/hooks-plugin/src/Plugin.cc index 407ad1c242..d636e12b7c 100644 --- a/testing/btest/plugins/hooks-plugin/src/Plugin.cc +++ b/testing/btest/plugins/hooks-plugin/src/Plugin.cc @@ -3,6 +3,8 @@ #include #include +#include +#include namespace plugin { namespace Demo_Hooks { Plugin plugin; } } @@ -18,6 +20,9 @@ plugin::Configuration Plugin::Configure() EnableHook(META_HOOK_PRE); EnableHook(META_HOOK_POST); EnableHook(HOOK_BRO_OBJ_DTOR); + EnableHook(HOOK_SETUP_ANALYZER_TREE); + EnableHook(HOOK_LOG_INIT); + EnableHook(HOOK_LOG_WRITE); plugin::Configuration config; config.name = "Demo::Hooks"; @@ -121,3 +126,134 @@ void Plugin::MetaHookPost(HookType hook, const HookArgumentList& args, HookArgum hook_name(hook), d1.Description(), d2.Description()); } + +void Plugin::HookSetupAnalyzerTree(Connection *conn) + { + ODesc d; + d.SetShort(); + conn->Describe(&d); + + fprintf(stderr, "%.6f %-15s %s\n", network_time, "| HookSetupAnalyzerTree", d.Description()); + } + +void Plugin::HookLogInit(const std::string& writer, const std::string& instantiating_filter, bool local, bool remote, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields) + { + ODesc d; + + d.Add("{"); + for ( int i=0; i < num_fields; i++ ) + { + const threading::Field* f = fields[i]; + + if ( i > 0 ) + d.Add(", "); + + d.Add(f->name); + d.Add(" ("); + d.Add(f->TypeName()); + d.Add(")"); + } + d.Add("}"); + + fprintf(stderr, "%.6f %-15s %s %d/%d %s\n", network_time, "| HookLogInit", info.path, local, remote, d.Description()); + } + +void Plugin::RenderVal(const threading::Value* val, ODesc &d) const + { + if ( ! val->present ) + { + d.Add(""); + return; + } + + switch ( val->type ) { + + case TYPE_BOOL: + d.Add(val->val.int_val ? "T" : "F"); + break; + + case TYPE_INT: + d.Add(val->val.int_val); + break; + + case TYPE_COUNT: + case TYPE_COUNTER: + d.Add(val->val.uint_val); + break; + + case TYPE_PORT: + d.Add(val->val.port_val.port); + break; + + case TYPE_SUBNET: + d.Add(threading::formatter::Formatter::Render(val->val.subnet_val)); + break; + + case TYPE_ADDR: + d.Add(threading::formatter::Formatter::Render(val->val.addr_val)); + break; + + case TYPE_DOUBLE: + d.Add(val->val.double_val, true); + break; + + case TYPE_INTERVAL: + case TYPE_TIME: + d.Add(threading::formatter::Formatter::Render(val->val.double_val)); + break; + + case TYPE_ENUM: + case TYPE_STRING: + case TYPE_FILE: + case TYPE_FUNC: + d.AddN(val->val.string_val.data, val->val.string_val.length); + break; + + case TYPE_TABLE: + for ( int j = 0; j < val->val.set_val.size; j++ ) + { + if ( j > 0 ) + d.Add(","); + + RenderVal(val->val.set_val.vals[j], d); + } + break; + + case TYPE_VECTOR: + for ( int j = 0; j < val->val.vector_val.size; j++ ) + { + if ( j > 0 ) + d.Add(","); + + RenderVal(val->val.vector_val.vals[j], d); + } + break; + + default: + assert(false); + } + } + +bool Plugin::HookLogWrite(const std::string& writer, const std::string& filter, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields, threading::Value** vals) + { + ODesc d; + + d.Add("["); + for ( int i=0; i < num_fields; i++ ) + { + const threading::Field* f = fields[i]; + const threading::Value* val = vals[i]; + + if ( i > 0 ) + d.Add(", "); + + d.Add(f->name); + d.Add("="); + + RenderVal(val, d); + } + d.Add("]"); + + fprintf(stderr, "%.6f %-15s %s %s\n", network_time, "| HookLogWrite", info.path, d.Description()); + return true; + } diff --git a/testing/btest/plugins/hooks-plugin/src/Plugin.h b/testing/btest/plugins/hooks-plugin/src/Plugin.h index efbd25bc2d..64227c0660 100644 --- a/testing/btest/plugins/hooks-plugin/src/Plugin.h +++ b/testing/btest/plugins/hooks-plugin/src/Plugin.h @@ -10,17 +10,22 @@ namespace Demo_Hooks { class Plugin : public ::plugin::Plugin { protected: - virtual int HookLoadFile(const std::string& file, const std::string& ext); - virtual std::pair HookCallFunction(const Func* func, Frame* frame, val_list* args); - virtual bool HookQueueEvent(Event* event); - virtual void HookDrainEvents(); - virtual void HookUpdateNetworkTime(double network_time); - virtual void HookBroObjDtor(void* obj); - virtual void MetaHookPre(HookType hook, const HookArgumentList& args); - virtual void MetaHookPost(HookType hook, const HookArgumentList& args, HookArgument result); + int HookLoadFile(const std::string& file, const std::string& ext) override; + std::pair HookCallFunction(const Func* func, Frame* frame, val_list* args) override; + bool HookQueueEvent(Event* event) override; + void HookDrainEvents() override; + void HookUpdateNetworkTime(double network_time) override; + void HookBroObjDtor(void* obj) override; + void HookLogInit(const std::string& writer, const std::string& instantiating_filter, bool local, bool remote, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields) override; + bool HookLogWrite(const std::string& writer, const std::string& filter, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields, threading::Value** vals) override; + void HookSetupAnalyzerTree(Connection *conn) override; + void MetaHookPre(HookType hook, const HookArgumentList& args) override; + void MetaHookPost(HookType hook, const HookArgumentList& args, HookArgument result) override; + + void RenderVal(const threading::Value* val, ODesc &d) const; // Overridden from plugin::Plugin. - virtual plugin::Configuration Configure(); + plugin::Configuration Configure() override; }; extern Plugin plugin; diff --git a/testing/btest/plugins/logging-hooks-plugin/.btest-ignore b/testing/btest/plugins/logging-hooks-plugin/.btest-ignore new file mode 100644 index 0000000000..e69de29bb2 diff --git a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc new file mode 100644 index 0000000000..32dd2b17b3 --- /dev/null +++ b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.cc @@ -0,0 +1,60 @@ + +#include "Plugin.h" + +#include +#include +#include +#include + +namespace plugin { namespace Log_Hooks { Plugin plugin; } } + +using namespace plugin::Log_Hooks; + +plugin::Configuration Plugin::Configure() + { + round = 0; + EnableHook(HOOK_LOG_INIT); + EnableHook(HOOK_LOG_WRITE); + + plugin::Configuration config; + config.name = "Log::Hooks"; + config.description = "Exercises Log hooks"; + config.version.major = 1; + config.version.minor = 0; + return config; + } + +void Plugin::HookLogInit(const std::string& writer, const std::string& instantiating_filter, bool local, bool remote, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields) + { + ODesc d; + + d.Add("{"); + for ( int i=0; i < num_fields; i++ ) + { + const threading::Field* f = fields[i]; + + if ( i > 0 ) + d.Add(", "); + + d.Add(f->name); + d.Add(" ("); + d.Add(f->TypeName()); + d.Add(")"); + } + d.Add("}"); + + fprintf(stderr, "%.6f %-15s %s %d/%d %s\n", network_time, "| HookLogInit", info.path, local, remote, d.Description()); + } + +bool Plugin::HookLogWrite(const std::string& writer, const std::string& filter, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields, threading::Value** vals) + { + round++; + if ( round == 1 ) // do not output line + return false; + else if ( round == 2 ) + vals[0]->val.int_val = 0; + else if ( round == 3 ) + vals[1]->present = false; + + return true; + } diff --git a/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h new file mode 100644 index 0000000000..12b821c22c --- /dev/null +++ b/testing/btest/plugins/logging-hooks-plugin/src/Plugin.h @@ -0,0 +1,28 @@ + +#ifndef BRO_PLUGIN_Log_Hooks +#define BRO_PLUGIN_Log_Hooks + +#include + +namespace plugin { +namespace Log_Hooks { + +class Plugin : public ::plugin::Plugin +{ +protected: + void HookLogInit(const std::string& writer, const std::string& instantiating_filter, bool local, bool remote, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields) override; + bool HookLogWrite(const std::string& writer, const std::string& filter, const logging::WriterBackend::WriterInfo& info, int num_fields, const threading::Field* const* fields, threading::Value** vals) override; + + // Overridden from plugin::Plugin. + plugin::Configuration Configure() override; + +private: + int round; +}; + +extern Plugin plugin; + +} +} + +#endif diff --git a/testing/btest/plugins/logging-hooks.bro b/testing/btest/plugins/logging-hooks.bro new file mode 100644 index 0000000000..f2ca926c06 --- /dev/null +++ b/testing/btest/plugins/logging-hooks.bro @@ -0,0 +1,72 @@ +# @TEST-EXEC: ${DIST}/aux/bro-aux/plugin-support/init-plugin -u . Log Hooks +# @TEST-EXEC: cp -r %DIR/logging-hooks-plugin/* . +# @TEST-EXEC: ./configure --bro-dist=${DIST} && make +# @TEST-EXEC: BRO_PLUGIN_ACTIVATE="Log::Hooks" BRO_PLUGIN_PATH=`pwd` bro -b %INPUT 2>&1 | $SCRIPTS/diff-remove-abspath | sort | uniq >output +# @TEST-EXEC: btest-diff output +# @TEST-EXEC: btest-diff ssh.log + +redef LogAscii::empty_field = "EMPTY"; + +module SSH; + +export { + redef enum Log::ID += { LOG }; + + type Log: record { + b: bool; + i: int &optional; + e: Log::ID; + c: count; + p: port; + sn: subnet; + a: addr; + d: double; + t: time; + iv: interval; + s: string; + sc: set[count]; + ss: set[string]; + se: set[string]; + vc: vector of count; + ve: vector of string; + f: function(i: count) : string; + } &log; +} + +function foo(i : count) : string + { + if ( i > 0 ) + return "Foo"; + else + return "Bar"; + } + +event bro_init() +{ + Log::create_stream(SSH::LOG, [$columns=Log]); + + local empty_set: set[string]; + local empty_vector: vector of string; + + local i = 0; + while ( ++i < 4 ) + Log::write(SSH::LOG, [ + $b=T, + $i=-i, + $e=SSH::LOG, + $c=21, + $p=123/tcp, + $sn=10.0.0.1/24, + $a=1.2.3.4, + $d=3.14, + $t=network_time(), + $iv=100secs, + $s="hurz", + $sc=set(1,2,3,4), + $ss=set("AA", "BB", "CC"), + $se=empty_set, + $vc=vector(10, 20, 30), + $ve=empty_vector, + $f=foo + ]); +}