From 20dfff0663faff9851767ecfb450577b6f4f1656 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Stefan=20B=C3=BChler?= Date: Tue, 30 Dec 2008 14:24:33 +0100 Subject: [PATCH] Cleanup log macros (moved from con to vrequest) --- include/lighttpd/log.h | 66 +++++++++++++++------------------------ src/angel_fake.c | 4 +-- src/config_lua.c | 2 +- src/config_parser.rl | 48 ++++++++++++++-------------- src/connection.c | 28 ++++++++--------- src/lighttpd.c | 6 ++-- src/log.c | 13 ++++---- src/modules/mod_fortune.c | 2 +- src/modules/mod_status.c | 6 ++-- src/plugin_core.c | 8 ++--- src/request.c | 2 +- src/virtualrequest.c | 2 +- src/worker.c | 4 +-- 13 files changed, 87 insertions(+), 104 deletions(-) diff --git a/include/lighttpd/log.h b/include/lighttpd/log.h index 588c04b..2d2b9dd 100644 --- a/include/lighttpd/log.h +++ b/include/lighttpd/log.h @@ -15,34 +15,37 @@ LI_API const char *remove_path(const char *path); #define REMOVE_PATH(file) file #endif -#define VR_ERROR(vr, fmt, ...) CON_ERROR(vr->con, fmt, __VA_ARGS__) -#define VR_TRACE(vr, fmt, ...) CON_TRACE(vr->con, fmt, __VA_ARGS__) -#define VR_SEGFAULT(vr, fmt, ...) CON_SEGFAULT(vr->con, fmt, __VA_ARGS__) +#define _SEGFAULT(srv, vr, fmt, ...) \ + do { \ + log_write_(srv, NULL, LOG_LEVEL_ABORT, LOG_FLAG_TIMETAMP, "(crashing) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__); \ + /* VALGRIND_PRINTF_BACKTRACE(fmt, __VA_ARGS__); */\ + abort();\ + } while(0) -#define ERROR(srv, fmt, ...) \ - log_write_(srv, NULL, LOG_LEVEL_ERROR, LOG_FLAG_TIMETAMP, "(error) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define _ERROR(srv, vr, fmt, ...) \ + log_write_(srv, vr, LOG_LEVEL_ERROR, LOG_FLAG_TIMETAMP, "(error) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) -#define WARNING(srv, fmt, ...) \ - log_write_(srv, NULL, LOG_LEVEL_WARNING, LOG_FLAG_TIMETAMP, "(warning) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define _WARNING(srv, vr, fmt, ...) \ + log_write_(srv, vr, LOG_LEVEL_WARNING, LOG_FLAG_TIMETAMP, "(warning) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) -#define INFO(srv, fmt, ...) \ - log_write_(srv, NULL, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(info) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define _INFO(srv, vr, fmt, ...) \ + log_write_(srv, vr, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(info) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) -#define TRACE(srv, fmt, ...) \ - log_write_(srv, NULL, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(debug) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define _DEBUG(srv, vr, fmt, ...) \ + log_write_(srv, vr, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(debug) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) -#define CON_ERROR(con, fmt, ...) \ - log_write_(con->srv, con, LOG_LEVEL_ERROR, LOG_FLAG_TIMETAMP, "(error) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define VR_SEGFAULT(vr, fmt, ...) _SEGFAULT(vr->con->srv, vr, fmt, __VA_ARGS__) +#define VR_ERROR(vr, fmt, ...) _ERROR(vr->con->srv, vr, fmt, __VA_ARGS__) +#define VR_WARNING(vr, fmt, ...) _WARNING(vr->con->srv, vr, fmt, __VA_ARGS__) +#define VR_INFO(vr, fmt, ...) _INFO(vr->con->srv, vr, fmt, __VA_ARGS__) +#define VR_DEBUG(vr, fmt, ...) _DEBUG(vr->con->srv, vr, fmt, __VA_ARGS__) -#define CON_WARNING(con, fmt, ...) \ - log_write_(con->srv, con, LOG_LEVEL_WARNING, LOG_FLAG_TIMETAMP, "(warning) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define CON_INFO(con, fmt, ...) \ - log_write_(con->srv, con, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(info) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define CON_TRACE(con, fmt, ...) \ - log_write_(con->srv, con, LOG_LEVEL_DEBUG, LOG_FLAG_TIMETAMP, "(debug) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) +#define SEGFAULT(srv, fmt, ...) _SEGFAULT(srv, NULL, fmt, __VA_ARGS__) +#define ERROR(srv, fmt, ...) _ERROR(srv, NULL, fmt, __VA_ARGS__) +#define WARNING(srv, fmt, ...) _WARNING(srv, NULL, fmt, __VA_ARGS__) +#define INFO(srv, fmt, ...) _INFO(srv, NULL, fmt, __VA_ARGS__) +#define DEBUG(srv, fmt, ...) _DEBUG(srv, NULL, fmt, __VA_ARGS__) /* TODO: perhaps make portable (detect if cc supports) */ @@ -51,25 +54,6 @@ LI_API const char *remove_path(const char *path); /*LI_API int log_write(server *srv, connection *con, const char *fmt, ...) __ATTRIBUTE_PRINTF_FORMAT(3, 4);*/ - -/* convenience makros */ -#define log_error(srv, con, fmt, ...) \ - log_write_(srv, con, LOG_LEVEL_ERROR, LOG_FLAG_TIMETAMP, "(error) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define log_warning(srv, con, fmt, ...) \ - log_write_(srv, con, LOG_LEVEL_WARNING, LOG_FLAG_TIMETAMP, "(warning) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define log_info(srv, con, fmt, ...) \ - log_write_(srv, con, LOG_LEVEL_INFO, LOG_FLAG_TIMETAMP, "(info) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define log_message(srv, con, fmt, ...) \ - log_write_(srv, con, LOG_LEVEL_MESSAGE, LOG_FLAG_TIMETAMP, "(message) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - -#define log_debug(srv, con, fmt, ...) \ - log_write_(srv, con, LOG_LEVEL_DEBUG, LOG_FLAG_TIMETAMP, "(debug) %s.%d: "fmt, REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__) - - - struct log_t; typedef struct log_t log_t; @@ -161,7 +145,7 @@ void log_cleanup(server *srv); /* log_write is used to directly write a message to a log target */ LI_API void log_write(server *srv, log_t *log, GString *msg); /* log_write_ is used to write to the errorlog */ -LI_API gboolean log_write_(server *srv, connection *con, log_level_t log_level, guint flags, const gchar *fmt, ...) __ATTRIBUTE_PRINTF_FORMAT(5, 6); +LI_API gboolean log_write_(server *srv, vrequest *vr, log_level_t log_level, guint flags, const gchar *fmt, ...) __ATTRIBUTE_PRINTF_FORMAT(5, 6); log_timestamp_t *log_timestamp_new(server *srv, GString *format); gboolean log_timestamp_free(server *srv, log_timestamp_t *ts); diff --git a/src/angel_fake.c b/src/angel_fake.c index f1042c8..ea87c0d 100644 --- a/src/angel_fake.c +++ b/src/angel_fake.c @@ -37,7 +37,7 @@ int angel_fake_listen(server *srv, GString *str) { ERROR(srv, "Couldn't listen on '%s': %s", inet_ntoa(*(struct in_addr*)&ipv4), g_strerror(errno)); return -1; } - TRACE(srv, "listen to ipv4: '%s' port: %d", inet_ntoa(*(struct in_addr*)&ipv4), port); + DEBUG(srv, "listen to ipv4: '%s' port: %d", inet_ntoa(*(struct in_addr*)&ipv4), port); return s; #ifdef HAVE_IPV6 } else if (parse_ipv6(str->str, ipv6, NULL, &port)) { @@ -80,7 +80,7 @@ int angel_fake_listen(server *srv, GString *str) { g_string_free(ipv6_str, TRUE); return -1; } - TRACE(srv, "listen to ipv6: '%s' port: %d", ipv6_str->str, port); + DEBUG(srv, "listen to ipv6: '%s' port: %d", ipv6_str->str, port); g_string_free(ipv6_str, TRUE); return s; #endif diff --git a/src/config_lua.c b/src/config_lua.c index ab765f7..103bcf8 100644 --- a/src/config_lua.c +++ b/src/config_lua.c @@ -181,7 +181,7 @@ gboolean config_lua_load(server *srv, const gchar *filename) { return FALSE; } - TRACE(srv, "Loaded config script '%s'", filename); + DEBUG(srv, "Loaded config script '%s'", filename); publish_str_hash(srv, L, srv->setups, handle_server_setup); lua_setfield(L, LUA_GLOBALSINDEX, "setup"); diff --git a/src/config_parser.rl b/src/config_parser.rl index a66d9c0..ac969a8 100644 --- a/src/config_parser.rl +++ b/src/config_parser.rl @@ -254,7 +254,7 @@ gboolean negative = FALSE; if (o->type != VALUE_STRING) { - log_error(srv, NULL, "can only cast strings to integers, %s given", value_type_string(o->type)); + ERROR(srv, "can only cast strings to integers, %s given", value_type_string(o->type)); return FALSE; } @@ -266,7 +266,7 @@ for (; i < o->data.string->len; i++) { gchar c = o->data.string->str[i]; if (c < '0' || c > '9') { - log_error(srv, NULL, "%s", "cast(int) parameter doesn't look like a numerical string"); + ERROR(srv, "%s", "cast(int) parameter doesn't look like a numerical string"); return FALSE; } x = x * 10 + c - '0'; @@ -284,7 +284,7 @@ GString *str; if (o->type != VALUE_NUMBER) { - log_error(srv, NULL, "can only cast integers to strings, %s given", value_type_string(o->type)); + ERROR(srv, "can only cast integers to strings, %s given", value_type_string(o->type)); return FALSE; } @@ -356,7 +356,7 @@ else if (r->type == VALUE_NUMBER && ctx->value_op == '*') { /* str * int */ if (r->data.number < 0) { - log_error(srv, NULL, "string multiplication with negative number (%" G_GINT64_FORMAT ")?", r->data.number); + ERROR(srv, "string multiplication with negative number (%" G_GINT64_FORMAT ")?", r->data.number); return FALSE; } else if (r->data.number == 0) { @@ -408,7 +408,7 @@ } if (o == NULL) { - log_warning(srv, NULL, "erronous value statement: %s %c %s in line %zd\n", + WARNING(srv, "erronous value statement: %s %c %s in line %zd\n", value_type_string(l->type), ctx->value_op, value_type_string(r->type), ctx->line); return FALSE; @@ -454,7 +454,7 @@ t = g_hash_table_lookup(ctx->uservars, o->data.string); if (t == NULL) { - log_warning(srv, NULL, "unknown variable '%s'", o->data.string->str); + WARNING(srv, "unknown variable '%s'", o->data.string->str); value_free(o); return FALSE; } @@ -465,7 +465,7 @@ /* look up string in environment, push value onto stack */ gchar *env = getenv(o->data.string->str + 4); if (env == NULL) { - log_error(srv, NULL, "unknown environment variable: %s", o->data.string->str + 4); + ERROR(srv, "unknown environment variable: %s", o->data.string->str + 4); value_free(o); return FALSE; } @@ -478,7 +478,7 @@ a = g_hash_table_lookup(ctx->action_blocks, o->data.string); if (a == NULL) { - log_warning(srv, NULL, "unknown action block referenced: %s", o->data.string->str); + WARNING(srv, "unknown action block referenced: %s", o->data.string->str); return FALSE; } @@ -620,7 +620,7 @@ if (g_str_equal(name->data.string->str, "include")) { if (val->type != VALUE_STRING) { - log_warning(srv, NULL, "include directive takes a string as parameter, %s given", value_type_string(val->type)); + WARNING(srv, "include directive takes a string as parameter, %s given", value_type_string(val->type)); value_free(name); value_free(val); return FALSE; @@ -636,7 +636,7 @@ } else if (g_str_equal(name->data.string->str, "include_shell")) { if (val->type != VALUE_STRING) { - log_warning(srv, NULL, "include_shell directive takes a string as parameter, %s given", value_type_string(val->type)); + WARNING(srv, "include_shell directive takes a string as parameter, %s given", value_type_string(val->type)); value_free(name); value_free(val); return FALSE; @@ -716,7 +716,7 @@ else if (g_str_has_prefix(str, "uest.")) str += 5; else { - log_warning(srv, NULL, "unkown lvalue for condition: %s", n->data.string->str); + WARNING(srv, "unkown lvalue for condition: %s", n->data.string->str); return FALSE; } @@ -732,13 +732,13 @@ lvalue = condition_lvalue_new(COMP_REQUEST_SCHEME, NULL); else if (g_str_equal(str, "header")) { if (k == NULL) { - log_warning(srv, NULL, "%s", "header conditional needs a key"); + WARNING(srv, "%s", "header conditional needs a key"); return FALSE; } lvalue = condition_lvalue_new(COMP_REQUEST_HEADER, value_extract(k).string); } else { - log_warning(srv, NULL, "unkown lvalue for condition: %s", n->data.string->str); + WARNING(srv, "unkown lvalue for condition: %s", n->data.string->str); return FALSE; } } @@ -749,7 +749,7 @@ else if (g_str_has_prefix(str, "ical.")) str += 5; else { - log_warning(srv, NULL, "unkown lvalue for condition: %s", n->data.string->str); + WARNING(srv, "unkown lvalue for condition: %s", n->data.string->str); return FALSE; } @@ -760,12 +760,12 @@ else if (g_str_equal(str, "size")) lvalue = condition_lvalue_new(COMP_PHYSICAL_SIZE, NULL); else { - log_warning(srv, NULL, "unkown lvalue for condition: %s", n->data.string->str); + WARNING(srv, "unkown lvalue for condition: %s", n->data.string->str); return FALSE; } } else { - log_warning(srv, NULL, "unkown lvalue for condition: %s", n->data.string->str); + WARNING(srv, "unkown lvalue for condition: %s", n->data.string->str); return FALSE; } @@ -780,7 +780,7 @@ if (cond == NULL) { - log_warning(srv, NULL, "%s", "could not create condition"); + WARNING(srv, "%s", "could not create condition"); return FALSE; } @@ -1123,7 +1123,7 @@ gboolean config_parser_file(server *srv, GList *ctx_stack, const gchar *path) { if (!g_file_get_contents(path, &ctx->ptr, &ctx->len, &err)) { /* could not read file */ - log_warning(srv, NULL, "could not read config file \"%s\". reason: \"%s\" (%d)", path, err->message, err->code); + WARNING(srv, "could not read config file \"%s\". reason: \"%s\" (%d)", path, err->message, err->code); config_parser_context_free(srv, ctx, FALSE); g_error_free(err); return FALSE; @@ -1135,7 +1135,7 @@ gboolean config_parser_file(server *srv, GList *ctx_stack, const gchar *path) { res = config_parser_buffer(srv, ctx_stack); if (!res) - log_warning(srv, NULL, "config parsing failed in line %zd of %s", ctx->line, ctx->filename); + WARNING(srv, "config parsing failed in line %zd of %s", ctx->line, ctx->filename); /* pop from stack */ ctx_stack = g_list_delete_link(ctx_stack, ctx_stack); @@ -1161,7 +1161,7 @@ gboolean config_parser_shell(server *srv, GList *ctx_stack, const gchar *command if (!g_spawn_command_line_sync(command, &_stdout, &_stderr, &status, &err)) { - log_warning(srv, NULL, "error launching shell command \"%s\": %s (%d)", command, err->message, err->code); + WARNING(srv, "error launching shell command \"%s\": %s (%d)", command, err->message, err->code); config_parser_context_free(srv, ctx, FALSE); g_error_free(err); return FALSE; @@ -1169,8 +1169,8 @@ gboolean config_parser_shell(server *srv, GList *ctx_stack, const gchar *command if (status != 0) { - log_warning(srv, NULL, "shell command \"%s\" exited with status %d", command, status); - log_debug(srv, NULL, "stdout:\n-----\n%s\n-----\nstderr:\n-----\n%s\n-----", _stdout, _stderr); + WARNING(srv, "shell command \"%s\" exited with status %d", command, status); + DEBUG(srv, "stdout:\n-----\n%s\n-----\nstderr:\n-----\n%s\n-----", _stdout, _stderr); g_free(_stdout); g_free(_stderr); config_parser_context_free(srv, ctx, FALSE); @@ -1180,7 +1180,7 @@ gboolean config_parser_shell(server *srv, GList *ctx_stack, const gchar *command ctx->len = strlen(_stdout); ctx->ptr = _stdout; - log_debug(srv, NULL, "included shell output from \"%s\" (%zu bytes)", command, ctx->len); + DEBUG(srv, "included shell output from \"%s\" (%zu bytes)", command, ctx->len); /* push on stack */ ctx_stack = g_list_prepend(ctx_stack, ctx); @@ -1213,7 +1213,7 @@ gboolean config_parser_buffer(server *srv, GList *ctx_stack) if (ctx->cs == config_parser_error || ctx->cs == config_parser_first_final) { /* parse error */ - log_warning(srv, NULL, "parse error in line %zd of \"%s\" at character '%c' (0x%.2x)", ctx->line, ctx->filename, *ctx->p, *ctx->p); + WARNING(srv, "parse error in line %zd of \"%s\" at character '%c' (0x%.2x)", ctx->line, ctx->filename, *ctx->p, *ctx->p); return FALSE; } diff --git a/src/connection.c b/src/connection.c index d59da38..3064a69 100644 --- a/src/connection.c +++ b/src/connection.c @@ -31,7 +31,7 @@ static void forward_response_body(connection *con) { if (!con->response_headers_sent) { con->response_headers_sent = TRUE; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "write response headers"); + VR_DEBUG(vr, "%s", "write response headers"); } response_send_headers(con); } @@ -51,7 +51,7 @@ static void forward_response_body(connection *con) { static void connection_request_done(connection *con) { vrequest *vr = con->mainvr; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "response end (keep_alive = %i)", con->keep_alive); + VR_DEBUG(con->mainvr, "response end (keep_alive = %i)", con->keep_alive); } plugins_handle_close(con); @@ -74,7 +74,7 @@ static gboolean check_response_done(connection *con) { static void connection_close(connection *con) { vrequest *vr = con->mainvr; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "connection closed"); + VR_DEBUG(vr, "%s", "connection closed"); } plugins_handle_close(con); @@ -85,7 +85,7 @@ static void connection_close(connection *con) { void connection_error(connection *con) { vrequest *vr = con->mainvr; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "connection closed (error)"); + VR_DEBUG(vr, "%s", "connection closed (error)"); } plugins_handle_close(con); @@ -137,7 +137,7 @@ static gboolean connection_handle_read(connection *con) { if (con->state == CON_STATE_READ_REQUEST_HEADER && con->mainvr->state == VRS_CLEAN) { if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "reading request header"); + VR_DEBUG(vr, "%s", "reading request header"); } switch(http_request_parse(con->mainvr, &con->req_parser_ctx)) { case HANDLER_FINISHED: @@ -157,7 +157,7 @@ static gboolean connection_handle_read(connection *con) { /* headers ready */ if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "validating request header"); + VR_DEBUG(vr, "%s", "validating request header"); } if (!request_validate_header(con)) { /* skip mainvr handling */ @@ -188,7 +188,7 @@ static void connection_cb(struct ev_loop *loop, ev_io *w, int revents) { if (!connection_handle_read(con)) return; break; case NETWORK_STATUS_FATAL_ERROR: - CON_ERROR(con, "%s", "network read fatal error"); + _ERROR(con->srv, con->mainvr, "%s", "network read fatal error"); connection_error(con); return; case NETWORK_STATUS_CONNECTION_CLOSE: @@ -217,7 +217,7 @@ static void connection_cb(struct ev_loop *loop, ev_io *w, int revents) { vrequest_joblist_append(con->mainvr); break; case NETWORK_STATUS_FATAL_ERROR: - CON_ERROR(con, "%s", "network write fatal error"); + _ERROR(con->srv, con->mainvr, "%s", "network write fatal error"); connection_error(con); break; case NETWORK_STATUS_CONNECTION_CLOSE: @@ -227,17 +227,17 @@ static void connection_cb(struct ev_loop *loop, ev_io *w, int revents) { break; case NETWORK_STATUS_WAIT_FOR_AIO_EVENT: ev_io_rem_events(loop, w, EV_WRITE); - CON_ERROR(con, "%s", "TODO: wait for aio"); + _ERROR(con->srv, con->mainvr, "%s", "TODO: wait for aio"); /* TODO: aio */ break; case NETWORK_STATUS_WAIT_FOR_FD: ev_io_rem_events(loop, w, EV_WRITE); - CON_ERROR(con, "%s", "TODO: wait for fd"); + _ERROR(con->srv, con->mainvr, "%s", "TODO: wait for fd"); /* TODO: wait for fd */ break; } } else { - CON_TRACE(con, "%s", "write event for empty queue"); + _DEBUG(con->srv, con->mainvr, "%s", "write event for empty queue"); ev_io_rem_events(loop, w, EV_WRITE); } } @@ -254,11 +254,11 @@ static void connection_keepalive_cb(struct ev_loop *loop, ev_timer *w, int reven static handler_t mainvr_handle_response_headers(vrequest *vr) { connection *con = vr->con; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - VR_TRACE(vr, "%s", "read request/handle response header"); + VR_DEBUG(vr, "%s", "read request/handle response header"); } if (con->expect_100_cont) { if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - VR_TRACE(vr, "%s", "send 100 Continue"); + VR_DEBUG(vr, "%s", "send 100 Continue"); } chunkqueue_append_mem(con->raw_out, CONST_STR_LEN("HTTP/1.1 100 Continue\r\n\r\n")); con->expect_100_cont = FALSE; @@ -274,7 +274,7 @@ static handler_t mainvr_handle_response_body(vrequest *vr) { if (check_response_done(con)) return HANDLER_FINISHED; if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - CON_TRACE(con, "%s", "write response"); + VR_DEBUG(vr, "%s", "write response"); } parse_request_body(con); diff --git a/src/lighttpd.c b/src/lighttpd.c index c3a6d3b..fdc4b36 100644 --- a/src/lighttpd.c +++ b/src/lighttpd.c @@ -82,7 +82,7 @@ int main(int argc, char *argv[]) { free_config_path = FALSE; } - log_debug(srv, NULL, "config path: %s", config_path); + DEBUG(srv, "config path: %s", config_path); if (!luaconfig) { GTimeVal start, end; @@ -116,8 +116,8 @@ int main(int argc, char *argv[]) { s = d / 1000000; millis = (d - s) / 1000; micros = (d - s - millis) %1000; - log_debug(srv, NULL, "parsed config file in %lu seconds, %lu milliseconds, %lu microseconds", s, millis, micros); - log_debug(srv, NULL, "option_stack: %u action_list_stack: %u (should be 0:1)", g_queue_get_length(ctx->option_stack), g_queue_get_length(ctx->action_list_stack)); + DEBUG(srv, "parsed config file in %lu seconds, %lu milliseconds, %lu microseconds", s, millis, micros); + DEBUG(srv, "option_stack: %u action_list_stack: %u (should be 0:1)", g_queue_get_length(ctx->option_stack), g_queue_get_length(ctx->action_list_stack)); config_parser_finish(srv, ctx_stack, FALSE); } diff --git a/src/log.c b/src/log.c index 6386849..d7090d4 100644 --- a/src/log.c +++ b/src/log.c @@ -34,17 +34,16 @@ void log_write(server *srv, log_t *log, GString *msg) { g_async_queue_push(srv->logs.queue, log_entry); } -gboolean log_write_(server *srv, connection *con, log_level_t log_level, guint flags, const gchar *fmt, ...) { +gboolean log_write_(server *srv, vrequest *vr, log_level_t log_level, guint flags, const gchar *fmt, ...) { va_list ap; GString *log_line; log_t *log = NULL; log_entry_t *log_entry; log_timestamp_t *ts = NULL; - vrequest *vr = con ? con->mainvr : NULL; - if (con != NULL) { + if (vr != NULL) { - if (!srv) srv = con->srv; + if (!srv) srv = vr->con->srv; /* get log from connection */ log = g_array_index(CORE_OPTION(CORE_OPTION_LOG).list, log_t*, log_level); if (log == NULL) @@ -82,7 +81,7 @@ gboolean log_write_(server *srv, connection *con, log_level_t log_level, guint f if (log->lastmsg_count > 0) { guint count = log->lastmsg_count; log->lastmsg_count = 0; - log_write_(srv, con, log_level, flags | LOG_FLAG_NOLOCK | LOG_FLAG_ALLOW_REPEAT, "last message repeated %d times", count); + log_write_(srv, vr, log_level, flags | LOG_FLAG_NOLOCK | LOG_FLAG_ALLOW_REPEAT, "last message repeated %d times", count); } } } @@ -96,8 +95,8 @@ gboolean log_write_(server *srv, connection *con, log_level_t log_level, guint f g_mutex_lock(srv->logs.mutex); /* if we have a worker context, we can use its timestamp to save us a call to time() */ - if (con != NULL) - cur_ts = (time_t)CUR_TS(con->wrk); + if (vr != NULL) + cur_ts = (time_t)CUR_TS(vr->con->wrk); else cur_ts = time(NULL); diff --git a/src/modules/mod_fortune.c b/src/modules/mod_fortune.c index 777e44f..a6e0937 100644 --- a/src/modules/mod_fortune.c +++ b/src/modules/mod_fortune.c @@ -127,7 +127,7 @@ static gboolean fortune_load(server *srv, plugin* p, value *val) { g_free(data); - TRACE(srv, "loaded %u cookies from file '%s'", count, file); + DEBUG(srv, "loaded %u cookies from file '%s'", count, file); return TRUE; } diff --git a/src/modules/mod_status.c b/src/modules/mod_status.c index 04e9a9f..fef3371 100644 --- a/src/modules/mod_status.c +++ b/src/modules/mod_status.c @@ -199,7 +199,7 @@ static void status_collect_cb(gpointer cbdata, gpointer fdata, GPtrArray *result GString *tmpstr; guint total_connections = 0; - VR_TRACE(vr, "finished collecting data: %s", complete ? "complete" : "not complete"); + VR_DEBUG(vr, "finished collecting data: %s", complete ? "complete" : "not complete"); vr->response.http_status = 200; /* we got everything */ @@ -446,7 +446,7 @@ static void status_collect_cb(gpointer cbdata, gpointer fdata, GPtrArray *result vrequest_joblist_append(vr); } else { /* something went wrong, client may have dropped the connection */ - CON_ERROR(vr->con, "%s", "collect request didn't end up complete"); + VR_ERROR(vr, "%s", "collect request didn't end up complete"); vrequest_error(vr); } } @@ -456,7 +456,7 @@ static handler_t status_page_handle(vrequest *vr, gpointer param, gpointer *cont if (vr->state == VRS_HANDLE_REQUEST_HEADERS) { collect_info *ci; - VR_TRACE(vr, "%s", "collecting stats..."); + VR_DEBUG(vr, "%s", "collecting stats..."); /* abuse fdata as pointer to plugin */ ci = collect_start(vr->con->wrk, status_collect_func, param, NULL, status_collect_cb, vr); *context = ci; diff --git a/src/plugin_core.c b/src/plugin_core.c index 06ef181..6b5266a 100644 --- a/src/plugin_core.c +++ b/src/plugin_core.c @@ -149,7 +149,7 @@ static handler_t core_handle_static(vrequest *vr, gpointer param, gpointer *cont g_string_append_len(vr->physical.path, GSTR_LEN(CORE_OPTION(CORE_OPTION_DOCROOT).string)); g_string_append_len(vr->physical.path, GSTR_LEN(vr->request.uri.path)); - VR_TRACE(vr, "physical path: %s", vr->physical.path->str); + VR_DEBUG(vr, "physical path: %s", vr->physical.path->str); if (vr->physical.path->len == 0) return HANDLER_GO_ON; @@ -158,7 +158,7 @@ static handler_t core_handle_static(vrequest *vr, gpointer param, gpointer *cont fd = open(vr->physical.path->str, O_RDONLY); if (fd == -1) { vr->response.http_status = 404; - VR_TRACE(vr, "open() failed: %s (%d)", g_strerror(errno), errno); + VR_DEBUG(vr, "open() failed: %s (%d)", g_strerror(errno), errno); switch (errno) { case ENOENT: @@ -388,7 +388,7 @@ static gboolean core_event_handler(server *srv, plugin* p, value *val) { } if (!(ev_recommended_backends() & backend)) { - TRACE(srv, "warning: event handler '%s' not recommended for this platform!", str); + DEBUG(srv, "warning: event handler '%s' not recommended for this platform!", str); } } @@ -453,7 +453,7 @@ static gboolean core_module_load(server *srv, plugin* p, value *val) { return FALSE; } - TRACE(srv, "loaded module '%s'", name->str); + DEBUG(srv, "loaded module '%s'", name->str); } value_free(mods); diff --git a/src/request.c b/src/request.c index f3c9513..5e152b7 100644 --- a/src/request.c +++ b/src/request.c @@ -141,7 +141,7 @@ gboolean request_validate_header(connection *con) { r = str_to_off_t(val, &err, 10); if (*err != '\0') { - CON_TRACE(con, "content-length is not a number: %s (Status: 400)", err); + _DEBUG(con->srv, con->mainvr, "content-length is not a number: %s (Status: 400)", err); bad_request(con, 400); /* bad request */ return FALSE; } diff --git a/src/virtualrequest.c b/src/virtualrequest.c index fc7d9d0..3fe9a92 100644 --- a/src/virtualrequest.c +++ b/src/virtualrequest.c @@ -244,7 +244,7 @@ void vrequest_state_machine(vrequest *vr) { case VRS_HANDLE_REQUEST_HEADERS: if (CORE_OPTION(CORE_OPTION_DEBUG_REQUEST_HANDLING).boolean) { - VR_TRACE(vr, "%s", "handle request header"); + VR_DEBUG(vr, "%s", "handle request header"); } if (!vrequest_do_handle_actions(vr)) return; res = vr->handle_request_headers(vr); diff --git a/src/worker.c b/src/worker.c index 0304c03..3bd6a72 100644 --- a/src/worker.c +++ b/src/worker.c @@ -110,7 +110,7 @@ static void worker_io_timeout_cb(struct ev_loop *loop, ev_timer *w, int revents) while ((wqe = waitqueue_pop(&wrk->io_timeout_queue)) != NULL) { /* connection has timed out */ con = wqe->data; - CON_TRACE(con, "connection io-timeout from %s after %.2f seconds", con->remote_addr_str->str, now - wqe->ts); + _DEBUG(con->srv, con->mainvr, "connection io-timeout from %s after %.2f seconds", con->remote_addr_str->str, now - wqe->ts); plugins_handle_close(con); worker_con_put(con); } @@ -218,7 +218,7 @@ static void worker_stats_watcher_cb(struct ev_loop *loop, ev_timer *w, int reven wrk->stats.requests_per_sec = (wrk->stats.requests - wrk->stats.last_requests) / (now - wrk->stats.last_update); if (wrk->stats.requests_per_sec > 0) - TRACE(wrk->srv, "worker %u: %.2f requests per second", wrk->ndx, wrk->stats.requests_per_sec); + DEBUG(wrk->srv, "worker %u: %.2f requests per second", wrk->ndx, wrk->stats.requests_per_sec); } /* 5s averages */