diff --git a/logging.c b/logging.c index 773b6ebb..f5c07cc7 100644 --- a/logging.c +++ b/logging.c @@ -19,6 +19,52 @@ extern struct uwsgi_server uwsgi; +struct uwsgi_logvar *uwsgi_logvar_get(struct wsgi_request *wsgi_req, char *key, uint8_t keylen) { + struct uwsgi_logvar *lv = wsgi_req->logvars; + while(lv) { + if (!uwsgi_strncmp(key, keylen, lv->key, lv->keylen)) { + return lv; + } + lv = lv->next; + } + return NULL; +} + +void uwsgi_logvar_add(struct wsgi_request *wsgi_req, char *key, uint8_t keylen, char *val, uint8_t vallen) { + + struct uwsgi_logvar *lv = uwsgi_logvar_get(wsgi_req, key, keylen); + if (lv) { + memcpy(lv->val, val, vallen); + lv->vallen = vallen; + return; + } + + // add a new log object + + lv = wsgi_req->logvars; + if (lv) { + while(lv) { + if (!lv->next) { + lv->next = uwsgi_malloc(sizeof(struct uwsgi_logvar)); + lv = lv->next; + break; + } + lv = lv->next; + } + } + else { + lv = uwsgi_malloc(sizeof(struct uwsgi_logvar)); + wsgi_req->logvars = lv; + } + + memcpy(lv->key, key, keylen); + lv->keylen = keylen; + memcpy(lv->val, val, vallen); + lv->vallen = vallen; + lv->next = NULL; + +} + void uwsgi_check_logrotate(void) { char message[1024]; @@ -112,33 +158,6 @@ void uwsgi_check_logrotate(void) { void log_request(struct wsgi_request *wsgi_req) { - // optimize this (please) - char time_request[26]; - time_t microseconds, microseconds2; - int rlen; - int app_req = -1; - char *msg2 = " "; - char *via = msg2; - - char mempkt[4096]; - char logpkt[4096]; - - struct iovec logvec[4]; - int logvecpos = 0; - - const char *msecs = "msecs"; - const char *micros = "micros"; - - long int rt; - char *tsize = (char *) msecs; - -#ifdef UWSGI_SENDFILE - char *msg1 = " via sendfile() "; -#endif - char *msg3 = " via route() "; - char *msg4 = " via offload() "; - - struct uwsgi_app *wi; int log_it = uwsgi.shared->options[UWSGI_OPTION_LOGGING]; if (wsgi_req->do_not_log) @@ -172,6 +191,39 @@ void log_request(struct wsgi_request *wsgi_req) { logit: + uwsgi.logit(wsgi_req); +} + +void uwsgi_logit_simple(struct wsgi_request *wsgi_req) { + + // optimize this (please) + char time_request[26]; + time_t microseconds, microseconds2; + int rlen; + int app_req = -1; + char *msg2 = " "; + char *via = msg2; + + char mempkt[4096]; + char logpkt[4096]; + + struct iovec logvec[4]; + int logvecpos = 0; + + const char *msecs = "msecs"; + const char *micros = "micros"; + + long int rt; + char *tsize = (char *) msecs; + +#ifdef UWSGI_SENDFILE + char *msg1 = " via sendfile() "; +#endif + char *msg3 = " via route() "; + char *msg4 = " via offload() "; + + struct uwsgi_app *wi; + if (wsgi_req->app_id >= 0) { wi = &uwsgi_apps[wsgi_req->app_id]; if (wi->requests > 0) { @@ -382,3 +434,216 @@ struct uwsgi_logger *uwsgi_get_logger(char *name) { return NULL; } + +void uwsgi_logit_lf(struct wsgi_request *wsgi_req) { + struct uwsgi_logchunk *logchunk = uwsgi.logchunks; + ssize_t rlen = 0; + while(logchunk) { + int pos = logchunk->vec; + // raw string + if (logchunk->type == 0) { + uwsgi.logvectors[wsgi_req->async_id][pos].iov_base = logchunk->ptr; + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = logchunk->len; + } + // offsetof + else if (logchunk->type == 1) { + char **var = (char **) (((char *) wsgi_req) + logchunk->pos); + uint16_t *varlen = (uint16_t *) (((char *) wsgi_req) + logchunk->pos_len); + uwsgi.logvectors[wsgi_req->async_id][pos].iov_base = *var; + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = *varlen; + } + // logvar + else if (logchunk->type == 2) { + struct uwsgi_logvar *lv = uwsgi_logvar_get(wsgi_req, logchunk->ptr, logchunk->len); + if (lv) { + uwsgi.logvectors[wsgi_req->async_id][pos].iov_base = lv->val; + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = lv->vallen; + } + else { + uwsgi.logvectors[wsgi_req->async_id][pos].iov_base = NULL; + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = 0; + } + } + // func + else if (logchunk->type == 3) { + rlen = logchunk->func(wsgi_req, (char **) &uwsgi.logvectors[wsgi_req->async_id][pos].iov_base); + if (rlen > 0) { + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = rlen; + } + else { + uwsgi.logvectors[wsgi_req->async_id][pos].iov_len = 0; + } + } + logchunk = logchunk->next; + } + + // do not check for errors + rlen = writev(2, uwsgi.logvectors[wsgi_req->async_id], uwsgi.logformat_vectors); + + // free allocated memory + logchunk = uwsgi.logchunks; + while(logchunk) { + if (logchunk->free) { + if (uwsgi.logvectors[wsgi_req->async_id][logchunk->vec].iov_len > 0) { + free(uwsgi.logvectors[wsgi_req->async_id][logchunk->vec].iov_base); + } + } + logchunk = logchunk->next; + } +} + +void uwsgi_logit_lf_strftime(struct wsgi_request *wsgi_req) { + uwsgi_log("lf strftime\n"); +} + +void uwsgi_build_log_format(char *format) { + int state = 0; + char *ptr = format; + char *current = ptr; + char *logvar = NULL; + // get the number of required iovec + while(*ptr) { + if (*ptr == '%') { + if (state == 0) { + state = 1; + } + } + // start of the variable + else if (*ptr == '(') { + if (state == 1) { + state = 2; + } + } + // end of the variable + else if (*ptr == ')') { + if (logvar) { + uwsgi_add_logchunk(1, uwsgi.logformat_vectors, logvar, ptr-logvar); + uwsgi.logformat_vectors++; + state = 0; + logvar = NULL; + current = ptr+1; + } + } + else { + if (state == 2) { + uwsgi_add_logchunk(0, uwsgi.logformat_vectors, current, (ptr-current)-2); + uwsgi.logformat_vectors++; + logvar = ptr; + } + state = 0; + } + ptr++; + } + + if (ptr-current > 0) { + uwsgi_add_logchunk(0, uwsgi.logformat_vectors, current, ptr-current); + uwsgi.logformat_vectors++; + } + + // +1 for "\n" + + uwsgi.logformat_vectors++; + +} + +ssize_t uwsgi_lf_status(struct wsgi_request *wsgi_req, char **buf) { + *buf = uwsgi_num2str(wsgi_req->status); + return strlen(*buf); +} + +ssize_t uwsgi_lf_epoch(struct wsgi_request *wsgi_req, char **buf) { + *buf = uwsgi_num2str(time(NULL)); + return strlen(*buf); +} + +ssize_t uwsgi_lf_micros(struct wsgi_request *wsgi_req, char **buf) { + int microseconds = wsgi_req->end_of_request.tv_sec * 1000000 + wsgi_req->end_of_request.tv_usec; + int microseconds2 = wsgi_req->start_of_request.tv_sec * 1000000 + wsgi_req->start_of_request.tv_usec; + *buf = uwsgi_num2str(microseconds - microseconds2); + return strlen(*buf); +} + +ssize_t uwsgi_lf_msecs(struct wsgi_request *wsgi_req, char **buf) { + int microseconds = wsgi_req->end_of_request.tv_sec * 1000000 + wsgi_req->end_of_request.tv_usec; + int microseconds2 = wsgi_req->start_of_request.tv_sec * 1000000 + wsgi_req->start_of_request.tv_usec; + *buf = uwsgi_num2str((microseconds - microseconds2)/1000); + return strlen(*buf); +} + + +void uwsgi_add_logchunk(int variable, int pos, char *ptr, size_t len) { + + struct uwsgi_logchunk *logchunk = uwsgi.logchunks; + + if (logchunk) { + while(logchunk) { + if (!logchunk->next) { + logchunk->next = uwsgi_calloc(sizeof(struct uwsgi_logchunk)); + logchunk = logchunk->next; + break; + } + logchunk = logchunk->next; + } + } + else { + uwsgi.logchunks = uwsgi_calloc(sizeof(struct uwsgi_logchunk)); + logchunk = uwsgi.logchunks; + } + + /* + 0 -> raw test + 1 -> offsetof variable + 2 -> logvar + 3 -> func + */ + + logchunk->type = variable; + logchunk->vec = pos; + // normal text + logchunk->ptr = ptr; + logchunk->len = len; + // variable + if (variable) { + if (!uwsgi_strncmp(ptr, len, "uri", 3)) { + logchunk->pos = offsetof(struct wsgi_request, uri); + logchunk->pos_len = offsetof(struct wsgi_request, uri_len); + } + else if (!uwsgi_strncmp(ptr, len, "method", 6)) { + logchunk->pos = offsetof(struct wsgi_request, method); + logchunk->pos_len = offsetof(struct wsgi_request, method_len); + } + else if (!uwsgi_strncmp(ptr, len, "user", 4)) { + logchunk->pos = offsetof(struct wsgi_request, remote_user); + logchunk->pos_len = offsetof(struct wsgi_request, remote_user_len); + } + else if (!uwsgi_strncmp(ptr, len, "addr", 4)) { + logchunk->pos = offsetof(struct wsgi_request, remote_addr); + logchunk->pos_len = offsetof(struct wsgi_request, remote_addr_len); + } + else if (!uwsgi_strncmp(ptr, len, "status", 6)) { + logchunk->type = 3; + logchunk->func = uwsgi_lf_status; + logchunk->free = 1; + } + else if (!uwsgi_strncmp(ptr, len, "micros", 6)) { + logchunk->type = 3; + logchunk->func = uwsgi_lf_micros; + logchunk->free = 1; + } + else if (!uwsgi_strncmp(ptr, len, "msecs", 5)) { + logchunk->type = 3; + logchunk->func = uwsgi_lf_msecs; + logchunk->free = 1; + } + else if (!uwsgi_strncmp(ptr, len, "epoch", 5)) { + logchunk->type = 3; + logchunk->func = uwsgi_lf_epoch; + logchunk->free = 1; + } + // logvar + else { + logchunk->type = 2; + } + } +} + diff --git a/plugins/python/uwsgi_pymodule.c b/plugins/python/uwsgi_pymodule.c index b2695f01..4210d550 100644 --- a/plugins/python/uwsgi_pymodule.c +++ b/plugins/python/uwsgi_pymodule.c @@ -498,6 +498,46 @@ PyObject *py_uwsgi_log_this(PyObject * self, PyObject * args) { return Py_None; } +PyObject *py_uwsgi_get_logvar(PyObject * self, PyObject * args) { + + char *key = NULL; + Py_ssize_t keylen = 0; + struct wsgi_request *wsgi_req = current_wsgi_req(); + + if (!PyArg_ParseTuple(args, "s#:get_logvar", &key, &keylen)) { + return NULL; + } + + struct uwsgi_logvar *lv = uwsgi_logvar_get(wsgi_req, key, keylen); + + if (lv) { + return PyString_FromStringAndSize(lv->val, lv->vallen); + } + + Py_INCREF(Py_None); + return Py_None; +} + +PyObject *py_uwsgi_set_logvar(PyObject * self, PyObject * args) { + + char *key = NULL; + Py_ssize_t keylen = 0; + char *val = NULL; + Py_ssize_t vallen = 0; + struct wsgi_request *wsgi_req = current_wsgi_req(); + + if (!PyArg_ParseTuple(args, "s#s#:set_logvar", &key, &keylen, &val, &vallen)) { + return NULL; + } + + uwsgi_logvar_add(wsgi_req, key, keylen, val, vallen); + + Py_INCREF(Py_None); + return Py_None; +} + + + PyObject *py_uwsgi_recv_frame(PyObject * self, PyObject * args) { struct wsgi_request *wsgi_req = current_wsgi_req(); @@ -3101,6 +3141,8 @@ static PyMethodDef uwsgi_advanced_methods[] = { {"mule_id", py_uwsgi_mule_id, METH_VARARGS, ""}, {"log", py_uwsgi_log, METH_VARARGS, ""}, {"log_this_request", py_uwsgi_log_this, METH_VARARGS, ""}, + {"set_logvar", py_uwsgi_set_logvar, METH_VARARGS, ""}, + {"get_logvar", py_uwsgi_get_logvar, METH_VARARGS, ""}, {"disconnect", py_uwsgi_disconnect, METH_VARARGS, ""}, {"grunt", py_uwsgi_grunt, METH_VARARGS, ""}, {"lock", py_uwsgi_lock, METH_VARARGS, ""}, diff --git a/utils.c b/utils.c index 0fe98df9..0ed0004c 100644 --- a/utils.c +++ b/utils.c @@ -824,6 +824,15 @@ void uwsgi_close_request(struct wsgi_request *wsgi_req) { while (waitpid(WAIT_ANY, &waitpid_status, WNOHANG) > 0); } + // free logvars + struct uwsgi_logvar *lv = wsgi_req->logvars; + while(lv) { + struct uwsgi_logvar *ptr = lv; + lv = lv->next; + free(ptr); + } + + // reset request tmp_id = wsgi_req->async_id; memset(wsgi_req, 0, sizeof(struct wsgi_request)); diff --git a/uwsgi.c b/uwsgi.c index 20721ec7..28403af0 100644 --- a/uwsgi.c +++ b/uwsgi.c @@ -322,6 +322,10 @@ static struct uwsgi_option uwsgi_base_options[] = { {"max-fd", required_argument, 0, "set maximum number of file descriptors (requires root privileges)", uwsgi_opt_set_int, &uwsgi.requested_max_fd, 0}, {"logto", required_argument, 0, "set logfile/udp address", uwsgi_opt_set_str, &uwsgi.logfile, 0}, {"logto2", required_argument, 0, "log to specified file or udp address after privileges drop", uwsgi_opt_set_str, &uwsgi.logto2, 0}, + {"log-format", required_argument, 0, "set advanced format for request logging", uwsgi_opt_set_str, &uwsgi.logformat, 0}, + {"logformat", required_argument, 0, "set advanced format for request logging", uwsgi_opt_set_str, &uwsgi.logformat, 0}, + {"logformat-strftime", no_argument, 0, "apply strftime to logformat output", uwsgi_opt_true, &uwsgi.logformat_strftime, 0}, + {"log-format-strftime", no_argument, 0, "apply strftime to logformat output", uwsgi_opt_true, &uwsgi.logformat_strftime, 0}, {"logfile-chown", no_argument, 0, "chown logfiles", uwsgi_opt_true, &uwsgi.logfile_chown, 0}, {"logfile-chmod", required_argument, 0, "chmod logfiles", uwsgi_opt_logfile_chmod, NULL, 0}, {"log-syslog", optional_argument, 0, "log to syslog", uwsgi_opt_set_logger, "syslog", UWSGI_OPT_MASTER | UWSGI_OPT_LOG_MASTER}, @@ -1540,6 +1544,9 @@ int main(int argc, char *argv[], char *envp[]) { uwsgi.shared->worker_log_pipe[0] = -1; uwsgi.shared->worker_log_pipe[1] = -1; + // set default logit hook + uwsgi.logit = uwsgi_logit_simple; + #ifdef UWSGI_SSL // 1 day of tolerance uwsgi.subscriptions_sign_check_tolerance = 3600 * 24; @@ -2786,6 +2793,21 @@ nextsock: memset(uwsgi.core[j], 0, sizeof(struct uwsgi_core)); } + // cores are now allocated, lets allocate logformat (if required) + if (uwsgi.logformat) { + uwsgi_build_log_format(uwsgi.logformat); + uwsgi.logit = uwsgi_logit_lf; + if (uwsgi.logformat_strftime) { + uwsgi.logit = uwsgi_logit_lf_strftime; + } + uwsgi.logvectors = uwsgi_malloc(sizeof(struct iovec *) * uwsgi.cores); + for (j = 0; j < uwsgi.cores; j++) { + uwsgi.logvectors[j] = uwsgi_malloc(sizeof(struct iovec) * uwsgi.logformat_vectors); + uwsgi.logvectors[j][uwsgi.logformat_vectors-1].iov_base = "\n"; + uwsgi.logvectors[j][uwsgi.logformat_vectors-1].iov_len = 1; + } + } + // preinit apps (create the language environment) for (i = 0; i < 256; i++) { if (uwsgi.p[i]->preinit_apps) { diff --git a/uwsgi.h b/uwsgi.h index a5463b2e..52d8dc19 100644 --- a/uwsgi.h +++ b/uwsgi.h @@ -828,6 +828,14 @@ struct uwsgi_async_fd { struct uwsgi_async_fd *next; }; +struct uwsgi_logvar { + char key[256]; + uint8_t keylen; + char val[256]; + uint8_t vallen; + struct uwsgi_logvar *next; +}; + struct wsgi_request { struct uwsgi_header uh; @@ -993,6 +1001,8 @@ struct wsgi_request { int sigwait; int signal_received; + struct uwsgi_logvar *logvars; + uint16_t stream_id; struct msghdr msg; @@ -1093,6 +1103,12 @@ struct uwsgi_server { int default_app; char *logto2; + char *logformat; + int logformat_strftime; + int logformat_vectors; + struct uwsgi_logchunk *logchunks; + void (*logit)(struct wsgi_request *); + struct iovec **logvectors; // autoload plugins int autoload; @@ -3018,6 +3034,29 @@ void uwsgi_deadlock_check(pid_t); char *uwsgi_setup_clusterbuf(size_t *); +struct uwsgi_logchunk { + char *ptr; + size_t len; + int vec; + long pos; + long pos_len; + int type; + int free; + ssize_t (*func)(struct wsgi_request *, char **); + struct uwsgi_logchunk *next; +}; + +void uwsgi_build_log_format(char *); + +void uwsgi_add_logchunk(int, int, char *, size_t); + +void uwsgi_logit_simple(struct wsgi_request *); +void uwsgi_logit_lf(struct wsgi_request *); +void uwsgi_logit_lf_strftime(struct wsgi_request *); + +struct uwsgi_logvar *uwsgi_logvar_get(struct wsgi_request *, char *, uint8_t); +void uwsgi_logvar_add(struct wsgi_request *, char *, uint8_t, char *, uint8_t); + #ifdef UWSGI_AS_SHARED_LIBRARY int uwsgi_init(int, char **, char **); #endif