From 4be6871df2c9ac5c7698f5c48a0f198010cbc3a4 Mon Sep 17 00:00:00 2001 From: Dev Bali Date: Mon, 18 Nov 2019 16:54:45 -0800 Subject: [PATCH] Added a non boolean configuration and other changes as suggested by Jon --- scripts/base/frameworks/logging/main.zeek | 37 ++++++---- src/Stmt.cc | 69 ++++++++++++------- .../.stdout | 0 .../anotherfile | 1 + .../otherfile | 2 + .../print.log | 11 +++ .../.stdout | 0 .../otherfile | 0 .../print_statements.log | 12 ++-- testing/btest/core/leaks/print-log.zeek | 14 ++++ .../frameworks/logging/print-log-stdout.zeek | 25 +++++++ .../base/frameworks/logging/print-log.zeek | 10 ++- 12 files changed, 136 insertions(+), 45 deletions(-) create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/anotherfile create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/otherfile create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/print.log create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log/.stdout create mode 100644 testing/btest/Baseline/scripts.base.frameworks.logging.print-log/otherfile create mode 100644 testing/btest/core/leaks/print-log.zeek create mode 100644 testing/btest/scripts/base/frameworks/logging/print-log-stdout.zeek diff --git a/scripts/base/frameworks/logging/main.zeek b/scripts/base/frameworks/logging/main.zeek index 9e5e639b6e..d8538d1521 100644 --- a/scripts/base/frameworks/logging/main.zeek +++ b/scripts/base/frameworks/logging/main.zeek @@ -11,8 +11,7 @@ export { ## The log ID implicitly determines the default name of the generated log ## file. type Log::ID: enum { - ## Dummy place-holder. - UNKNOWN + PRINTLOG }; ## If true, local logging is by default enabled for all filters. @@ -75,21 +74,35 @@ export { ## Returns: The path to be used for the filter. global default_path_func: function(id: ID, path: string, rec: any) : string &redef; - # Log Print Statements - + ## If :zeek:see:`Log::print_to_log` is set to redirect, ``print`` statements will + ## automatically populate log entries with the fields contained in this record. type PrintLogInfo: record { - ## Current timestamp. + ## Current timestamp. ts: time &log; ## Set of strings passed to the print statement. - vals: set[string] &log; + vals: string_vec &log; }; - redef enum Log::ID += {PRINTLOG}; + ## Configurations for :zeek:see:`Log::print_to_log` + type PrintLogType: enum { + ## No redirection of ``print`` statements. + REDIRECT_NONE, + ## Redirection of those ``print`` statements that were being logged to stdout, + ## leaving behind those set to go to other specific files. + REDIRECT_STDOUT, + ## Redirection of all ``print`` statements. + REDIRECT_ALL + }; - ## If true, logging is enabled for print statements instead of output to files - const print_to_log = F &redef; + ## Event for accessing logged print records + global log_print: event(rec: PrintLogInfo); - ## If print_to_log is true, this is the path to which the print Log Stream writes + ## Set configuration for ``print`` statements redirected to logs + ## :zeek:see:`Log::print_log_type` + const print_to_log: PrintLogType = REDIRECT_NONE &redef; + + ## If :zeek:see:`Log::print_to_log` is enabled to write to a print log, + ## this is the path to which the print Log Stream writes to const print_log_path = "print" &redef; # Log rotation support. @@ -663,7 +676,7 @@ function remove_default_filter(id: ID) : bool event zeek_init() &priority=5 { - if ( print_to_log ) + if ( print_to_log != REDIRECT_NONE ) # "print" added for the test coverage.find-bro-logs - Log::create_stream(PRINTLOG, [$columns=PrintLogInfo, $path=print_log_path]); #"print" + Log::create_stream(PRINTLOG, [$columns=PrintLogInfo, $ev=log_print, $path=print_log_path]); #"print" } diff --git a/src/Stmt.cc b/src/Stmt.cc index 9a86924cf6..e76ff1331d 100644 --- a/src/Stmt.cc +++ b/src/Stmt.cc @@ -15,6 +15,7 @@ #include "Traverse.h" #include "Trigger.h" #include "logging/Manager.h" +#include "IntrusivePtr.h" const char* stmt_name(BroStmtTag t) { @@ -185,48 +186,57 @@ TraversalCode ExprListStmt::Traverse(TraversalCallback* cb) const static BroFile* print_stdout = 0; -TableVal* get_string_set_from_vals (val_list* vals, ODesc* d) +static EnumVal* LookupEnumID (const string& module_name, const char* name) { - ListVal* set = new ListVal(TYPE_STRING); + ID* id = lookup_ID(name, module_name.c_str()); + assert(id); + assert(id->IsEnumConst()); + + EnumType* et = id->Type()->AsEnumType(); + + int index = et->Lookup(module_name, name); + assert(index >= 0); + EnumVal* val = et->GetVal(index); + assert(val); + + return val; + } + +static Val* print_log (val_list* vals, ODesc* d) + { + EnumVal* plval = LookupEnumID("Log", "PRINTLOG"); + RecordType* pltype = internal_type("Log::PrintLogInfo")->AsRecordType(); + + RecordVal* record = new RecordVal(pltype); + VectorVal* vec = new VectorVal(internal_type("string_vec")->AsVectorType()); + for ( int i = 0; i < vals->length(); i++ ) { d->Clear(); Val* val = (*vals)[i]; val->Describe(d); - set->Append(new StringVal(d->Description())); + const bool assigned = vec->Assign(i, new StringVal(d->Description())); + assert(assigned); } - return set->ConvertToSet(); + record->Assign(0, new Val(current_time(), TYPE_TIME)); + record->Assign(1, vec); + + log_mgr->Write(plval, record); + Unref(record); + Unref(plval); + return 0; } Val* PrintStmt::DoExec(val_list* vals, stmt_flow_type& /* flow */) const { RegisterAccess(); - - if ( internal_val("Log::print_to_log")->AsBool() ) + unsigned int PrintToLog = internal_val("Log::print_to_log")->AsEnumVal()->ForceAsUInt(); + if ( PrintToLog == 2 ) // Redirect all Print Statements to Log { - ID* plid = global_scope()->Lookup("Log::PRINTLOG"); - assert(plid); - assert(plid->IsEnumConst()); - - EnumType* et = plid->Type()->AsEnumType(); - int plint = et->Lookup("Log", "PRINTLOG"); - assert(plint >= 0); - EnumVal* plval = et->GetVal(plint); - assert(plval); - - RecordType* pltype = log_mgr->StreamColumns(plval); - assert(pltype); - - RecordVal record = RecordVal(pltype); ODesc d(DESC_READABLE); d.SetFlush(0); - - record.Assign(0, new Val(current_time(), TYPE_TIME)); - record.Assign(1, get_string_set_from_vals(vals, &d)); - - log_mgr->Write(plval, &record); - return 0; + return print_log(vals, &d); } if ( ! print_stdout ) @@ -244,6 +254,13 @@ Val* PrintStmt::DoExec(val_list* vals, stmt_flow_type& /* flow */) const ++offset; } + if ( f->Name() == print_stdout->Name() && PrintToLog ) + { + ODesc d(DESC_READABLE); + d.SetFlush(0); + return print_log(vals, &d); + } + desc_style style = f->IsRawOutput() ? RAW_STYLE : STANDARD_STYLE; if ( f->IsRawOutput() ) diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/.stdout new file mode 100644 index 0000000000..e69de29bb2 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/anotherfile b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/anotherfile new file mode 100644 index 0000000000..0f26e071a1 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/anotherfile @@ -0,0 +1 @@ +from event, [ts=1574278151.973419, vals=[2, T]] diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/otherfile b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/otherfile new file mode 100644 index 0000000000..6a8799a20f --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/otherfile @@ -0,0 +1,2 @@ +hello world , +2, T diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/print.log b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/print.log new file mode 100644 index 0000000000..5452244963 --- /dev/null +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log-stdout/print.log @@ -0,0 +1,11 @@ +#separator \x09 +#set_separator , +#empty_field (empty) +#unset_field - +#path print +#open 2019-11-18-15-32-20 +#fields ts vals +#types time vector[string] +1574119940.484001 hello world \x2c +1574119940.484104 2,T +#close 2019-11-18-15-32-20 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/.stdout b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/.stdout new file mode 100644 index 0000000000..e69de29bb2 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/otherfile b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/otherfile new file mode 100644 index 0000000000..e69de29bb2 diff --git a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/print_statements.log b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/print_statements.log index f7ae620e76..9496a1eab9 100644 --- a/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/print_statements.log +++ b/testing/btest/Baseline/scripts.base.frameworks.logging.print-log/print_statements.log @@ -3,9 +3,11 @@ #empty_field (empty) #unset_field - #path print_statements -#open 2019-11-13-18-11-01 +#open 2019-11-19-00-27-19 #fields ts vals -#types time set[string] -1573697461.909861 hello world \x2c -1573697461.909946 T,2 -#close 2019-11-13-18-11-01 \ No newline at end of file +#types time vector[string] +1574123239.274803 file "otherfile" of string,hello world \x2c +1574123239.275147 hello world \x2c +1574123239.275171 file "otherfile" of string,2,T +1574123239.275177 2,T +#close 2019-11-19-00-27-19 diff --git a/testing/btest/core/leaks/print-log.zeek b/testing/btest/core/leaks/print-log.zeek new file mode 100644 index 0000000000..3130625e50 --- /dev/null +++ b/testing/btest/core/leaks/print-log.zeek @@ -0,0 +1,14 @@ +# @TEST-GROUP: leaks +# +# @TEST-REQUIRES: zeek --help 2>&1 | grep -q mem-leaks +# +# @TEST-EXEC: HEAP_CHECK_DUMP_DIRECTORY=. HEAPCHECK=local btest-bg-run zeek zeek -m -b -r $TRACES/http/get.trace %INPUT +# @TEST-EXEC: btest-bg-wait 60 + +redef Log::print_to_log = Log::REDIRECT_ALL; + +event new_connection(c: connection) + { + print "hello world ,"; + print 2,T; + } \ No newline at end of file diff --git a/testing/btest/scripts/base/frameworks/logging/print-log-stdout.zeek b/testing/btest/scripts/base/frameworks/logging/print-log-stdout.zeek new file mode 100644 index 0000000000..a42d5ff084 --- /dev/null +++ b/testing/btest/scripts/base/frameworks/logging/print-log-stdout.zeek @@ -0,0 +1,25 @@ +# +# @TEST-EXEC: zeek -b %INPUT +# @TEST-EXEC: btest-diff print.log +# @TEST-EXEC: btest-diff .stdout +# @TEST-EXEC: btest-diff otherfile +# @TEST-EXEC: btest-diff anotherfile + +redef Log::print_to_log = Log::REDIRECT_STDOUT; + +event zeek_init() + { + local f = open("otherfile"); + print f, "hello world ,"; + print "hello world ,"; + print f,2,T; + print 2,T; + close(f); + } + +event Log::log_print (rec: Log::PrintLogInfo) + { + local f = open("anotherfile"); + print f,"from event",rec; + close(f); + } \ No newline at end of file diff --git a/testing/btest/scripts/base/frameworks/logging/print-log.zeek b/testing/btest/scripts/base/frameworks/logging/print-log.zeek index ddce8cd8e4..9c1bd30c73 100644 --- a/testing/btest/scripts/base/frameworks/logging/print-log.zeek +++ b/testing/btest/scripts/base/frameworks/logging/print-log.zeek @@ -1,12 +1,18 @@ # # @TEST-EXEC: zeek -b %INPUT # @TEST-EXEC: btest-diff print_statements.log +# @TEST-EXEC: btest-diff .stdout +# @TEST-EXEC: btest-diff otherfile -redef Log::print_to_log = T; +redef Log::print_to_log = Log::REDIRECT_ALL; redef Log::print_log_path = "print_statements"; event zeek_init() { + local f = open("otherfile"); + print f, "hello world ,"; print "hello world ,"; + print f,2,T; print 2,T; - } + close(f); + } \ No newline at end of file