Overhauling the internal reporting of messages to the user.

The Logger class is now in charge of reporting all errors, warnings,
informational messages, weirds, and syslogs. All other components
route their messages through the global bro_logger singleton.

The Logger class comes with these reporting methods:

    void Message(const char* fmt, ...);
    void Warning(const char* fmt, ...);
    void Error(const char* fmt, ...);
    void FatalError(const char* fmt, ...); // Terminate Bro.
    void Weird(const char* name);
    [ .. some more Weird() variants ... ]
    void Syslog(const char* fmt, ...);
    void InternalWarning(const char* fmt, ...);
    void InternalError(const char* fmt, ...); // Terminates Bro.

See Logger.h for more information on these.

Generally, the reporting now works as follows:

    - All non-fatal message are reported in one of two ways:

        (1) At startup (i.e., before we start processing packets),
            they are logged to stderr.

        (2) During processing, they turn into events:

            event log_message%(msg: string, location: string%);
            event log_warning%(msg: string, location: string%);
            event log_error%(msg: string, location: string%);

            The script level can then handle them as desired.

            If we don't have an event handler, we fall back to
            reporting on stderr.

    - All fatal errors are logged to stderr and Bro terminates
      immediately.

    - Syslog(msg) directly syslogs, but doesn't do anything else.

The three main types of messages can also be generated on the
scripting layer via new Log::* bifs:

    Log::error(msg: string);
    Log::warning(msg: string);
    Log::message(msg: string);

These pass through the bro_logger as well and thus are handled in the
same way. Their output includes location information.

More changes:

    - Removed the alarm statement and the alarm_hook event.

    - Adapted lots of locations to use the bro_logger, including some
      of the messages that were previously either just written to
      stdout, or even funneled through the alarm mechanism.

    - No distinction anymore between Error() and RunTime(). There's
      now only one class of errors; the line was quite blurred already
      anyway.

    - util.h: all the error()/warn()/message()/run_time()/pinpoint()
      functions are gone. Use the bro_logger instead now.

    - Script errors are formatted a bit differently due to the
      changes. What I've seen so far looks ok to me, but let me know
      if there's something odd.

Notes:

    - The default handlers for the new log_* events are just dummy
      implementations for now since we need to integrate all this into
      the new scripts anyway.

    - I'm not too happy with the names of the Logger class and its
      instance bro_logger. We now have a LogMgr as well, which makes
      this all a bit confusing. But I didn't have a good idea for
      better names so I stuck with them for now.

      Perhaps we should merge Logger and LogMgr?
This commit is contained in:
Robin Sommer 2011-06-24 21:33:05 -07:00
parent ff7b92ffc8
commit 93894eed9b
140 changed files with 2453 additions and 1054 deletions

View file

@ -38,6 +38,7 @@
#include "Val.h"
#include "NetVar.h"
#include "Net.h"
#include "Logger.h"
char* copy_string(const char* s)
{
@ -83,7 +84,7 @@ int expand_escape(const char*& s)
int result;
if ( sscanf(start, "%3o", &result) != 1 )
{
warn("bad octal escape: ", start);
bro_logger->Warning("bad octal escape: ", start);
result = 0;
}
@ -102,7 +103,7 @@ int expand_escape(const char*& s)
int result;
if ( sscanf(start, "%2x", &result) != 1 )
{
warn("bad hexadecimal escape: ", start);
bro_logger->Warning("bad hexadecimal escape: ", start);
result = 0;
}
@ -229,7 +230,7 @@ unsigned char encode_hex(int h)
if ( h < 0 || h >= 16 )
{
internal_error("illegal value for encode_hex: %d", h);
bro_logger->InternalError("illegal value for encode_hex: %d", h);
return 'X';
}
@ -455,7 +456,7 @@ const char* fmt(const char* format, ...)
va_end(al);
if ( (unsigned int) n >= buf_len )
internal_error("confusion reformatting in fmt()");
bro_logger->InternalError("confusion reformatting in fmt()");
}
return buf;
@ -476,14 +477,14 @@ bool ensure_dir(const char *dirname)
{
if ( errno != ENOENT )
{
warn(fmt("can't stat directory %s: %s",
bro_logger->Warning(fmt("can't stat directory %s: %s",
dirname, strerror(errno)));
return false;
}
if ( mkdir(dirname, 0700) < 0 )
{
warn(fmt("can't create directory %s: %s",
bro_logger->Warning(fmt("can't create directory %s: %s",
dirname, strerror(errno)));
return false;
}
@ -491,7 +492,7 @@ bool ensure_dir(const char *dirname)
else if ( ! S_ISDIR(st.st_mode) )
{
warn(fmt("%s exists but is not a directory", dirname));
bro_logger->Warning(fmt("%s exists but is not a directory", dirname));
return false;
}
@ -504,7 +505,7 @@ bool is_dir(const char* path)
if ( stat(path, &st) < 0 )
{
if ( errno != ENOENT )
warn(fmt("can't stat %s: %s", path, strerror(errno)));
bro_logger->Warning(fmt("can't stat %s: %s", path, strerror(errno)));
return false;
}
@ -536,7 +537,7 @@ uint8 shared_hmac_md5_key[16];
void hmac_md5(size_t size, const unsigned char* bytes, unsigned char digest[16])
{
if ( ! hmac_key_set )
internal_error("HMAC-MD5 invoked before the HMAC key is set");
bro_logger->InternalError("HMAC-MD5 invoked before the HMAC key is set");
hash_md5(size, bytes, digest);
@ -554,14 +555,14 @@ static bool read_random_seeds(const char* read_file, uint32* seed,
if ( stat(read_file, &st) < 0 )
{
warn(fmt("Seed file '%s' does not exist: %s",
bro_logger->Warning(fmt("Seed file '%s' does not exist: %s",
read_file, strerror(errno)));
return false;
}
if ( ! (f = fopen(read_file, "r")) )
{
warn(fmt("Could not open seed file '%s': %s",
bro_logger->Warning(fmt("Could not open seed file '%s': %s",
read_file, strerror(errno)));
return false;
}
@ -597,7 +598,7 @@ static bool write_random_seeds(const char* write_file, uint32 seed,
if ( ! (f = fopen(write_file, "w+")) )
{
warn(fmt("Could not create seed file '%s': %s",
bro_logger->Warning(fmt("Could not create seed file '%s': %s",
write_file, strerror(errno)));
return false;
}
@ -632,7 +633,7 @@ void init_random_seed(uint32 seed, const char* read_file, const char* write_file
if ( read_file )
{
if ( ! read_random_seeds(read_file, &seed, buf, bufsiz) )
fprintf(stderr, "Could not load seeds from file '%s'.\n",
bro_logger->Error("Could not load seeds from file '%s'.\n",
read_file);
else
seeds_done = true;
@ -695,7 +696,7 @@ void init_random_seed(uint32 seed, const char* read_file, const char* write_file
}
if ( write_file && ! write_random_seeds(write_file, seed, buf, bufsiz) )
fprintf(stderr, "Could not write seeds to file '%s'.\n",
bro_logger->Error("Could not write seeds to file '%s'.\n",
write_file);
}
@ -735,105 +736,6 @@ uint64 rand64bit()
return base;
}
void message(const char* msg)
{
pinpoint();
fprintf(stderr, "%s\n", msg);
}
void warn(const char* msg)
{
pinpoint();
fprintf(stderr, "warning: %s\n", msg);
++nwarn;
}
void warn(const char* msg, const char* addl)
{
pinpoint();
fprintf(stderr, "warning: %s %s\n", msg, addl);
++nwarn;
}
void error(const char* msg)
{
pinpoint();
fprintf(stderr, "error: %s\n", msg);
++nerr;
}
void error(const char* msg, const char* addl)
{
pinpoint();
fprintf(stderr, "error: %s %s\n", msg, addl);
++nerr;
}
void error(const char* msg, uint32 addl)
{
pinpoint();
fprintf(stderr, "error: %s - %u\n", msg, addl);
++nerr;
}
void run_time(const char* msg)
{
pinpoint();
fprintf(stderr, "run-time error: %s\n", msg);
++nruntime;
}
void run_time(const char* fmt, BroObj* obj)
{
ODesc d;
obj->Describe(&d);
run_time(fmt, d.Description());
}
void run_time(const char* fmt, const char* arg)
{
pinpoint();
fprintf(stderr, "run-time error: ");
fprintf(stderr, fmt, arg);
fprintf(stderr, "\n");
++nruntime;
}
void run_time(const char* fmt, const char* arg1, const char* arg2)
{
pinpoint();
fprintf(stderr, "run-time error: ");
fprintf(stderr, fmt, arg1, arg2);
fprintf(stderr, "\n");
++nruntime;
}
void internal_error(const char* fmt, ...)
{
va_list al;
pinpoint();
fprintf(stderr, "internal error: ");
va_start(al, fmt);
vfprintf(stderr, fmt, al);
va_end(al);
fprintf(stderr, "\n");
set_processing_status("TERMINATED", "internal_error");
abort();
}
void pinpoint()
{
if ( network_time > 0.0 )
fprintf(stderr, "%.6f ", network_time);
else
{
if ( filename )
fprintf(stderr, "%s, ", filename);
fprintf(stderr, "line %d: ", line_number);
}
}
int int_list_cmp(const void* v1, const void* v2)
{
ptr_compat_int i1 = *(ptr_compat_int*) v1;
@ -974,7 +876,7 @@ FILE* rotate_file(const char* name, RecordVal* rotate_info)
FILE* newf = fopen(tmpname, "w");
if ( ! newf )
{
run_time(fmt("rotate_file: can't open %s: %s", tmpname, strerror(errno)));
bro_logger->Error(fmt("rotate_file: can't open %s: %s", tmpname, strerror(errno)));
return 0;
}
@ -983,7 +885,7 @@ FILE* rotate_file(const char* name, RecordVal* rotate_info)
struct stat dummy;
if ( link(name, newname) < 0 || stat(newname, &dummy) < 0 )
{
run_time(fmt("rotate_file: can't move %s to %s: %s", name, newname, strerror(errno)));
bro_logger->Error(fmt("rotate_file: can't move %s to %s: %s", name, newname, strerror(errno)));
fclose(newf);
unlink(newname);
unlink(tmpname);
@ -993,7 +895,7 @@ FILE* rotate_file(const char* name, RecordVal* rotate_info)
// Close current file, and move the tmp to its place.
if ( unlink(name) < 0 || link(tmpname, name) < 0 || unlink(tmpname) < 0 )
{
run_time(fmt("rotate_file: can't move %s to %s: %s", tmpname, name, strerror(errno)));
bro_logger->Error(fmt("rotate_file: can't move %s to %s: %s", tmpname, name, strerror(errno)));
exit(1); // hard to fix, but shouldn't happen anyway...
}
@ -1033,7 +935,7 @@ double calc_next_rotate(double interval, const char* rotate_base_time)
{
struct tm t;
if ( ! strptime(rotate_base_time, "%H:%M", &t) )
run_time("calc_next_rotate(): can't parse rotation base time");
bro_logger->Error("calc_next_rotate(): can't parse rotation base time");
else
base = t.tm_min * 60 + t.tm_hour * 60 * 60;
}
@ -1096,7 +998,7 @@ double current_time(bool real)
{
struct timeval tv;
if ( gettimeofday(&tv, 0) < 0 )
internal_error("gettimeofday failed in current_time()");
bro_logger->InternalError("gettimeofday failed in current_time()");
double t = double(tv.tv_sec) + double(tv.tv_usec) / 1e6;
@ -1186,8 +1088,7 @@ uint64 calculate_unique_id()
void out_of_memory(const char* where)
{
fprintf( stderr, "bro: out of memory in %s.\n", where );
abort();
bro_logger->FatalError("out of memory in %s.\n", where);
}
void get_memory_usage(unsigned int* total, unsigned int* malloced)