Browse Source

[log] remove different timestamp format handling (one is enough), separate log context (liLogMap) from virtualrequest

personal/stbuehler/wip
Stefan Bühler 10 years ago
parent
commit
77f786ed18
  1. 2
      include/lighttpd/base.h
  2. 145
      include/lighttpd/log.h
  3. 3
      include/lighttpd/plugin_core.h
  4. 14
      include/lighttpd/server.h
  5. 6
      include/lighttpd/typedefs.h
  6. 2
      include/lighttpd/worker.h
  7. 4
      src/main/connection.c
  8. 4
      src/main/core_lua.c
  9. 182
      src/main/log.c
  10. 62
      src/main/plugin_core.c
  11. 2
      src/main/request.c
  12. 4
      src/main/worker.c
  13. 2
      src/modules/mod_accesslog.c
  14. 2
      src/modules/mod_fastcgi.c

2
include/lighttpd/base.h

@ -39,6 +39,7 @@
#include <lighttpd/waitqueue.h>
#include <lighttpd/radix.h>
#include <lighttpd/log.h>
#include <lighttpd/server.h>
#include <lighttpd/worker.h>
#include <lighttpd/angel.h>
@ -56,7 +57,6 @@
#include <lighttpd/environment.h>
#include <lighttpd/filter_buffer_on_disk.h>
#include <lighttpd/virtualrequest.h>
#include <lighttpd/log.h>
#include <lighttpd/stat_cache.h>
#include <lighttpd/throttle.h>
#include <lighttpd/mimetype.h>

145
include/lighttpd/log.h

@ -18,78 +18,110 @@
/* #include <lighttpd/valgrind/valgrind.h> */
#define _SEGFAULT(srv, vr, fmt, ...) \
/* at least one of srv and wrk must not be NULL. log_map may be NULL. */
#define _SEGFAULT(srv, wrk, log_map, fmt, ...) \
do { \
li_log_write(srv, NULL, LI_LOG_LEVEL_ABORT, LOG_FLAG_TIMESTAMP, "(crashing) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__); \
li_log_write(srv, NULL, NULL, LI_LOG_LEVEL_ABORT, LOG_FLAG_TIMESTAMP, "(crashing) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__); \
/* VALGRIND_PRINTF_BACKTRACE(fmt, __VA_ARGS__); */\
abort();\
} while(0)
#define _ERROR(srv, vr, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_ERROR, LOG_FLAG_TIMESTAMP, "(error) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _WARNING(srv, vr, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_WARNING, LOG_FLAG_TIMESTAMP, "(warning) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _INFO(srv, vr, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_INFO, LOG_FLAG_TIMESTAMP, "(info) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _DEBUG(srv, vr, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_DEBUG, LOG_FLAG_TIMESTAMP, "(debug) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _BACKEND(srv, vr, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_BACKEND, LOG_FLAG_TIMESTAMP, fmt, __VA_ARGS__)
#define _BACKEND_LINES(srv, vr, txt, fmt, ...) \
li_log_split_lines_(srv, vr, LI_LOG_LEVEL_BACKEND, LOG_FLAG_TIMESTAMP, txt, fmt, __VA_ARGS__)
#define _GERROR(srv, vr, error, fmt, ...) \
li_log_write(srv, vr, LI_LOG_LEVEL_ERROR, LOG_FLAG_TIMESTAMP, "(error) %s.%d: " fmt "\n %s", LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__, error ? error->message : "Empty GError")
#define VR_SEGFAULT(vr, fmt, ...) _SEGFAULT(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_ERROR(vr, fmt, ...) _ERROR(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_WARNING(vr, fmt, ...) _WARNING(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_INFO(vr, fmt, ...) _INFO(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_DEBUG(vr, fmt, ...) _DEBUG(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_BACKEND(vr, fmt, ...) _BACKEND(vr->wrk->srv, vr, fmt, __VA_ARGS__)
#define VR_BACKEND_LINES(vr, txt, fmt, ...) _BACKEND_LINES(vr->wrk->srv, vr, txt, fmt, __VA_ARGS__)
#define VR_GERROR(vr, error, fmt, ...) _GERROR(vr->wrk->srv, vr, error, fmt, __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__)
#define BACKEND(srv, fmt, ...) _BACKEND(srv, NULL, fmt, __VA_ARGS__)
#define GERROR(srv, error, fmt, ...) _GERROR(srv, NULL, error, fmt, __VA_ARGS__)
#define _ERROR(srv, wrk, log_map, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_ERROR, LOG_FLAG_TIMESTAMP, "(error) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _WARNING(srv, wrk, log_map, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_WARNING, LOG_FLAG_TIMESTAMP, "(warning) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _INFO(srv, wrk, log_map, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_INFO, LOG_FLAG_TIMESTAMP, "(info) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _DEBUG(srv, wrk, log_map, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_DEBUG, LOG_FLAG_TIMESTAMP, "(debug) %s.%d: "fmt, LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__)
#define _BACKEND(srv, wrk, log_map, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_BACKEND, LOG_FLAG_TIMESTAMP, fmt, __VA_ARGS__)
#define _BACKEND_LINES(srv, wrk, log_map, txt, fmt, ...) \
li_log_split_lines_(srv, wrk, log_map, LI_LOG_LEVEL_BACKEND, LOG_FLAG_TIMESTAMP, txt, fmt, __VA_ARGS__)
#define _GERROR(srv, wrk, log_map, error, fmt, ...) \
li_log_write(srv, wrk, log_map, LI_LOG_LEVEL_ERROR, LOG_FLAG_TIMESTAMP, "(error) %s.%d: " fmt "\n %s", LI_REMOVE_PATH(__FILE__), __LINE__, __VA_ARGS__, error ? error->message : "Empty GError")
#define VR_SEGFAULT(vr, fmt, ...) _SEGFAULT(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_ERROR(vr, fmt, ...) _ERROR(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_WARNING(vr, fmt, ...) _WARNING(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_INFO(vr, fmt, ...) _INFO(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_DEBUG(vr, fmt, ...) _DEBUG(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_BACKEND(vr, fmt, ...) _BACKEND(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define VR_BACKEND_LINES(vr, txt, fmt, ...) _BACKEND_LINES(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), txt, fmt, __VA_ARGS__)
#define VR_GERROR(vr, error, fmt, ...) _GERROR(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), error, fmt, __VA_ARGS__)
/* vr may be NULL; if vr is NULL, srv must NOT be NULL */
#define _VR_SEGFAULT(srv, vr, fmt, ...) _SEGFAULT(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_ERROR(srv, vr, fmt, ...) _ERROR(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_WARNING(srv, vr, fmt, ...) _WARNING(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_INFO(srv, vr, fmt, ...) _INFO(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_DEBUG(srv, vr, fmt, ...) _DEBUG(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_BACKEND(srv, vr, fmt, ...) _BACKEND(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), fmt, __VA_ARGS__)
#define _VR_BACKEND_LINES(srv, vr, txt, fmt, ...) _BACKEND_LINES(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), txt, fmt, __VA_ARGS__)
#define _VR_GERROR(srv, vr, error, fmt, ...) _GERROR(srv, NULL != vr ? vr->wrk : NULL, li_log_vr_map(vr), error, fmt, __VA_ARGS__)
#define SEGFAULT(srv, fmt, ...) _SEGFAULT(srv, NULL, NULL, fmt, __VA_ARGS__)
#define ERROR(srv, fmt, ...) _ERROR(srv, NULL, NULL, fmt, __VA_ARGS__)
#define WARNING(srv, fmt, ...) _WARNING(srv, NULL, NULL, fmt, __VA_ARGS__)
#define INFO(srv, fmt, ...) _INFO(srv, NULL, NULL, fmt, __VA_ARGS__)
#define DEBUG(srv, fmt, ...) _DEBUG(srv, NULL, NULL, fmt, __VA_ARGS__)
#define BACKEND(srv, fmt, ...) _BACKEND(srv, NULL, NULL, fmt, __VA_ARGS__)
#define GERROR(srv, error, fmt, ...) _GERROR(srv, NULL, NULL, error, fmt, __VA_ARGS__)
/* flags for li_log_write */
#define LOG_FLAG_NONE (0x0) /* default flag */
#define LOG_FLAG_TIMESTAMP (0x1) /* prepend a timestamp to the log message */
#define LOG_FLAG_NOLOCK (0x1 << 1) /* for internal use only */
struct liLog {
struct liLogTarget {
liLogType type;
GString *path;
gint fd;
liWaitQueueElem wqelem;
};
struct liLogTimestamp {
gint refcount;
ev_tstamp last_ts;
GString *format;
GString *cached;
};
struct liLogEntry {
GString *path;
liLogTimestamp *ts;
liLogLevel level;
guint flags;
GString *msg;
GList queue_link;
};
struct liLogServerData {
struct ev_loop *loop;
ev_async watcher;
liRadixTree *targets; /** const gchar* path => (liLog*) */
liWaitQueue close_queue;
GQueue write_queue;
GStaticMutex write_queue_mutex;
GThread *thread;
gboolean thread_alive;
gboolean thread_finish;
gboolean thread_stop;
/* timestamp format cache */
struct {
ev_tstamp last_ts;
GString *format;
GString *cached;
} timestamp;
};
struct liLogWorkerData {
GQueue log_queue;
};
struct liLogMap {
int refcount;
GArray *arr;
};
/* determines the type of a log target by the path given. /absolute/path = file; |app = pipe; stderr = stderr; syslog = syslog;
* returns the begin of the parameter string in *param if param != NULL (filename for /absolute/path or file:///absolute/path)
* *param is either NULL or points into the path string!
@ -100,7 +132,7 @@ LI_API liLogLevel li_log_level_from_string(GString *str);
LI_API gchar* li_log_level_str(liLogLevel log_level);
/* log_new is used to create a new log target, if a log with the same path already exists, it is referenced instead */
LI_API liLog *li_log_new(liServer *srv, liLogType type, GString *path);
LI_API liLogTarget *li_log_new(liServer *srv, liLogType type, GString *path);
LI_API void li_log_thread_start(liServer *srv);
LI_API void li_log_thread_wakeup(liServer *srv);
@ -110,16 +142,19 @@ LI_API void li_log_thread_finish(liServer *srv);
LI_API void li_log_init(liServer *srv);
LI_API void li_log_cleanup(liServer *srv);
LI_API gboolean li_log_write_direct(liServer *srv, liVRequest *vr, GString *path, GString *msg);
/* li_log_write is used to write to the errorlog */
LI_API gboolean li_log_write(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, const gchar *fmt, ...) G_GNUC_PRINTF(5, 6);
LI_API liLogMap* li_log_map_new(void);
LI_API void li_log_map_acquire(liLogMap *log_map);
LI_API void li_log_map_release(liLogMap *log_map);
LI_API liLogTimestamp *li_log_timestamp_new(liServer *srv, GString *format);
LI_API gboolean li_log_timestamp_free(liServer *srv, liLogTimestamp *ts);
LI_API liLogMap* li_log_vr_map(liVRequest *vr);
LI_API gboolean li_log_write_direct(liServer *srv, liWorker *wrk, GString *path, GString *msg);
/* li_log_write is used to write to the errorlog */
LI_API gboolean li_log_write(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, const gchar *fmt, ...) G_GNUC_PRINTF(6, 7);
/* replaces '\r' and '\n' with '\0' */
LI_API void li_log_split_lines(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, gchar *txt, const gchar *prefix);
LI_API void li_log_split_lines_(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, gchar *txt, const gchar *fmt, ...) G_GNUC_PRINTF(6, 7);
LI_API void li_log_split_lines(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, gchar *txt, const gchar *prefix);
LI_API void li_log_split_lines_(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, gchar *txt, const gchar *fmt, ...) G_GNUC_PRINTF(7, 8);
#endif

3
include/lighttpd/plugin_core.h

@ -19,8 +19,7 @@ enum liCoreOptions {
};
enum liCoreOptionPtrs {
LI_CORE_OPTION_LOG_TS_FORMAT = 0,
LI_CORE_OPTION_LOG,
LI_CORE_OPTION_LOG = 0,
LI_CORE_OPTION_STATIC_FILE_EXCLUDE_EXTENSIONS,

14
include/lighttpd/server.h

@ -109,19 +109,7 @@ struct liServer {
gboolean exiting; /** atomic access */
struct {
struct ev_loop *loop;
ev_async watcher;
liRadixTree *targets; /** const gchar* path => (liLog*) */
liWaitQueue close_queue;
GQueue write_queue;
GStaticMutex write_queue_mutex;
GThread *thread;
gboolean thread_alive;
gboolean thread_finish;
gboolean thread_stop;
GArray *timestamps;
} logs;
liLogServerData logs;
ev_tstamp started;
GString *started_str;

6
include/lighttpd/typedefs.h

@ -92,9 +92,11 @@ typedef struct liHttpResponseCtx liHttpResponseCtx;
/* log.h */
typedef struct liLog liLog;
typedef struct liLogTarget liLogTarget;
typedef struct liLogEntry liLogEntry;
typedef struct liLogTimestamp liLogTimestamp;
typedef struct liLogServerData liLogServerData;
typedef struct liLogWorkerData liLogWorkerData;
typedef struct liLogMap liLogMap;
typedef enum {
LI_LOG_LEVEL_DEBUG,

2
include/lighttpd/worker.h

@ -71,7 +71,7 @@ struct liWorker {
/* ev_check loop_check; */
ev_async worker_stop_watcher, worker_stopping_watcher, worker_suspend_watcher, worker_exit_watcher;
GQueue log_queue;
liLogWorkerData logs;
guint connections_active; /** 0..con_act-1: active connections, con_act..used-1: free connections
* use with atomic, read direct from local worker context

4
src/main/connection.c

@ -324,7 +324,7 @@ static G_GNUC_WARN_UNUSED_RESULT gboolean connection_try_read(liConnection *con)
if (!connection_handle_read(con)) return FALSE;
break;
case LI_NETWORK_STATUS_FATAL_ERROR:
_ERROR(con->srv, con->mainvr, "%s", "network read fatal error");
_VR_ERROR(con->srv, con->mainvr, "%s", "network read fatal error");
li_connection_error(con);
return FALSE;
case LI_NETWORK_STATUS_CONNECTION_CLOSE:
@ -381,7 +381,7 @@ static G_GNUC_WARN_UNUSED_RESULT gboolean connection_try_write(liConnection *con
case LI_NETWORK_STATUS_SUCCESS:
break;
case LI_NETWORK_STATUS_FATAL_ERROR:
_ERROR(con->srv, con->mainvr, "%s", "network write fatal error");
_VR_ERROR(con->srv, con->mainvr, "%s", "network write fatal error");
li_connection_error(con);
return FALSE;
case LI_NETWORK_STATUS_CONNECTION_CLOSE:

4
src/main/core_lua.c

@ -48,7 +48,7 @@ gboolean li_lua_call_object(liServer *srv, liVRequest *vr, lua_State *L, const c
if (!lua_isfunction(L, -1)) {
if (!optional) {
_ERROR(srv, vr, "li_lua_call_object: method '%s' not found", method);
_VR_ERROR(srv, vr, "li_lua_call_object: method '%s' not found", method);
}
lua_pop(L, 1 + nargs);
return FALSE;
@ -58,7 +58,7 @@ gboolean li_lua_call_object(liServer *srv, liVRequest *vr, lua_State *L, const c
errfunc = li_lua_push_traceback(L, nargs); /* +1 "errfunc" */
if (lua_pcall(L, nargs, nresults, errfunc)) { /* pops func and arguments, push result */
_ERROR(srv, vr, "lua_pcall(): %s", lua_tostring(L, -1));
_VR_ERROR(srv, vr, "lua_pcall(): %s", lua_tostring(L, -1));
lua_pop(L, 1); /* -1 */
result = FALSE;
} else {

182
src/main/log.c

@ -38,8 +38,8 @@ static void li_log_write_stderr(liServer *srv, const gchar *msg, gboolean newlin
g_static_mutex_unlock(&mtx);
}
static liLog *log_open(liServer *srv, GString *path) {
liLog *log;
static liLogTarget *log_open(liServer *srv, GString *path) {
liLogTarget *log;
log = li_radixtree_lookup_exact(srv->logs.targets, path->str, path->len * 8);
@ -69,7 +69,7 @@ static liLog *log_open(liServer *srv, GString *path) {
}
/* Even if -1 == fd we create an entry, so we don't throw an error every time */
log = g_slice_new0(liLog);
log = g_slice_new0(liLogTarget);
log->type = type;
log->path = g_string_new_len(GSTR_LEN(path));
log->fd = fd;
@ -83,7 +83,7 @@ static liLog *log_open(liServer *srv, GString *path) {
return log;
}
static void log_close(liServer *srv, liLog *log) {
static void log_close(liServer *srv, liLogTarget *log) {
li_radixtree_remove(srv->logs.targets, log->path->str, log->path->len * 8);
li_waitqueue_remove(&srv->logs.close_queue, &log->wqelem);
@ -94,7 +94,7 @@ static void log_close(liServer *srv, liLog *log) {
/*g_print("log_close(\"%s\")\n", log->path->str);*/
g_string_free(log->path, TRUE);
g_slice_free(liLog, log);
g_slice_free(liLogTarget, log);
}
static void log_close_cb(liWaitQueue *wq, gpointer data) {
@ -115,13 +115,12 @@ void li_log_init(liServer *srv) {
srv->logs.watcher.data = srv;
srv->logs.targets = li_radixtree_new();
li_waitqueue_init(&srv->logs.close_queue, srv->logs.loop, log_close_cb, LOG_DEFAULT_TTL, srv);
srv->logs.timestamps = g_array_new(FALSE, FALSE, sizeof(liLogTimestamp*));
srv->logs.timestamp.format = g_string_new_len(CONST_STR_LEN(LOG_DEFAULT_TS_FORMAT));
srv->logs.timestamp.cached = g_string_sized_new(255);
srv->logs.timestamp.last_ts = 0;
srv->logs.thread_alive = FALSE;
g_queue_init(&srv->logs.write_queue);
g_static_mutex_init(&srv->logs.write_queue_mutex);
/* first entry in srv->logs.timestamps is the default timestamp */
li_log_timestamp_new(srv, g_string_new_len(CONST_STR_LEN(LOG_DEFAULT_TS_FORMAT)));
}
void li_log_cleanup(liServer *srv) {
@ -134,20 +133,51 @@ void li_log_cleanup(liServer *srv) {
li_radixtree_free(srv->logs.targets, NULL, NULL);
/* we allocated the first entry, lets release only that one */
li_log_timestamp_free(srv, g_array_index(srv->logs.timestamps, liLogTimestamp*, 0));
g_string_free(srv->logs.timestamp.format, TRUE);
g_string_free(srv->logs.timestamp.cached, TRUE);
g_array_free(srv->logs.timestamps, TRUE);
ev_loop_destroy(srv->logs.loop);
}
gboolean li_log_write_direct(liServer *srv, liVRequest *vr, GString *path, GString *msg) {
LI_API liLogMap* li_log_map_new(void) {
liLogMap *log_map = g_slice_new0(liLogMap);
log_map->refcount = 1;
log_map->arr = g_array_sized_new(FALSE, TRUE, sizeof(GString*), 6);
g_array_set_size(log_map->arr, 6);
return log_map;
}
LI_API void li_log_map_acquire(liLogMap *log_map) {
assert(g_atomic_int_get(&log_map->refcount) > 0);
g_atomic_int_inc(&log_map->refcount);
}
LI_API void li_log_map_release(liLogMap *log_map) {
if (!log_map) return;
assert(g_atomic_int_get(&log_map->refcount) > 0);
if (g_atomic_int_dec_and_test(&log_map->refcount)) {
for (guint i = 0; i < log_map->arr->len; i++) {
if (NULL != g_array_index(log_map->arr, GString*, i))
g_string_free(g_array_index(log_map->arr, GString*, i), TRUE);
}
g_array_free(log_map->arr, TRUE);
g_slice_free(liLogMap, log_map);
}
}
liLogMap* li_log_vr_map(liVRequest *vr) {
return (NULL != vr) ? CORE_OPTIONPTR(LI_CORE_OPTION_LOG).ptr : NULL;
}
gboolean li_log_write_direct(liServer *srv, liWorker *wrk, GString *path, GString *msg) {
liLogEntry *log_entry;
liWorker *wrk;
log_entry = g_slice_new(liLogEntry);
log_entry->path = g_string_new_len(GSTR_LEN(path));
log_entry->ts = NULL;
log_entry->level = 0;
log_entry->flags = 0;
log_entry->msg = msg;
@ -155,10 +185,9 @@ gboolean li_log_write_direct(liServer *srv, liVRequest *vr, GString *path, GStri
log_entry->queue_link.next = NULL;
log_entry->queue_link.prev = NULL;
if (G_LIKELY(vr)) {
if (G_LIKELY(wrk)) {
/* push onto local worker log queue */
wrk = vr->wrk;
g_queue_push_tail_link(&wrk->log_queue, &log_entry->queue_link);
g_queue_push_tail_link(&wrk->logs.log_queue, &log_entry->queue_link);
} else {
/* no worker context, push directly onto global log queue */
g_static_mutex_lock(&srv->logs.write_queue_mutex);
@ -170,42 +199,27 @@ gboolean li_log_write_direct(liServer *srv, liVRequest *vr, GString *path, GStri
return TRUE;
}
gboolean li_log_write(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, const gchar *fmt, ...) {
liWorker *wrk;
gboolean li_log_write(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, const gchar *fmt, ...) {
va_list ap;
GString *log_line;
liLogEntry *log_entry;
liLogTimestamp *ts = NULL;
GArray *logs = NULL;
GString *path;
if (vr != NULL) {
wrk = vr->wrk;
if (!srv) srv = wrk->srv;
/* get log from connection */
logs = CORE_OPTIONPTR(LI_CORE_OPTION_LOG).list;
ts = CORE_OPTIONPTR(LI_CORE_OPTION_LOG_TS_FORMAT).ptr;
} else {
liOptionPtrValue *ologval = NULL;
wrk = NULL;
if (!srv) srv = wrk->srv;
if (NULL == log_map) {
if (0 + LI_CORE_OPTION_LOG < srv->optionptr_def_values->len) {
ologval = g_array_index(srv->optionptr_def_values, liOptionPtrValue*, 0 + LI_CORE_OPTION_LOG);
liOptionPtrValue *oval = g_array_index(srv->optionptr_def_values, liOptionPtrValue*, 0 + LI_CORE_OPTION_LOG);
if (NULL != oval) log_map = oval->data.ptr;
}
if (ologval != NULL)
logs = ologval->data.list;
}
if (logs != NULL && log_level < logs->len) {
path = g_array_index(logs, GString*, log_level);
if (log_map != NULL && log_level < log_map->arr->len) {
path = g_array_index(log_map->arr, GString*, log_level);
} else {
return FALSE;
}
if (NULL == ts && srv->logs.timestamps->len > 0) {
ts = g_array_index(srv->logs.timestamps, liLogTimestamp*, 0);
}
log_line = g_string_sized_new(63);
va_start(ap, fmt);
g_string_vprintf(log_line, fmt, ap);
@ -233,7 +247,6 @@ gboolean li_log_write(liServer *srv, liVRequest *vr, liLogLevel log_level, guint
log_entry = g_slice_new(liLogEntry);
log_entry->path = g_string_new_len(GSTR_LEN(path));
log_entry->ts = ts;
log_entry->level = log_level;
log_entry->flags = flags;
log_entry->msg = log_line;
@ -243,7 +256,7 @@ gboolean li_log_write(liServer *srv, liVRequest *vr, liLogLevel log_level, guint
if (G_LIKELY(wrk)) {
/* push onto local worker log queue */
g_queue_push_tail_link(&wrk->log_queue, &log_entry->queue_link);
g_queue_push_tail_link(&wrk->logs.log_queue, &log_entry->queue_link);
} else {
/* no worker context, push directly onto global log queue */
g_static_mutex_lock(&srv->logs.write_queue_mutex);
@ -260,25 +273,26 @@ static gpointer log_thread(liServer *srv) {
return NULL;
}
static GString *log_timestamp_format(liServer *srv, liLogTimestamp *ts) {
static GString *log_timestamp_format(liServer *srv) {
gsize s;
struct tm tm;
time_t now = (time_t) ev_now(srv->logs.loop);
/* cache hit */
if (now == ts->last_ts)
return ts->cached;
if (now == srv->logs.timestamp.last_ts) {
return srv->logs.timestamp.cached;
}
#ifdef HAVE_LOCALTIME_R
s = strftime(ts->cached->str, ts->cached->allocated_len, ts->format->str, localtime_r(&now, &tm));
s = strftime(srv->logs.timestamp.cached->str, srv->logs.timestamp.cached->allocated_len, srv->logs.timestamp.format->str, localtime_r(&now, &tm));
#else
s = strftime(ts->cached->str, ts->cached->allocated_len, ts->format->str, localtime(&now));
s = strftime(srv->logs.timestamp.cached->str, srv->logs.timestamp.cached->allocated_len, srv->logs.timestamp.format->str, localtime(&now));
#endif
g_string_set_size(ts->cached, s);
ts->last_ts = now;
g_string_set_size(srv->logs.timestamp.cached, s);
srv->logs.timestamp.last_ts = now;
return ts->cached;
return srv->logs.timestamp.cached;
}
static void log_watcher_cb(struct ev_loop *loop, ev_async *w, int revents) {
@ -306,16 +320,16 @@ static void log_watcher_cb(struct ev_loop *loop, ev_async *w, int revents) {
g_static_mutex_unlock(&srv->logs.write_queue_mutex);
while (queue_link) {
liLog *log;
liLogTarget *log;
liLogEntry *log_entry = queue_link->data;
GString *msg = log_entry->msg;
gssize bytes_written = 0;
gssize write_res;
if (log_entry->flags & LOG_FLAG_TIMESTAMP) {
log_timestamp_format(srv, log_entry->ts);
GString *ts = log_timestamp_format(srv);
g_string_prepend_c(msg, ' ');
g_string_prepend_len(msg, GSTR_LEN(log_entry->ts->cached));
g_string_prepend_len(msg, GSTR_LEN(ts));
}
g_string_append_len(msg, CONST_STR_LEN("\n"));
@ -478,57 +492,7 @@ void li_log_thread_wakeup(liServer *srv) {
ev_async_send(srv->logs.loop, &srv->logs.watcher);
}
liLogTimestamp *li_log_timestamp_new(liServer *srv, GString *format) {
liLogTimestamp *ts;
/* check if there already exists a timestamp entry with the same format */
g_mutex_lock(srv->action_mutex);
for (guint i = 0; i < srv->logs.timestamps->len; i++) {
ts = g_array_index(srv->logs.timestamps, liLogTimestamp*, i);
if (g_string_equal(ts->format, format)) {
g_atomic_int_inc(&(ts->refcount));
g_string_free(format, TRUE);
g_mutex_unlock(srv->action_mutex);
return ts;
}
}
ts = g_slice_new(liLogTimestamp);
ts->cached = g_string_sized_new(255);
ts->last_ts = 0;
ts->refcount = 1;
ts->format = format;
g_array_append_val(srv->logs.timestamps, ts);
g_mutex_unlock(srv->action_mutex);
return ts;
}
gboolean li_log_timestamp_free(liServer *srv, liLogTimestamp *ts) {
if (g_atomic_int_dec_and_test(&(ts->refcount))) {
g_mutex_lock(srv->action_mutex);
for (guint i = 0; i < srv->logs.timestamps->len; i++) {
if (g_array_index(srv->logs.timestamps, liLogTimestamp*, i) == ts) {
g_array_remove_index_fast(srv->logs.timestamps, i);
break;
}
}
g_mutex_unlock(srv->action_mutex);
g_string_free(ts->cached, TRUE);
g_string_free(ts->format, TRUE);
g_slice_free(liLogTimestamp, ts);
return TRUE;
}
return FALSE;
}
void li_log_split_lines(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, gchar *txt, const gchar *prefix) {
void li_log_split_lines(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, gchar *txt, const gchar *prefix) {
gchar *start;
start = txt;
@ -536,7 +500,7 @@ void li_log_split_lines(liServer *srv, liVRequest *vr, liLogLevel log_level, gui
if ('\r' == *txt || '\n' == *txt) {
*txt = '\0';
if (txt - start > 1) { /* skip empty lines*/
li_log_write(srv, vr, log_level, flags, "%s%s", prefix, start);
li_log_write(srv, wrk, log_map, log_level, flags, "%s%s", prefix, start);
}
txt++;
while (*txt == '\n' || *txt == '\r') txt++;
@ -546,11 +510,11 @@ void li_log_split_lines(liServer *srv, liVRequest *vr, liLogLevel log_level, gui
}
}
if (txt - start > 1) { /* skip empty lines*/
li_log_write(srv, vr, log_level, flags, "%s%s", prefix, start);
li_log_write(srv, wrk, log_map, log_level, flags, "%s%s", prefix, start);
}
}
void li_log_split_lines_(liServer *srv, liVRequest *vr, liLogLevel log_level, guint flags, gchar *txt, const gchar *fmt, ...) {
void li_log_split_lines_(liServer *srv, liWorker *wrk, liLogMap* log_map, liLogLevel log_level, guint flags, gchar *txt, const gchar *fmt, ...) {
va_list ap;
GString *prefix;
@ -559,7 +523,7 @@ void li_log_split_lines_(liServer *srv, liVRequest *vr, liLogLevel log_level, gu
g_string_vprintf(prefix, fmt, ap);
va_end(ap);
li_log_split_lines(srv, vr, log_level, flags, txt, prefix->str);
li_log_split_lines(srv, wrk, log_map, log_level, flags, txt, prefix->str);
g_string_free(prefix, TRUE);
}

62
src/main/plugin_core.c

@ -1323,20 +1323,19 @@ static gboolean core_option_log_parse(liServer *srv, liWorker *wrk, liPlugin *p,
liLogLevel level;
GString *path;
GString *level_str;
GArray *arr = g_array_sized_new(FALSE, TRUE, sizeof(GString*), 6);
liLogMap *logmap = li_log_map_new();
UNUSED(wrk);
UNUSED(p);
UNUSED(ndx);
*oval = arr;
g_array_set_size(arr, 6);
*oval = logmap;
/* default value */
if (!val) {
/* default: log LI_LOG_LEVEL_WARNING, LI_LOG_LEVEL_ERROR and LI_LOG_LEVEL_BACKEND to stderr */
g_array_index(arr, GString*, LI_LOG_LEVEL_WARNING) = g_string_new_len(CONST_STR_LEN("stderr"));
g_array_index(arr, GString*, LI_LOG_LEVEL_ERROR) = g_string_new_len(CONST_STR_LEN("stderr"));
g_array_index(arr, GString*, LI_LOG_LEVEL_BACKEND) = g_string_new_len(CONST_STR_LEN("stderr"));
g_array_index(logmap->arr, GString*, LI_LOG_LEVEL_WARNING) = g_string_new_len(CONST_STR_LEN("stderr"));
g_array_index(logmap->arr, GString*, LI_LOG_LEVEL_ERROR) = g_string_new_len(CONST_STR_LEN("stderr"));
g_array_index(logmap->arr, GString*, LI_LOG_LEVEL_BACKEND) = g_string_new_len(CONST_STR_LEN("stderr"));
return TRUE;
}
@ -1344,7 +1343,7 @@ static gboolean core_option_log_parse(liServer *srv, liWorker *wrk, liPlugin *p,
while (g_hash_table_iter_next(&iter, &k, &v)) {
if (((liValue*)v)->type != LI_VALUE_STRING) {
ERROR(srv, "log expects a hashtable with string values, %s given", li_value_type_string(((liValue*)v)->type));
g_array_free(arr, TRUE);
li_log_map_release(logmap);
return FALSE;
}
@ -1352,17 +1351,20 @@ static gboolean core_option_log_parse(liServer *srv, liWorker *wrk, liPlugin *p,
level_str = (GString*)k;
if (g_str_equal(level_str->str, "*")) {
for (guint i = 0; i < arr->len; i++) {
for (guint i = 0; i < logmap->arr->len; i++) {
/* overwrite old path */
if (NULL != g_array_index(arr, GString*, i))
g_string_free(g_array_index(arr, GString*, i), TRUE);
if (NULL != g_array_index(logmap->arr, GString*, i)) {
g_string_free(g_array_index(logmap->arr, GString*, i), TRUE);
}
g_array_index(arr, GString*, i) = g_string_new_len(GSTR_LEN(path));
g_array_index(logmap->arr, GString*, i) = g_string_new_len(GSTR_LEN(path));
}
}
else {
} else {
level = li_log_level_from_string(level_str);
g_array_index(arr, GString*, level) = g_string_new_len(GSTR_LEN(path));;
if (NULL != g_array_index(logmap->arr, GString*, level)) {
g_string_free(g_array_index(logmap->arr, GString*, level), TRUE);
}
g_array_index(logmap->arr, GString*, level) = li_value_extract_string(v);
}
}
@ -1370,40 +1372,28 @@ static gboolean core_option_log_parse(liServer *srv, liWorker *wrk, liPlugin *p,
}
static void core_option_log_free(liServer *srv, liPlugin *p, size_t ndx, gpointer oval) {
GArray *arr = oval;
liLogMap *logmap = oval;
UNUSED(srv);
UNUSED(p);
UNUSED(ndx);
if (!arr) return;
for (guint i = 0; i < arr->len; i++) {
if (NULL != g_array_index(arr, GString*, i))
g_string_free(g_array_index(arr, GString*, i), TRUE);
}
g_array_free(arr, TRUE);
li_log_map_release(logmap);
}
static gboolean core_option_log_timestamp_parse(liServer *srv, liWorker *wrk, liPlugin *p, size_t ndx, liValue *val, gpointer *oval) {
UNUSED(wrk);
static gboolean core_setup_log_timestamp(liServer *srv, liPlugin* p, liValue *val, gpointer userdata) {
UNUSED(p);
UNUSED(ndx);
UNUSED(userdata);
if (!val) return TRUE;
*oval = li_log_timestamp_new(srv, li_value_extract_string(val));
if (NULL != srv->logs.timestamp.format) {
g_string_free(srv->logs.timestamp.format, TRUE);
}
srv->logs.timestamp.format = li_value_extract_string(val);
srv->logs.timestamp.last_ts = 0;
return TRUE;
}
static void core_option_log_timestamp_free(liServer *srv, liPlugin *p, size_t ndx, gpointer oval) {
UNUSED(p);
UNUSED(ndx);
if (!oval) return;
li_log_timestamp_free(srv, oval);
}
static gboolean core_option_static_exclude_exts_parse(liServer *srv, liWorker *wrk, liPlugin *p, size_t ndx, liValue *val, gpointer *oval) {
GArray *arr;
UNUSED(srv);
@ -2029,7 +2019,6 @@ static const liPluginOption options[] = {
};
static const liPluginOptionPtr optionptrs[] = {
{ "log.timestamp", LI_VALUE_STRING, NULL, core_option_log_timestamp_parse, core_option_log_timestamp_free },
{ "log", LI_VALUE_HASH, NULL, core_option_log_parse, core_option_log_free },
{ "static.exclude_extensions", LI_VALUE_LIST, NULL, core_option_static_exclude_exts_parse, NULL },
@ -2090,6 +2079,7 @@ static const liPluginSetup setups[] = {
{ "io.timeout", core_io_timeout, NULL },
{ "stat_cache.ttl", core_stat_cache_ttl, NULL },
{ "tasklet_pool.threads", core_tasklet_pool_threads, NULL },
{ "log.timestamp", core_setup_log_timestamp, NULL },
{ NULL, NULL, NULL }
};

2
src/main/request.c

@ -195,7 +195,7 @@ gboolean li_request_validate_header(liConnection *con) {
r = g_ascii_strtoll(val, &err, 10);
if (*err != '\0') {
_DEBUG(con->srv, con->mainvr, "content-length is not a number: %s (Status: 400)", err);
_VR_DEBUG(con->srv, con->mainvr, "content-length is not a number: %s (Status: 400)", err);
bad_request(con, 400); /* bad request */
return FALSE;
}

4
src/main/worker.c

@ -211,11 +211,11 @@ static void li_worker_prepare_cb(struct ev_loop *loop, ev_prepare *w, int revent
UNUSED(revents);
/* are there pending log entries? */
if (g_queue_get_length(&wrk->log_queue)) {
if (g_queue_get_length(&wrk->logs.log_queue)) {
/* take log entries from local queue, insert into global queue and notify log thread */
g_static_mutex_lock(&srv->logs.write_queue_mutex);
li_g_queue_merge(&srv->logs.write_queue, &wrk->log_queue);
li_g_queue_merge(&srv->logs.write_queue, &wrk->logs.log_queue);
g_static_mutex_unlock(&srv->logs.write_queue_mutex);
ev_async_send(srv->logs.loop, &srv->logs.watcher);

2
src/modules/mod_accesslog.c

@ -397,7 +397,7 @@ static void al_handle_vrclose(liVRequest *vr, liPlugin *p) {
msg = al_format_log(vr, p->data, format);
li_log_write_direct(vr->wrk->srv, vr, log_path, msg);
li_log_write_direct(vr->wrk->srv, vr->wrk, log_path, msg);
}

2
src/modules/mod_fastcgi.c

@ -533,7 +533,7 @@ static gboolean fastcgi_parse_response(fastcgi_connection *fcon) {
len = fastcgi_available(fcon);
li_chunkqueue_extract_to(vr, fcon->fcgi_in, len, vr->wrk->tmp_str);
if (OPTION(FASTCGI_OPTION_LOG_PLAIN_ERRORS).boolean) {
li_log_split_lines(vr->wrk->srv, vr, LI_LOG_LEVEL_BACKEND, 0, vr->wrk->tmp_str->str, "");
li_log_split_lines(vr->wrk->srv, vr->wrk, li_log_vr_map(vr), LI_LOG_LEVEL_BACKEND, 0, vr->wrk->tmp_str->str, "");
} else {
VR_BACKEND_LINES(vr, vr->wrk->tmp_str->str, "(fcgi-stderr %s) ", fcon->ctx->socket_str->str);
}

Loading…
Cancel
Save