From dd173f49619e78693a0e5fc5e3be5c570bd0b023 Mon Sep 17 00:00:00 2001 From: Jon Siwek Date: Fri, 17 May 2019 14:13:46 -0700 Subject: [PATCH] Always emit scripting errors to stderr during zeek_init Otherwise, setting Reporter::errors_to_stderr=F causes important error messages to be lost (and this setting is the default for ZeekCtl). E.g. now that we terminate if there's errors during zeek_init, GH-369 shows that the only error message given was "fatal error: errors occurred while initializing", which is not helpful in determining the actual issue. --- CHANGES | 4 ++++ VERSION | 2 +- src/Reporter.cc | 16 +++++++++------- src/Reporter.h | 11 +++++++++++ src/main.cc | 1 + .../base/frameworks/reporter/disable-stderr.zeek | 9 ++++++++- 6 files changed, 34 insertions(+), 9 deletions(-) diff --git a/CHANGES b/CHANGES index 4c8f46e65d..fdcbd21efd 100644 --- a/CHANGES +++ b/CHANGES @@ -1,4 +1,8 @@ +2.6-308 | 2019-05-17 14:13:46 -0700 + + * Always emit scripting errors to stderr during zeek_init (Jon Siwek, Corelight) + 2.6-307 | 2019-05-16 13:37:24 -0700 * More bro-to-zeek renaming in scripts and other files (Daniel Thayer) diff --git a/VERSION b/VERSION index ec79da4e31..522799029d 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -2.6-307 +2.6-308 diff --git a/src/Reporter.cc b/src/Reporter.cc index 09a4aa03b5..a40ddb9a3d 100644 --- a/src/Reporter.cc +++ b/src/Reporter.cc @@ -31,12 +31,14 @@ Reporter::Reporter() via_events = false; in_error_handler = 0; - // Always use stderr at startup/init before scripts have been fully parsed. + // Always use stderr at startup/init before scripts have been fully parsed + // and zeek_init() processed. // Messages may otherwise be missed if an error occurs that prevents events // from ever being dispatched. info_to_stderr = true; warnings_to_stderr = true; errors_to_stderr = true; + after_zeek_init = false; weird_count = 0; weird_sampling_rate = 0; @@ -80,7 +82,7 @@ void Reporter::Info(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - FILE* out = info_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(info_to_stderr) ? stderr : 0; DoLog("", reporter_info, out, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -89,7 +91,7 @@ void Reporter::Warning(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - FILE* out = warnings_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(warnings_to_stderr) ? stderr : 0; DoLog("warning", reporter_warning, out, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -99,7 +101,7 @@ void Reporter::Error(const char* fmt, ...) ++errors; va_list ap; va_start(ap, fmt); - FILE* out = errors_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(errors_to_stderr) ? stderr : 0; DoLog("error", reporter_error, out, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -142,7 +144,7 @@ void Reporter::ExprRuntimeError(const Expr* expr, const char* fmt, ...) PushLocation(expr->GetLocationInfo()); va_list ap; va_start(ap, fmt); - FILE* out = errors_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(errors_to_stderr) ? stderr : 0; DoLog("expression error", reporter_error, out, 0, 0, true, true, d.Description(), fmt, ap); va_end(ap); @@ -156,7 +158,7 @@ void Reporter::RuntimeError(const Location* location, const char* fmt, ...) PushLocation(location); va_list ap; va_start(ap, fmt); - FILE* out = errors_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(errors_to_stderr) ? stderr : 0; DoLog("runtime error", reporter_error, out, 0, 0, true, true, "", fmt, ap); va_end(ap); PopLocation(); @@ -196,7 +198,7 @@ void Reporter::InternalWarning(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - FILE* out = warnings_to_stderr ? stderr : 0; + FILE* out = EmitToStderr(warnings_to_stderr) ? stderr : 0; // TODO: would be nice to also log a call stack. DoLog("internal warning", reporter_warning, out, 0, 0, true, true, 0, fmt, ap); diff --git a/src/Reporter.h b/src/Reporter.h index 88270a9dba..dce075de64 100644 --- a/src/Reporter.h +++ b/src/Reporter.h @@ -233,6 +233,13 @@ public: this->weird_sampling_duration = weird_sampling_duration; } + /** + * Called after zeek_init() and toggles whether messages may stop being + * emitted to stderr. + */ + void ZeekInitDone() + { after_zeek_init = true; } + private: void DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Connection* conn, val_list* addl, bool location, bool time, @@ -248,12 +255,16 @@ private: bool PermitNetWeird(const char* name); bool PermitFlowWeird(const char* name, const IPAddr& o, const IPAddr& r); + bool EmitToStderr(bool flag) + { return flag || ! after_zeek_init; } + int errors; bool via_events; int in_error_handler; bool info_to_stderr; bool warnings_to_stderr; bool errors_to_stderr; + bool after_zeek_init; std::list > locations; diff --git a/src/main.cc b/src/main.cc index 630cd4f5a4..414de5c7e4 100644 --- a/src/main.cc +++ b/src/main.cc @@ -1087,6 +1087,7 @@ int main(int argc, char** argv) reporter->FatalError("errors occurred while initializing"); broker_mgr->ZeekInitDone(); + reporter->ZeekInitDone(); analyzer_mgr->DumpDebug(); have_pending_timers = ! reading_traces && timer_mgr->Size() > 0; diff --git a/testing/btest/scripts/base/frameworks/reporter/disable-stderr.zeek b/testing/btest/scripts/base/frameworks/reporter/disable-stderr.zeek index 2adf5e1d7f..1395f20807 100644 --- a/testing/btest/scripts/base/frameworks/reporter/disable-stderr.zeek +++ b/testing/btest/scripts/base/frameworks/reporter/disable-stderr.zeek @@ -7,7 +7,14 @@ redef Reporter::errors_to_stderr = F; global test: table[count] of string = {}; -event zeek_init() +event my_event() { print test[3]; } + +event zeek_init() + { + # Errors within zeek_init are always printed to stderr, so check whether + # an error that happens later is suppressed. + schedule 0.2sec { my_event() }; + }