From 15ab2874369b5d7a3e6a14df24b141fa759999bb Mon Sep 17 00:00:00 2001 From: Robin Sommer Date: Sun, 9 Oct 2011 20:28:06 -0700 Subject: [PATCH 1/2] Experimental code to better handle interpreter errors. Currently, a lot of interpreter runtime errors, such as an access to an unset optional record field, cause Bro to abort with an internal error. This is an experimental branch that turns such errors into non-fatal runtime errors by internally raising exceptions. These are caught upstream and processing continues afterwards. For now, not many errors actually raise exceptions (the example above does though). We'll need to go through them eventually and adapt the current Internal() calls (and potentially others). More generally, at some point we should cleanup the interpreter error handling (unifying errors reported at parse- and runtime; and switching to exceptions for all Expr/Stmt/Vals). But that's a larger change and left for later. The main question for now is if this code is already helpful enough to go into 2.0. It will quite likely prevent a number of crashes due to script errors. --- src/Discard.cc | 48 +++++++++++++++++++++++++++++++++--- src/Event.h | 11 ++++++++- src/EventHandler.cc | 1 + src/Expr.cc | 10 +++++--- src/LogMgr.cc | 43 ++++++++++++++++++++++++++------ src/PersistenceSerializer.cc | 8 +++++- src/RemoteSerializer.cc | 8 +++++- src/Reporter.cc | 44 +++++++++++++++++++++++++-------- src/Reporter.h | 24 +++++++++++++++++- src/RuleCondition.cc | 16 +++++++++--- src/Sessions.cc | 9 ++++++- src/Val.cc | 29 ++++++++++++++++++---- 12 files changed, 213 insertions(+), 38 deletions(-) diff --git a/src/Discard.cc b/src/Discard.cc index 2705aa55be..a71b810601 100644 --- a/src/Discard.cc +++ b/src/Discard.cc @@ -42,7 +42,17 @@ int Discarder::NextPacket(const IP_Hdr* ip, int len, int caplen) { val_list* args = new val_list; args->append(BuildHeader(ip4)); - discard_packet = check_ip->Call(args)->AsBool(); + + try + { + discard_packet = check_ip->Call(args)->AsBool(); + } + + catch ( InterpreterException& e ) + { + discard_packet = false; + } + delete args; if ( discard_packet ) @@ -90,7 +100,17 @@ int Discarder::NextPacket(const IP_Hdr* ip, int len, int caplen) args->append(BuildHeader(ip4)); args->append(BuildHeader(tp, len)); args->append(BuildData(data, th_len, len, caplen)); - discard_packet = check_tcp->Call(args)->AsBool(); + + try + { + discard_packet = check_tcp->Call(args)->AsBool(); + } + + catch ( InterpreterException& e ) + { + discard_packet = false; + } + delete args; } } @@ -106,7 +126,17 @@ int Discarder::NextPacket(const IP_Hdr* ip, int len, int caplen) args->append(BuildHeader(ip4)); args->append(BuildHeader(up)); args->append(BuildData(data, uh_len, len, caplen)); - discard_packet = check_udp->Call(args)->AsBool(); + + try + { + discard_packet = check_udp->Call(args)->AsBool(); + } + + catch ( InterpreterException& e ) + { + discard_packet = false; + } + delete args; } } @@ -120,7 +150,17 @@ int Discarder::NextPacket(const IP_Hdr* ip, int len, int caplen) val_list* args = new val_list; args->append(BuildHeader(ip4)); args->append(BuildHeader(ih)); - discard_packet = check_icmp->Call(args)->AsBool(); + + try + { + discard_packet = check_icmp->Call(args)->AsBool(); + } + + catch ( InterpreterException& e ) + { + discard_packet = false; + } + delete args; } } diff --git a/src/Event.h b/src/Event.h index 805396a488..1740372407 100644 --- a/src/Event.h +++ b/src/Event.h @@ -41,7 +41,16 @@ protected: if ( handler->ErrorHandler() ) reporter->BeginErrorHandler(); - handler->Call(args, no_remote); + try + { + handler->Call(args, no_remote); + } + + catch ( InterpreterException& e ) + { + // Already reported. + } + if ( obj ) // obj->EventDone(); Unref(obj); diff --git a/src/EventHandler.cc b/src/EventHandler.cc index 55f9902079..2867b63437 100644 --- a/src/EventHandler.cc +++ b/src/EventHandler.cc @@ -68,6 +68,7 @@ void EventHandler::Call(val_list* vl, bool no_remote) } if ( local ) + // No try/catch here; we pass exceptions upstream. Unref(local->Call(vl)); else { diff --git a/src/Expr.cc b/src/Expr.cc index 9fecab4019..f6d1fc568e 100644 --- a/src/Expr.cc +++ b/src/Expr.cc @@ -3118,8 +3118,9 @@ Val* FieldExpr::Fold(Val* v) const return def_attr->AttrExpr()->Eval(0); else { - Internal("field value missing"); - return 0; + reporter->ExprRuntimeError(this, "field value missing"); + assert(false); + return 0; // Will never get here, but compiler can't tell. } } @@ -3730,6 +3731,7 @@ Val* RecordMatchExpr::Fold(Val* v1, Val* v2) const } } + // No try/catch here; we pass exceptions upstream. Val* pred_val = match_rec->Lookup(pred_field_index)->AsFunc()->Call(&args); bool is_zero = pred_val->IsZero(); @@ -4220,7 +4222,7 @@ Val* FlattenExpr::Fold(Val* v) const l->Append(fa->AttrExpr()->Eval(0)); else - Internal("missing field value"); + reporter->ExprRuntimeError(this, "missing field value"); } return l; @@ -4646,7 +4648,7 @@ Val* CallExpr::Eval(Frame* f) const if ( f ) f->SetCall(this); - ret = func->Call(v, f); + ret = func->Call(v, f); // No try/catch here; we pass exceptions upstream. if ( f ) f->ClearCall(); // Don't Unref() the arguments, as Func::Call already did that. diff --git a/src/LogMgr.cc b/src/LogMgr.cc index 3f088fd439..473f480ada 100644 --- a/src/LogMgr.cc +++ b/src/LogMgr.cc @@ -888,9 +888,18 @@ bool LogMgr::Write(EnumVal* id, RecordVal* columns) // to log this record. val_list vl(1); vl.append(columns->Ref()); - Val* v = filter->pred->Call(&vl); - int result = v->AsBool(); - Unref(v); + + int result = 1; + + try + { + Val* v = filter->pred->Call(&vl); + int result = v->AsBool(); + Unref(v); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } if ( ! result ) continue; @@ -920,7 +929,17 @@ bool LogMgr::Write(EnumVal* id, RecordVal* columns) vl.append(rec_arg); - Val* v = filter->path_func->Call(&vl); + Val* v = 0; + + try + { + v = filter->path_func->Call(&vl); + } + + catch ( InterpreterException& e ) + { + return false; + } if ( ! v->Type()->Tag() == TYPE_STRING ) { @@ -1569,9 +1588,19 @@ bool LogMgr::FinishedRotation(LogWriter* writer, string new_name, string old_nam // Call the postprocessor function. val_list vl(1); vl.append(info); - Val* v = func->Call(&vl); - int result = v->AsBool(); - Unref(v); + + int result = 0; + + try + { + Val* v = func->Call(&vl); + result = v->AsBool(); + Unref(v); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } + return result; } diff --git a/src/PersistenceSerializer.cc b/src/PersistenceSerializer.cc index c72f59c0dd..c757467f90 100644 --- a/src/PersistenceSerializer.cc +++ b/src/PersistenceSerializer.cc @@ -200,7 +200,13 @@ void PersistenceSerializer::GotEvent(const char* name, double time, void PersistenceSerializer::GotFunctionCall(const char* name, double time, Func* func, val_list* args) { - func->Call(args); + try + { + func->Call(args); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } } void PersistenceSerializer::GotStateAccess(StateAccess* s) diff --git a/src/RemoteSerializer.cc b/src/RemoteSerializer.cc index e359a4a749..79268946d5 100644 --- a/src/RemoteSerializer.cc +++ b/src/RemoteSerializer.cc @@ -2809,7 +2809,13 @@ void RemoteSerializer::GotFunctionCall(const char* name, double time, return; } - function->Call(args); + try + { + function->Call(args); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } } void RemoteSerializer::GotID(ID* id, Val* val) diff --git a/src/Reporter.cc b/src/Reporter.cc index b2bffd3432..fca9a6a233 100644 --- a/src/Reporter.cc +++ b/src/Reporter.cc @@ -39,7 +39,7 @@ void Reporter::Info(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - DoLog("", reporter_info, stderr, 0, 0, true, true, fmt, ap); + DoLog("", reporter_info, stderr, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -47,7 +47,7 @@ void Reporter::Warning(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - DoLog("warning", reporter_warning, stderr, 0, 0, true, true, fmt, ap); + DoLog("warning", reporter_warning, stderr, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -56,7 +56,7 @@ void Reporter::Error(const char* fmt, ...) ++errors; va_list ap; va_start(ap, fmt); - DoLog("error", reporter_error, stderr, 0, 0, true, true, fmt, ap); + DoLog("error", reporter_error, stderr, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -66,7 +66,7 @@ void Reporter::FatalError(const char* fmt, ...) va_start(ap, fmt); // Always log to stderr. - DoLog("fatal error", 0, stderr, 0, 0, true, false, fmt, ap); + DoLog("fatal error", 0, stderr, 0, 0, true, false, 0, fmt, ap); va_end(ap); @@ -80,7 +80,7 @@ void Reporter::FatalErrorWithCore(const char* fmt, ...) va_start(ap, fmt); // Always log to stderr. - DoLog("fatal error", 0, stderr, 0, 0, true, false, fmt, ap); + DoLog("fatal error", 0, stderr, 0, 0, true, false, 0, fmt, ap); va_end(ap); @@ -88,13 +88,29 @@ void Reporter::FatalErrorWithCore(const char* fmt, ...) abort(); } +void Reporter::ExprRuntimeError(const Expr* expr, const char* fmt, ...) + { + ++errors; + + ODesc d; + expr->Describe(&d); + + PushLocation(expr->GetLocationInfo()); + va_list ap; + va_start(ap, fmt); + DoLog("expression error", reporter_error, stderr, 0, 0, true, true, d.Description(), fmt, ap); + va_end(ap); + PopLocation(); + throw InterpreterException(); + } + void Reporter::InternalError(const char* fmt, ...) { va_list ap; va_start(ap, fmt); // Always log to stderr. - DoLog("internal error", 0, stderr, 0, 0, true, false, fmt, ap); + DoLog("internal error", 0, stderr, 0, 0, true, false, 0, fmt, ap); va_end(ap); @@ -106,7 +122,7 @@ void Reporter::InternalWarning(const char* fmt, ...) { va_list ap; va_start(ap, fmt); - DoLog("internal warning", reporter_warning, stderr, 0, 0, true, true, fmt, ap); + DoLog("internal warning", reporter_warning, stderr, 0, 0, true, true, 0, fmt, ap); va_end(ap); } @@ -133,7 +149,7 @@ void Reporter::WeirdHelper(EventHandlerPtr event, Val* conn_val, const char* add va_list ap; va_start(ap, fmt_name); - DoLog("weird", event, stderr, 0, vl, false, false, fmt_name, ap); + DoLog("weird", event, stderr, 0, vl, false, false, 0, fmt_name, ap); va_end(ap); delete vl; @@ -147,7 +163,7 @@ void Reporter::WeirdFlowHelper(const uint32* orig, const uint32* resp, const cha va_list ap; va_start(ap, fmt_name); - DoLog("weird", flow_weird, stderr, 0, vl, false, false, fmt_name, ap); + DoLog("weird", flow_weird, stderr, 0, vl, false, false, 0, fmt_name, ap); va_end(ap); delete vl; @@ -173,7 +189,7 @@ void Reporter::Weird(const uint32* orig, const uint32* resp, const char* name) WeirdFlowHelper(orig, resp, "%s", name); } -void Reporter::DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Connection* conn, val_list* addl, bool location, bool time, const char* fmt, va_list ap) +void Reporter::DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Connection* conn, val_list* addl, bool location, bool time, const char* postfix, const char* fmt, va_list ap) { static char tmp[512]; @@ -235,6 +251,9 @@ void Reporter::DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Conne int n = vsnprintf(buffer, size, fmt, aq); va_end(aq); + if ( postfix ) + n += strlen(postfix) + 10; // Add a bit of slack. + if ( n > -1 && n < size ) // We had enough space; break; @@ -247,6 +266,11 @@ void Reporter::DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Conne FatalError("out of memory in Reporter"); } + if ( postfix ) + // Note, if you change this fmt string, adjust the additional + // buffer size above. + sprintf(buffer + strlen(buffer), " [%s]", postfix); + if ( event && via_events && ! in_error_handler ) { val_list* vl = new val_list; diff --git a/src/Reporter.h b/src/Reporter.h index d0fc66299b..52a2aff53a 100644 --- a/src/Reporter.h +++ b/src/Reporter.h @@ -14,6 +14,22 @@ class Connection; class Location; +class Reporter; + +// One cannot raise this exception directly, go through the +// Reporter's methods instead. + +class ReporterException { +protected: + friend class Reporter; + ReporterException() {} +}; + +class InterpreterException : public ReporterException { +protected: + friend class Reporter; + InterpreterException() {} +}; class Reporter { public: @@ -42,6 +58,10 @@ public: // reported and always generate a core dump. void FatalErrorWithCore(const char* fmt, ...); + // Report a runtime error in evaluating a Bro script expression. This + // function will not return but raise an InterpreterException. + void ExprRuntimeError(const Expr* expr, const char* fmt, ...); + // Report a traffic weirdness, i.e., an unexpected protocol situation // that may lead to incorrectly processing a connnection. void Weird(const char* name); // Raises net_weird(). @@ -87,7 +107,9 @@ public: void EndErrorHandler() { --in_error_handler; } private: - void DoLog(const char* prefix, EventHandlerPtr event, FILE* out, Connection* conn, val_list* addl, bool location, bool time, const char* fmt, va_list ap); + void DoLog(const char* prefix, EventHandlerPtr event, FILE* out, + Connection* conn, val_list* addl, bool location, bool time, + const char* postfix, const char* fmt, va_list ap); // The order if addl, name needs to be like that since fmt_name can // contain format specifiers diff --git a/src/RuleCondition.cc b/src/RuleCondition.cc index 1b94fcffe6..8852747cc4 100644 --- a/src/RuleCondition.cc +++ b/src/RuleCondition.cc @@ -149,9 +149,19 @@ bool RuleConditionEval::DoMatch(Rule* rule, RuleEndpointState* state, else args.append(new StringVal("")); - Val* val = id->ID_Val()->AsFunc()->Call(&args); - bool result = val->AsBool(); - Unref(val); + bool result = 0; + + try + { + Val* val = id->ID_Val()->AsFunc()->Call(&args); + result = val->AsBool(); + Unref(val); + } + + catch ( InterpreterException& e ) + { + result = false; + } return result; } diff --git a/src/Sessions.cc b/src/Sessions.cc index 1d2604b8db..572e8dea59 100644 --- a/src/Sessions.cc +++ b/src/Sessions.cc @@ -331,7 +331,14 @@ void NetSessions::NextPacketSecondary(double /* t */, const struct pcap_pkthdr* args->append(cmd_val); args->append(BuildHeader(ip)); // ### Need to queue event here. - sp->Event()->Event()->Call(args); + try + { + sp->Event()->Event()->Call(args); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } + delete args; } } diff --git a/src/Val.cc b/src/Val.cc index 164994b3b8..ddf04bb528 100644 --- a/src/Val.cc +++ b/src/Val.cc @@ -2007,7 +2007,16 @@ Val* TableVal::Default(Val* index) else vl->append(index->Ref()); - Val* result = f->Call(vl); + Val* result = 0; + + try + { + result = f->Call(vl); + } + + catch ( InterpreterException& e ) + { /* Already reported. */ } + delete vl; if ( ! result ) @@ -2466,10 +2475,20 @@ double TableVal::CallExpireFunc(Val* idx) vl->append(idx); - Val* vs = expire_expr->Eval(0)->AsFunc()->Call(vl); - double secs = vs->AsInterval(); - Unref(vs); - delete vl; + double secs; + + try + { + Val* vs = expire_expr->Eval(0)->AsFunc()->Call(vl); + secs = vs->AsInterval(); + Unref(vs); + delete vl; + } + + catch ( InterpreterException& e ) + { + secs = 0; + } return secs; } From c81d428256b0478510d1782744e6d47fcb69e3d0 Mon Sep 17 00:00:00 2001 From: Robin Sommer Date: Sun, 9 Oct 2011 20:41:55 -0700 Subject: [PATCH 2/2] Adding test for new error handling. --- .../btest/Baseline/core.expr-exception/reporter.log | 13 +++++++++++++ testing/btest/core/expr-exception.bro | 9 +++++++++ 2 files changed, 22 insertions(+) create mode 100644 testing/btest/Baseline/core.expr-exception/reporter.log create mode 100644 testing/btest/core/expr-exception.bro diff --git a/testing/btest/Baseline/core.expr-exception/reporter.log b/testing/btest/Baseline/core.expr-exception/reporter.log new file mode 100644 index 0000000000..2dfe6b7b8e --- /dev/null +++ b/testing/btest/Baseline/core.expr-exception/reporter.log @@ -0,0 +1,13 @@ +#separator \x09 +#path reporter +#fields ts level message location +#types time enum string string +1300475168.783842 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.915940 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.916118 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.918295 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.952193 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.952228 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.954761 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475168.962628 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 +1300475169.780331 Reporter::ERROR field value missing [c$ftp] /home/robin/bro/master/testing/btest/.tmp/core.expr-exception/expr-exception.bro, line 8 diff --git a/testing/btest/core/expr-exception.bro b/testing/btest/core/expr-exception.bro new file mode 100644 index 0000000000..c4fe998af0 --- /dev/null +++ b/testing/btest/core/expr-exception.bro @@ -0,0 +1,9 @@ +# Bro shouldn't crash when doing nothing, nor outputting anything. +# +# @TEST-EXEC: cat /dev/null | bro -r $TRACES/wikipedia.trace %INPUT +# @TEST-EXEC: btest-diff reporter.log + +event connection_established(c: connection) + { + print c$ftp; + }