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.
This commit is contained in:
Jon Siwek 2019-05-17 14:13:46 -07:00
parent 9d07e4f0b8
commit dd173f4961
6 changed files with 34 additions and 9 deletions

View file

@ -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 2.6-307 | 2019-05-16 13:37:24 -0700
* More bro-to-zeek renaming in scripts and other files (Daniel Thayer) * More bro-to-zeek renaming in scripts and other files (Daniel Thayer)

View file

@ -1 +1 @@
2.6-307 2.6-308

View file

@ -31,12 +31,14 @@ Reporter::Reporter()
via_events = false; via_events = false;
in_error_handler = 0; 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 // Messages may otherwise be missed if an error occurs that prevents events
// from ever being dispatched. // from ever being dispatched.
info_to_stderr = true; info_to_stderr = true;
warnings_to_stderr = true; warnings_to_stderr = true;
errors_to_stderr = true; errors_to_stderr = true;
after_zeek_init = false;
weird_count = 0; weird_count = 0;
weird_sampling_rate = 0; weird_sampling_rate = 0;
@ -80,7 +82,7 @@ void Reporter::Info(const char* fmt, ...)
{ {
va_list ap; va_list ap;
va_start(ap, fmt); 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); DoLog("", reporter_info, out, 0, 0, true, true, 0, fmt, ap);
va_end(ap); va_end(ap);
} }
@ -89,7 +91,7 @@ void Reporter::Warning(const char* fmt, ...)
{ {
va_list ap; va_list ap;
va_start(ap, fmt); 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); DoLog("warning", reporter_warning, out, 0, 0, true, true, 0, fmt, ap);
va_end(ap); va_end(ap);
} }
@ -99,7 +101,7 @@ void Reporter::Error(const char* fmt, ...)
++errors; ++errors;
va_list ap; va_list ap;
va_start(ap, fmt); 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); DoLog("error", reporter_error, out, 0, 0, true, true, 0, fmt, ap);
va_end(ap); va_end(ap);
} }
@ -142,7 +144,7 @@ void Reporter::ExprRuntimeError(const Expr* expr, const char* fmt, ...)
PushLocation(expr->GetLocationInfo()); PushLocation(expr->GetLocationInfo());
va_list ap; va_list ap;
va_start(ap, fmt); 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, DoLog("expression error", reporter_error, out, 0, 0, true, true,
d.Description(), fmt, ap); d.Description(), fmt, ap);
va_end(ap); va_end(ap);
@ -156,7 +158,7 @@ void Reporter::RuntimeError(const Location* location, const char* fmt, ...)
PushLocation(location); PushLocation(location);
va_list ap; va_list ap;
va_start(ap, fmt); 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); DoLog("runtime error", reporter_error, out, 0, 0, true, true, "", fmt, ap);
va_end(ap); va_end(ap);
PopLocation(); PopLocation();
@ -196,7 +198,7 @@ void Reporter::InternalWarning(const char* fmt, ...)
{ {
va_list ap; va_list ap;
va_start(ap, fmt); 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. // TODO: would be nice to also log a call stack.
DoLog("internal warning", reporter_warning, out, 0, 0, true, true, 0, fmt, DoLog("internal warning", reporter_warning, out, 0, 0, true, true, 0, fmt,
ap); ap);

View file

@ -233,6 +233,13 @@ public:
this->weird_sampling_duration = weird_sampling_duration; 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: private:
void DoLog(const char* prefix, EventHandlerPtr event, FILE* out, void DoLog(const char* prefix, EventHandlerPtr event, FILE* out,
Connection* conn, val_list* addl, bool location, bool time, Connection* conn, val_list* addl, bool location, bool time,
@ -248,12 +255,16 @@ private:
bool PermitNetWeird(const char* name); bool PermitNetWeird(const char* name);
bool PermitFlowWeird(const char* name, const IPAddr& o, const IPAddr& r); bool PermitFlowWeird(const char* name, const IPAddr& o, const IPAddr& r);
bool EmitToStderr(bool flag)
{ return flag || ! after_zeek_init; }
int errors; int errors;
bool via_events; bool via_events;
int in_error_handler; int in_error_handler;
bool info_to_stderr; bool info_to_stderr;
bool warnings_to_stderr; bool warnings_to_stderr;
bool errors_to_stderr; bool errors_to_stderr;
bool after_zeek_init;
std::list<std::pair<const Location*, const Location*> > locations; std::list<std::pair<const Location*, const Location*> > locations;

View file

@ -1087,6 +1087,7 @@ int main(int argc, char** argv)
reporter->FatalError("errors occurred while initializing"); reporter->FatalError("errors occurred while initializing");
broker_mgr->ZeekInitDone(); broker_mgr->ZeekInitDone();
reporter->ZeekInitDone();
analyzer_mgr->DumpDebug(); analyzer_mgr->DumpDebug();
have_pending_timers = ! reading_traces && timer_mgr->Size() > 0; have_pending_timers = ! reading_traces && timer_mgr->Size() > 0;

View file

@ -7,7 +7,14 @@ redef Reporter::errors_to_stderr = F;
global test: table[count] of string = {}; global test: table[count] of string = {};
event zeek_init() event my_event()
{ {
print test[3]; 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() };
}