diff --git a/.gitignore b/.gitignore index af53311..e932198 100644 --- a/.gitignore +++ b/.gitignore @@ -58,3 +58,6 @@ src/logdconfig.lua src/logdconfig.lua.h test/helper.sh + +# six +*.swp diff --git a/README.md b/README.md index 5b5c6ba..5d0481d 100644 --- a/README.md +++ b/README.md @@ -16,9 +16,9 @@ Logd is a log scanner daemon that exposes a Lua API to run arbitrary logic on st | Hook | Description | | --- | --- | -| `function logd.on_log (logptr)` | Logs are scanned and supplied to this handler. Use `logd.log_*` set of functions to manipulate them. | +| `function logd.on_log (logptr, logstr)` | Logs are scanned and supplied to this handler. Use `logd.log_*` set of functions to manipulate them. | | `function logd.on_exit (code, reason)` | Called when collector is gracefully terminating. | -| `function logd.on_error (error, logptr, at)` | Called when collector failed to scan a log line. Scanning will resume after this function returns. | +| `function logd.on_error (error, logptr, at, logstr)` | Called when collector failed to scan a log line. Scanning will resume after this function returns. | ## Preloaded Lua modules - [logd](#logd-module-api) diff --git a/src/logd.c b/src/logd.c index bd3528a..eb02719 100644 --- a/src/logd.c +++ b/src/logd.c @@ -145,8 +145,7 @@ char* args_init(int argc, char* argv[]) return NULL; } backoff = - strncmp(LINEAL_BACKOFF, optarg, strlen(LINEAL_BACKOFF)) == 0 ? 1 : - 2; + strncmp(LINEAL_BACKOFF, optarg, strlen(LINEAL_BACKOFF)) == 0 ? 1 : 2; break; case 'd': if ((args.reopen_delay = parse_non_negative_int(optarg)) == -1 || @@ -465,16 +464,16 @@ bool logd_buf_compact() return 1; } -void call_on_error(lua_t* l, const char* err, log_t* partial, const char* at) +void call_on_error(lua_t* l, const char* err, log_t* partial, const char* data, const char* at) { partial->is_safe = true; - lua_call_on_error(lstate, err, partial, at); + lua_call_on_error(lstate, err, partial, data, at); partial->is_safe = false; } -#define CALL_ON_LOG(lstate, res) \ +#define CALL_ON_LOG(lstate, input, res) \ res.log->is_safe = true; \ - lua_call_on_log(lstate, res.log); \ + lua_call_on_log(lstate, input, res.log); \ buf_consume(b, res.consumed); \ logd_reset_scanner(); \ res.log->is_safe = false; @@ -504,14 +503,14 @@ void on_read_eof() res = scan_scanner(scanner, b->next_read, buf_readable(b)); switch (res.type) { case SCAN_COMPLETE: - CALL_ON_LOG(lstate, res); + CALL_ON_LOG(lstate, b->next_read, res); goto scan; case SCAN_ERROR: DEBUG_LOG("EOF scan error: %s", res.error.msg); - buf_ack(b, res.consumed); if (lua_on_error_defined(lstate)) { - call_on_error(lstate, res.error.msg, res.log, res.error.at); + call_on_error(lstate, res.error.msg, res.log, b->next_read, res.error.at); } + buf_ack(b, res.consumed); logd_reset_scanner(); goto scan; case SCAN_PARTIAL: @@ -564,7 +563,7 @@ void on_read_skip(uv_poll_t* req, int status, int events) call_on_error(lstate, "log line was skipped because it is more than " STR( LOGD_BUF_MAX_CAP) " bytes", - res.log, ""); + res.log, b->next_read, ""); } buf_ack(b, res.consumed); DEBUG_LOG("successfully skipped line: buffer has now %zu readable bytes " @@ -593,15 +592,15 @@ void on_read(uv_poll_t* req, int status, int events) case SCAN_COMPLETE: // DEBUG_LOG("scanned new log: %p", &res.log); - CALL_ON_LOG(lstate, res); + CALL_ON_LOG(lstate, b->next_read, res); goto scan; case SCAN_ERROR: DEBUG_LOG("scan error: %s", res.error.msg); - buf_ack(b, res.consumed); if (lua_on_error_defined(lstate)) { - call_on_error(lstate, res.error.msg, res.log, res.error.at); + call_on_error(lstate, res.error.msg, res.log, b->next_read, res.error.at); } + buf_ack(b, res.consumed); logd_reset_scanner(); goto scan; diff --git a/src/lua.c b/src/lua.c index d3ae98f..75256bc 100644 --- a/src/lua.c +++ b/src/lua.c @@ -225,14 +225,15 @@ int lua_init(lua_t* l, uv_loop_t* loop, const char* script) return -1; } -void lua_call_on_log(lua_t* l, log_t* log) +void lua_call_on_log(lua_t* l, const char* data, log_t* log) { lua_getglobal(l->state, ON_LOG_INTERNAL); DEBUG_ASSERT(lua_isfunction(l->state, -1)); lua_pushlightuserdata(l->state, log); + lua_pushstring(l->state, data); - lua_call(l->state, 1, 0); + lua_call(l->state, 2, 0); } bool lua_on_error_defined(lua_t* l) @@ -247,7 +248,7 @@ bool lua_on_error_defined(lua_t* l) } void lua_call_on_error( - lua_t* l, const char* err, log_t* partial, const char* at) + lua_t* l, const char* err, log_t* partial, const char* data, const char* at) { lua_push_on_error(l->state); DEBUG_ASSERT(lua_isfunction(l->state, -1)); @@ -255,8 +256,9 @@ void lua_call_on_error( lua_pushstring(l->state, err); lua_pushlightuserdata(l->state, partial); lua_pushstring(l->state, at); + lua_pushstring(l->state, data); - lua_call(l->state, 3, 0); + lua_call(l->state, 4, 0); lua_pop(l->state, 1); // logd module } diff --git a/src/lua.h b/src/lua.h index 076fc46..0877611 100644 --- a/src/lua.h +++ b/src/lua.h @@ -15,10 +15,10 @@ typedef struct lua_s { lua_t* lua_create(uv_loop_t* loop, const char* script); int lua_init(lua_t* l, uv_loop_t* loop, const char* script); -void lua_call_on_log(lua_t*, log_t* log); +void lua_call_on_log(lua_t*, const char* data, log_t* log); bool lua_on_error_defined(lua_t*); void lua_call_on_error( - lua_t*, const char* err, log_t* partial, const char* remaining); + lua_t*, const char* err, log_t* partial, const char* data, const char* remaining); bool lua_on_exit_defined(lua_t*); void lua_call_on_exit( lua_t* l, enum exit_reason reason, const char* reason_str); diff --git a/test/test_error.sh b/test/test_error.sh old mode 100755 new mode 100644 index 6ef72c1..f5eb487 --- a/test/test_error.sh +++ b/test/test_error.sh @@ -39,26 +39,31 @@ end function logd.on_exit() assert(logs == 3) end -function logd.on_error(error, logptr, at) +function logd.on_error(error, logptr, at, logstr) local error_expected local at_expected + local logstr_expected errors = errors + 1 -- should be able to use log_get on logptr logd.log_get(logptr, "date") if errors == 1 then error_expected = "incomplete header" at_expected = "" + logstr_expected = "" elseif errors == 2 then error_expected = "invalid date or time in log header" at_expected = "GARBAGE DEBUG [thread4] clazz callType: b: ," + logstr_expected = "2018-05-12 GARBAGE DEBUG [thread4] clazz callType: b: ," else error_expected = "reached max number of log properties: $LOGD_SLAB_CAP" + logstr_expected = "2018-05-12 12:55:22 TRACE [thread5] clazz tooManyProps: b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, : c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C, b: c: C," end assert(errors < 4) assert(error == error_expected, string.format("error was '%s' instead of '%s'", error, error_expected)) if at_expected ~= nil then assert(at == at_expected, string.format("at was '%s' instead of '%s'", at, at_expected)) + assert(logstr == logstr_expected, string.format("logstr was '%s' instead of '%s'", logstr, logstr_expected)) end end EOF diff --git a/test/test_log.sh b/test/test_log.sh old mode 100755 new mode 100644 index 2cc5a3c..13e7005 --- a/test/test_log.sh +++ b/test/test_log.sh @@ -31,31 +31,35 @@ EOF cat >$SCRIPT << EOF local logd = require("logd") local counter = 0 -function logd.on_log(logptr) +function logd.on_log(logptr, logstr) if counter == 0 then assert("ERROR" == logd.log_get(logptr, "level")) assert("thread1" == logd.log_get(logptr, "thread")) assert("clazz" == logd.log_get(logptr, "class")) assert(nil == logd.log_get(logptr, "callType")) assert("A" == logd.log_get(logptr, "a")) + assert("2018-05-12 12:51:28 ERROR [thread1] clazz a: A, ", logstr) elseif counter == 1 then assert("WARN" == logd.log_get(logptr, "level")) assert("thread2" == logd.log_get(logptr, "thread")) assert("clazz" == logd.log_get(logptr, "class")) assert("callType" == logd.log_get(logptr, "callType")) assert("B" == logd.log_get(logptr, "b")) + assert("2018-05-12 12:52:22 WARN [thread2] clazz callType: b: B", logstr) elseif counter == 2 then assert("INFO" == logd.log_get(logptr, "level")) assert("thread3" == logd.log_get(logptr, "thread")) assert("clazz" == logd.log_get(logptr, "class")) assert("callType" == logd.log_get(logptr, "callType")) assert("C" == logd.log_get(logptr, "c")) + assert("2018-05-12 12:53:22 INFO [thread3] clazz callType: c: C, ", logstr) elseif counter == 3 then assert("DEBUG" == logd.log_get(logptr, "level")) assert("thread4" == logd.log_get(logptr, "thread")) assert("clazz" == logd.log_get(logptr, "class")) assert("callType" == logd.log_get(logptr, "callType")) assert("" == logd.log_get(logptr, "b")) + assert("2018-05-12 12:54:22 DEBUG [thread4] clazz callType: b: ,", logstr) else assert("TRACE" == logd.log_get(logptr, "level")) assert("thread5" == logd.log_get(logptr, "thread")) @@ -63,6 +67,7 @@ function logd.on_log(logptr) assert("callType" == logd.log_get(logptr, "callType")) assert("c: C" == logd.log_get(logptr, "b")) assert(nil == logd.log_get(logptr, "c")) + assert("2018-05-12 12:55:22 TRACE [thread5] clazz callType: b: c: C, ", logstr) end counter = counter + 1 end