diff --git a/doc/configuration.txt b/doc/configuration.txt index 6ed736a62..70a25391e 100644 --- a/doc/configuration.txt +++ b/doc/configuration.txt @@ -8741,8 +8741,8 @@ Detailed fields description : 8.2.4 Custom log format ----------------------- -The directive log-format allows you to custom the logs in http mode. It takes a -string as argument. +The directive log-format allows you to custom the logs in http mode and tcp +mode. It takes a string as argument. HAproxy understands some log format variables. % precedes log format variables. Variables can take arguments using braces ('{}'), and multiple arguments are @@ -8769,49 +8769,55 @@ At the moment, the default HTTP format is defined this way : log-format %Ci:%Cp\ [%t]\ %f\ %b/%s\ %Tq/%Tw/%Tc/%Tr/%Tt\ %st\ %B\ %cc\ \ %cs\ %ts\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r -And the default CLF format is defined this way : +the default CLF format is defined this way : log-format %{+Q}o\ %{-Q}Ci\ -\ -\ [%T]\ %r\ %st\ %B\ \"\"\ \"\"\ %Cp\ \ %ms\ %f\ %b\ %s\ \%Tq\ %Tw\ %Tc\ %Tr\ %Tt\ %ts\ %ac\ %fc\ \ %bc\ %sc\ %rc\ %sq\ %bq\ %cc\ %cs\ \%hrl\ %hsl +and the default TCP format is defined this way : + + log-format %Ci:%Cp\ [%t]\ %f\ %b/%s\ %Tw/%Tc/%Tt\ %B\ %ts\ \ + %ac/%fc/%bc/%sc/%rc\ %sq/%bq + Please refer to the table below for currently defined variables : - +------+-----------------------------------------------+-------------+ - | var | field name (8.2.2 and 8.2.3 for description) | type | - +------+-----------------------------------------------+-------------+ - | %o | special variable, apply flags on all next var | | - +------+-----------------------------------------------+-------------+ - | %B | bytes_read | numeric | - | %Ci | client_ip | string | - | %Cp | client_port | numeric | - | %Tc | Tc | numeric | - | %Tq | Tq | numeric | - | %Tr | Tr | numeric | - | %Tt | Tt | numeric | - | %Tw | Tw | numeric | - | %ac | actconn | numeric | - | %b | backend_name | string | - | %bc | beconn | numeric | - | %bq | backend_queue | numeric | - | %cc | captured_request_cookie | string | - | %cs | captured_response_cookie | string | - | %f | frontend_name | string | - | %fc | feconn | numeric | - | %hr | captured_request_headers default style | string | - | %hrl | captured_request_headers CLF style | string list | - | %hs | captured_response_headers default style | string | - | %hsl | captured_response_headers CLF style | string list | - | %ms | accept date milliseconds | numeric | - | %r | http_request | string | - | %rc | retries | numeric | - | %s | server_name | string | - | %sc | srv_conn | numeric | - | %sq | srv_queue | numeric | - | %st | status_code | numeric | - | %ts | termination_state | string | - +------+-----------------------------------------------+-------------+ + +---+------+-----------------------------------------------+-------------+ + | H | var | field name (8.2.2 and 8.2.3 for description) | type | + +---+------+-----------------------------------------------+-------------+ + | | %o | special variable, apply flags on all next var | | + +---+------+-----------------------------------------------+-------------+ + | | %B | bytes_read | numeric | + | | %Ci | client_ip | string | + | | %Cp | client_port | numeric | + | | %Tc | Tc | numeric | + | * | %Tq | Tq | numeric | + | * | %Tr | Tr | numeric | + | | %Tt | Tt | numeric | + | | %Tw | Tw | numeric | + | | %ac | actconn | numeric | + | | %b | backend_name | string | + | | %bc | beconn | numeric | + | | %bq | backend_queue | numeric | + | * | %cc | captured_request_cookie | string | + | * | %cs | captured_response_cookie | string | + | | %f | frontend_name | string | + | | %fc | feconn | numeric | + | * | %hr | captured_request_headers default style | string | + | * | %hrl | captured_request_headers CLF style | string list | + | * | %hs | captured_response_headers default style | string | + | * | %hsl | captured_response_headers CLF style | string list | + | | %ms | accept date milliseconds | numeric | + | * | %r | http_request | string | + | | %rc | retries | numeric | + | | %s | server_name | string | + | | %sc | srv_conn | numeric | + | | %sq | srv_queue | numeric | + | * | %st | status_code | numeric | + | | %ts | termination_state | string | + +---+------+-----------------------------------------------+-------------+ +*: mode httplog only 8.3. Advanced logging options ----------------------------- diff --git a/include/proto/log.h b/include/proto/log.h index 34d381329..66fbe34df 100644 --- a/include/proto/log.h +++ b/include/proto/log.h @@ -35,9 +35,17 @@ extern struct pool_head *pool2_requri; extern char *log_format; +extern char default_tcp_log_format[]; extern char default_http_log_format[]; extern char clf_http_log_format[]; + +/* + * send a log for the session when we have enough info about it. + * Will not log if the frontend has no log defined. + */ +void sess_log(struct session *s); + /* * Parse args in a logformat_var */ @@ -98,10 +106,6 @@ void send_log(struct proxy *p, int level, const char *format, ...) */ void __send_log(struct proxy *p, int level, char *message, size_t size); -/* - * send a log for the session when we have enough info about it - */ -void tcp_sess_log(struct session *s); /* * returns log level for or -1 if not found. diff --git a/src/cfgparse.c b/src/cfgparse.c index e01b90f76..6f1df9c99 100644 --- a/src/cfgparse.c +++ b/src/cfgparse.c @@ -3313,9 +3313,13 @@ stats_error_parsing: } parse_logformat_string(logformat, curproxy); } - else if (!strcmp(args[1], "tcplog")) + else if (!strcmp(args[1], "tcplog")) { + char *logformat; /* generate a detailed TCP log */ curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_PXID | LW_BYTES; + logformat = default_tcp_log_format; + parse_logformat_string(logformat, curproxy); + } else if (!strcmp(args[1], "tcpka")) { /* enable TCP keep-alives on client and server sessions */ if (warnifnotcap(curproxy, PR_CAP_BE | PR_CAP_FE, file, linenum, args[1], NULL)) diff --git a/src/frontend.c b/src/frontend.c index f185f62c7..12dc2c8a0 100644 --- a/src/frontend.c +++ b/src/frontend.c @@ -78,10 +78,7 @@ int frontend_accept(struct session *s) /* FIXME: the logs are horribly complicated now, because they are * defined in

,

, and later and . */ - if (s->logs.logwait & LW_REQ) - s->do_log = http_sess_log; - else - s->do_log = tcp_sess_log; + s->do_log = sess_log; /* default error reporting function, may be changed by analysers */ s->srv_error = default_srv_error; diff --git a/src/log.c b/src/log.c index 0d1332935..3bcfaa56b 100644 --- a/src/log.c +++ b/src/log.c @@ -56,46 +56,48 @@ const char sess_fin_state[8] = "-RCHDLQT"; /* cliRequest, srvConnect, srvHeader struct logformat_type { char *name; int type; + int mode; }; /* log_format variable names */ static const struct logformat_type logformat_keywords[] = { - { "o", LOG_GLOBAL }, /* global option */ - { "Ci", LOG_CLIENTIP }, /* client ip */ - { "Cp", LOG_CLIENTPORT }, /* client port */ - { "t", LOG_DATE }, /* date */ - { "T", LOG_DATEGMT }, /* date GMT */ - { "ms", LOG_MS }, /* accept date millisecond */ - { "f", LOG_FRONTEND }, /* frontend */ - { "b", LOG_BACKEND }, /* backend */ - { "s", LOG_SERVER }, /* server */ - { "B", LOG_BYTES }, /* bytes read */ - { "Tq", LOG_TQ }, /* Tq */ - { "Tw", LOG_TW }, /* Tw */ - { "Tc", LOG_TC }, /* Tc */ - { "Tr", LOG_TR }, /* Tr */ - { "Tt", LOG_TT }, /* Tt */ - { "st", LOG_STATUS }, /* status code */ - { "cc", LOG_CCLIENT }, /* client cookie */ - { "cs", LOG_CSERVER }, /* server cookie */ - { "ts", LOG_TERMSTATE },/* terminaison state */ - { "ac", LOG_ACTCONN }, /* actconn */ - { "fc", LOG_FECONN }, /* feconn */ - { "bc", LOG_BECONN }, /* beconn */ - { "sc", LOG_SRVCONN }, /* srv_conn */ - { "rc", LOG_RETRIES }, /* retries */ - { "sq", LOG_SRVQUEUE }, /* srv_queue */ - { "bq", LOG_BCKQUEUE }, /* backend_queue */ - { "hr", LOG_HDRREQUEST }, /* header request */ - { "hs", LOG_HDRRESPONS }, /* header response */ - { "hrl", LOG_HDRREQUESTLIST }, /* header request list */ - { "hsl", LOG_HDRRESPONSLIST }, /* header response list */ - { "r", LOG_REQ }, /* request */ + { "o", LOG_GLOBAL, PR_MODE_TCP }, /* global option */ + { "Ci", LOG_CLIENTIP, PR_MODE_TCP }, /* client ip */ + { "Cp", LOG_CLIENTPORT, PR_MODE_TCP }, /* client port */ + { "t", LOG_DATE, PR_MODE_TCP }, /* date */ + { "T", LOG_DATEGMT, PR_MODE_TCP }, /* date GMT */ + { "ms", LOG_MS, PR_MODE_TCP }, /* accept date millisecond */ + { "f", LOG_FRONTEND, PR_MODE_TCP }, /* frontend */ + { "b", LOG_BACKEND, PR_MODE_TCP }, /* backend */ + { "s", LOG_SERVER, PR_MODE_TCP }, /* server */ + { "B", LOG_BYTES, PR_MODE_TCP }, /* bytes read */ + { "Tq", LOG_TQ, PR_MODE_HTTP }, /* Tq */ + { "Tw", LOG_TW, PR_MODE_TCP }, /* Tw */ + { "Tc", LOG_TC, PR_MODE_TCP }, /* Tc */ + { "Tr", LOG_TR, PR_MODE_HTTP }, /* Tr */ + { "Tt", LOG_TT, PR_MODE_TCP }, /* Tt */ + { "st", LOG_STATUS, PR_MODE_HTTP }, /* status code */ + { "cc", LOG_CCLIENT, PR_MODE_HTTP }, /* client cookie */ + { "cs", LOG_CSERVER, PR_MODE_HTTP }, /* server cookie */ + { "ts", LOG_TERMSTATE, PR_MODE_TCP },/* terminaison state */ + { "ac", LOG_ACTCONN, PR_MODE_TCP }, /* actconn */ + { "fc", LOG_FECONN, PR_MODE_TCP }, /* feconn */ + { "bc", LOG_BECONN, PR_MODE_TCP }, /* beconn */ + { "sc", LOG_SRVCONN, PR_MODE_TCP }, /* srv_conn */ + { "rc", LOG_RETRIES, PR_MODE_TCP }, /* retries */ + { "sq", LOG_SRVQUEUE, PR_MODE_TCP }, /* srv_queue */ + { "bq", LOG_BCKQUEUE, PR_MODE_TCP }, /* backend_queue */ + { "hr", LOG_HDRREQUEST, PR_MODE_HTTP }, /* header request */ + { "hs", LOG_HDRRESPONS, PR_MODE_HTTP }, /* header response */ + { "hrl", LOG_HDRREQUESTLIST, PR_MODE_HTTP }, /* header request list */ + { "hsl", LOG_HDRRESPONSLIST, PR_MODE_HTTP }, /* header response list */ + { "r", LOG_REQ, PR_MODE_HTTP }, /* request */ { 0, 0 } }; char default_http_log_format[] = "%Ci:%Cp [%t] %f %b/%s %Tq/%Tw/%Tc/%Tr/%Tt %st %B %cc %cs %ts %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"; // default format char clf_http_log_format[] = "%{+Q}o %{-Q}Ci - - [%T] %r %st %B \"\" \"\" %Cp %ms %f %b %s %Tq %Tw %Tc %Tr %Tt %ts %ac %fc %bc %sc %rc %sq %bq %cc %cs %hrl %hsl"; +char default_tcp_log_format[] = "%Ci:%Cp [%t] %f %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"; char *log_format = NULL; struct logformat_var_args { @@ -174,7 +176,6 @@ int parse_logformat_var(char *str, size_t len, struct proxy *curproxy) char varname[255] = { 0 }; // variable name int logformat_options = 0x00000000; - for (i = 1; i < len; i++) { // escape first char % if (!arg && str[i] == '{') { arg = str + i; @@ -190,18 +191,25 @@ int parse_logformat_var(char *str, size_t len, struct proxy *curproxy) varname[len - i] = '\0'; for (j = 0; logformat_keywords[j].name; j++) { // search a log type if (strcmp(varname, logformat_keywords[j].name) == 0) { - node = calloc(1, sizeof(struct logformat_node)); - node->type = logformat_keywords[j].type; - node->options = logformat_options; - node->arg = arg; - parse_logformat_var_args(node->arg, node); - if (node->type == LOG_GLOBAL) { - logformat_options = node->options; - free(node); + if (!((logformat_keywords[j].mode == PR_MODE_HTTP) && (curproxy->mode == PR_MODE_TCP))) { + node = calloc(1, sizeof(struct logformat_node)); + node->type = logformat_keywords[j].type; + node->options = logformat_options; + node->arg = arg; + parse_logformat_var_args(node->arg, node); + if (node->type == LOG_GLOBAL) { + logformat_options = node->options; + free(node); + } else { + LIST_ADDQ(&curproxy->logformat, &node->list); + } + return 0; } else { - LIST_ADDQ(&curproxy->logformat, &node->list); + Warning("Warning: No such variable name '%s' in this log mode\n", varname); + if (arg) + free(arg); + return -1; } - return 0; } } Warning("Warning: No such variable name '%s' in logformat\n", varname); @@ -438,50 +446,50 @@ int get_log_facility(const char *fac) */ char *logformat_write_string(char *dst, char *src, size_t size, struct logformat_node *node) { - char *orig = dst; + char *orig = dst; - if (src == NULL || *src == '\0') { - if (node->options & LOG_OPT_QUOTE) { - if (size > 2) { - *(dst++) = '"'; - *(dst++) = '"'; - *dst = '\0'; - node->options |= LOG_OPT_WRITTEN; - } else { - dst = NULL; - return dst; - } - } else { - if (size > 1) { - *(dst++) = '-'; - *dst = '\0'; - node->options |= LOG_OPT_WRITTEN; - } else { // error no space available - dst = NULL; - return dst; - } - } - } else { - if (node->options & LOG_OPT_QUOTE) { - if (size-- > 1 ) { - *(dst++) = '"'; - } else { - dst = NULL; - return NULL; - } - dst += strlcpy2(dst, src, size); - size -= orig - dst + 1; - if (size > 1) { - *(dst++) = '"'; - *dst = '\0'; - } else { - dst = NULL; - } - } else { - dst += strlcpy2(dst, src, size); - } - } - return dst; + if (src == NULL || *src == '\0') { + if (node->options & LOG_OPT_QUOTE) { + if (size > 2) { + *(dst++) = '"'; + *(dst++) = '"'; + *dst = '\0'; + node->options |= LOG_OPT_WRITTEN; + } else { + dst = NULL; + return dst; + } + } else { + if (size > 1) { + *(dst++) = '-'; + *dst = '\0'; + node->options |= LOG_OPT_WRITTEN; + } else { // error no space available + dst = NULL; + return dst; + } + } + } else { + if (node->options & LOG_OPT_QUOTE) { + if (size-- > 1 ) { + *(dst++) = '"'; + } else { + dst = NULL; + return NULL; + } + dst += strlcpy2(dst, src, size); + size -= orig - dst + 1; + if (size > 1) { + *(dst++) = '"'; + *dst = '\0'; + } else { + dst = NULL; + } + } else { + dst += strlcpy2(dst, src, size); + } + } + return dst; } /* generate the syslog header once a second */ @@ -618,7 +626,7 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) /* we can filter the level of the messages that are sent to each logger */ if (level > logsrv->level) continue; - + /* For each target, we may have a different facility. * We can also have a different log level for each message. * This induces variations in the message header length. @@ -646,32 +654,60 @@ void __send_log(struct proxy *p, int level, char *message, size_t size) } } +extern fd_set hdr_encode_map[]; +extern fd_set url_encode_map[]; + + +const char sess_cookie[8] = "NIDVEO67"; /* No cookie, Invalid cookie, cookie for a Down server, Valid cookie, Expired cookie, Old cookie, unknown */ +const char sess_set_cookie[8] = "NPDIRU67"; /* No set-cookie, Set-cookie found and left unchanged (passive), + Set-cookie Deleted, Set-Cookie Inserted, Set-cookie Rewritten, + Set-cookie Updated, unknown, unknown */ + +#define LOGCHAR(x) do { \ + if (MAX_SYSLOG_LEN - (tmplog - logline) > 1) { \ + *(tmplog++) = (x); \ + } else { \ + goto out; \ + } \ + } while(0) /* - * send a log for the session when we have enough info about it + * send a log for the session when we have enough info about it. + * Will not log if the frontend has no log defined. */ -void tcp_sess_log(struct session *s) +void sess_log(struct session *s) { char pn[INET6_ADDRSTRLEN]; struct proxy *fe = s->fe; struct proxy *be = s->be; struct proxy *prx_log; + struct http_txn *txn = &s->txn; int tolog, level, err; - char *svid; + char *uri; + const char *svid; struct tm tm; + int t_request; + int hdr; + int last_isspace = 1; + static char logline[MAX_SYSLOG_LEN] = { 0 }; + static char *tmplog; + struct logformat_node *tmp; /* if we don't want to log normal traffic, return now */ - err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || (s->req->cons->conn_retries != be->conn_retries); + err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || + (s->req->cons->conn_retries != be->conn_retries) || + ((s->fe->mode == PR_MODE_HTTP) && txn->status >= 500); if (!err && (fe->options2 & PR_O2_NOLOGNORM)) return; - addr_to_str(&s->si[0].addr.from, pn, sizeof(pn)); - get_localtime(s->logs.tv_accept.tv_sec, &tm); - - if(LIST_ISEMPTY(&fe->logsrvs)) + if (LIST_ISEMPTY(&fe->logsrvs)) return; - prx_log = fe; + + if (addr_to_str(&s->req->prod->addr.from, pn, sizeof(pn)) == AF_UNIX) + snprintf(pn, sizeof(pn), "unix:%d", s->listener->luid); + + /* FIXME: let's limit ourselves to frontend logging for now. */ tolog = fe->to_log; if (!(tolog & LW_SVID)) @@ -688,33 +724,345 @@ void tcp_sess_log(struct session *s) break; } + t_request = -1; + if (tv_isge(&s->logs.tv_request, &s->logs.tv_accept)) + t_request = tv_ms_elapsed(&s->logs.tv_accept, &s->logs.tv_request); + level = LOG_INFO; if (err && (fe->options2 & PR_O2_LOGERRORS)) level = LOG_ERR; - send_log(prx_log, level, "%s:%d [%02d/%s/%04d:%02d:%02d:%02d.%03d]" - " %s %s/%s %ld/%ld/%s%ld %s%lld" - " %c%c %d/%d/%d/%d/%s%u %ld/%ld\n", - s->si[0].addr.from.ss_family == AF_UNIX ? "unix" : pn, - s->si[0].addr.from.ss_family == AF_UNIX ? s->listener->luid : get_host_port(&s->si[0].addr.from), - tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900, - tm.tm_hour, tm.tm_min, tm.tm_sec, (int)s->logs.tv_accept.tv_usec/1000, - fe->id, be->id, svid, - (s->logs.t_queue >= 0) ? s->logs.t_queue : -1, - (s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1, - (tolog & LW_BYTES) ? "" : "+", s->logs.t_close, - (tolog & LW_BYTES) ? "" : "+", s->logs.bytes_out, - sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT], - sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT], - actconn, fe->feconn, be->beconn, target_srv(&s->target) ? target_srv(&s->target)->cur_sess : 0, - (s->flags & SN_REDISP)?"+":"", - (s->req->cons->conn_retries>0)?(be->conn_retries - s->req->cons->conn_retries):be->conn_retries, - s->logs.srv_queue_size, s->logs.prx_queue_size); + /* fill logbuffer */ + tmplog = logline; + tmplog = hdr_log(tmplog); + + list_for_each_entry(tmp, &fe->logformat, list) { + char *src = NULL; + switch (tmp->type) { + + case LOG_SEPARATOR: + if (!last_isspace) { + LOGCHAR(' '); + last_isspace = 1; + *tmplog = '\0'; + } + break; + + case LOG_TEXT: // text + src = tmp->arg; + tmplog += strlcpy2(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_CLIENTIP: // %Ci + src = (s->req->prod->addr.from.ss_family == AF_UNIX) ? "unix" : pn; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_CLIENTPORT: // %Cp + tmplog = ltoa_o((s->req->prod->addr.from.ss_family == AF_UNIX) ? s->listener->luid : get_host_port(&s->req->prod->addr.from), + tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_DATE: // %t + get_localtime(s->logs.accept_date.tv_sec, &tm); + tmplog = date2str_log(tmplog, &tm, &(s->logs.accept_date), MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_DATEGMT: // %T + get_gmtime(s->logs.accept_date.tv_sec, &tm); + tmplog = gmt2str_log(tmplog, &tm, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_MS: // %ms + if ((MAX_SYSLOG_LEN - (tmplog - logline)) < 4) { + tmplog = NULL; + goto out; + } + tmplog = utoa_pad((unsigned int)s->logs.accept_date.tv_usec/1000, + tmplog, 4); + last_isspace = 0; + + break; + + case LOG_FRONTEND: // %f + src = fe->id; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + if (!tmplog) + goto out; + last_isspace = 0 ; + break; + + case LOG_BACKEND: // %b + src = be->id; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + if (!tmplog) + goto out; + last_isspace = 0 ; + break; + + case LOG_SERVER: // %s + src = (char *)svid; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_TQ: // %Tq + tmplog = ltoa_o(t_request, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_TW: // %Tw + tmplog = ltoa_o((s->logs.t_queue >= 0) ? s->logs.t_queue - t_request : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_TC: // %Tc + tmplog = ltoa_o((s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_TR: // %Tr + tmplog = ltoa_o((s->logs.t_data >= 0) ? s->logs.t_data - s->logs.t_connect : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_TT: // %Tt + if (!(tolog & LW_BYTES)) + *(tmplog++) = '+'; + tmplog = ltoa_o(s->logs.t_close, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_STATUS: // %st + tmplog = ultoa_o(txn->status, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_BYTES: // %B + if (!(tolog & LW_BYTES)) + *(tmplog++) = '+'; + tmplog = lltoa(s->logs.bytes_out, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_CCLIENT: // %cc + src = txn->cli_cookie; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + last_isspace = 0; + break; + + case LOG_CSERVER: // %cs + src = txn->srv_cookie; + tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); + last_isspace = 0; + break; + + case LOG_TERMSTATE: // %ts + + LOGCHAR(sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT]); + LOGCHAR(sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT]); + if (fe->mode == PR_MODE_HTTP) { + LOGCHAR((be->options & PR_O_COOK_ANY) ? sess_cookie[(txn->flags & TX_CK_MASK) >> TX_CK_SHIFT] : '-'); + LOGCHAR((be->options & PR_O_COOK_ANY) ? sess_set_cookie[(txn->flags & TX_SCK_MASK) >> TX_SCK_SHIFT] : '-'); + } + *tmplog = '\0'; + last_isspace = 0; + break; + + case LOG_ACTCONN: // %ac + tmplog = ltoa_o(actconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_FECONN: // %fc + tmplog = ltoa_o(fe->feconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_BECONN: // %bc + tmplog = ltoa_o(be->beconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_SRVCONN: // %sc + tmplog = ultoa_o(target_srv(&s->target) ? target_srv(&s->target)->cur_sess : 0, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_RETRIES: // %rq + if (s->flags & SN_REDISP) + *(tmplog++) = '+'; + tmplog = ltoa_o((s->req->cons->conn_retries>0)?(be->conn_retries - s->req->cons->conn_retries):be->conn_retries, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + last_isspace = 0; + break; + + case LOG_SRVQUEUE: // %sq + tmplog = ltoa_o(s->logs.srv_queue_size, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_BCKQUEUE: // %bq + tmplog = ltoa_o(s->logs.prx_queue_size, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); + if (!tmplog) + goto out; + last_isspace = 0; + break; + + case LOG_HDRREQUEST: // %hr + /* request header */ + if (fe->to_log & LW_REQHDR && txn->req.cap) { + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + LOGCHAR('{'); + for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { + if (hdr) + LOGCHAR('|'); + if (txn->req.cap[hdr] != NULL) + tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, + '#', hdr_encode_map, txn->req.cap[hdr]); + } + LOGCHAR('}'); + last_isspace = 0; + } + *tmplog = '\0'; + break; + + case LOG_HDRREQUESTLIST: // %hrl + /* request header list */ + if (fe->to_log & LW_REQHDR && txn->req.cap) { + for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { + if (hdr > 0) + LOGCHAR(' '); + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + if (txn->req.cap[hdr] != NULL) { + tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, + '#', hdr_encode_map, txn->req.cap[hdr]); + } else if (!(tmp->options & LOG_OPT_QUOTE)) + LOGCHAR('-'); + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + *tmplog = '\0'; + last_isspace = 0; + } + } + break; + + case LOG_HDRRESPONS: // %hs + /* response header */ + if (fe->to_log & LW_RSPHDR && + txn->rsp.cap) { + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + LOGCHAR('{'); + for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { + if (hdr) + LOGCHAR('|'); + if (txn->rsp.cap[hdr] != NULL) + tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, + '#', hdr_encode_map, txn->rsp.cap[hdr]); + } + LOGCHAR('}'); + last_isspace = 0; + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + } + *tmplog = '\0'; + break; + + case LOG_HDRRESPONSLIST: // %hsl + /* response header list */ + if (fe->to_log & LW_RSPHDR && txn->rsp.cap) { + for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { + if (hdr > 0) + LOGCHAR(' '); + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + if (txn->rsp.cap[hdr] != NULL) { + tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, + '#', hdr_encode_map, txn->rsp.cap[hdr]); + } else if (!(tmp->options & LOG_OPT_QUOTE)) + LOGCHAR('-'); + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + *tmplog = '\0'; + last_isspace = 0; + } + } + break; + + case LOG_REQ: // %r + /* Request */ + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + uri = txn->uri ? txn->uri : ""; + tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, + '#', url_encode_map, uri); + if (tmp->options & LOG_OPT_QUOTE) + LOGCHAR('"'); + *tmplog = '\0'; + last_isspace = 0; + break; + } + } + +out: + + if (tmplog == NULL) // if previous error + tmplog = logline + MAX_SYSLOG_LEN - 1; + + __send_log(prx_log, level, logline, tmplog - logline + 1); s->logs.logwait = 0; + } + + + /* * Local variables: * c-indent-level: 8 diff --git a/src/proto_http.c b/src/proto_http.c index c71b83955..b3a1f9800 100644 --- a/src/proto_http.c +++ b/src/proto_http.c @@ -844,408 +844,9 @@ void http_return_srv_error(struct session *s, struct stream_interface *si) extern const char sess_term_cond[8]; extern const char sess_fin_state[8]; extern const char *monthname[12]; -const char sess_cookie[8] = "NIDVEO67"; /* No cookie, Invalid cookie, cookie for a Down server, Valid cookie, Expired cookie, Old cookie, unknown */ -const char sess_set_cookie[8] = "NPDIRU67"; /* No set-cookie, Set-cookie found and left unchanged (passive), - Set-cookie Deleted, Set-Cookie Inserted, Set-cookie Rewritten, - Set-cookie Updated, unknown, unknown */ struct pool_head *pool2_requri; struct pool_head *pool2_capture; -#define LOGCHAR(x) do { \ - if (MAX_SYSLOG_LEN - (tmplog - logline) > 1) { \ - *(tmplog++) = (x); \ - } else { \ - goto out; \ - } \ - } while(0) - -/* - * send a log for the session when we have enough info about it. - * Will not log if the frontend has no log defined. - */ -void http_sess_log(struct session *s) -{ - char pn[INET6_ADDRSTRLEN]; - struct proxy *fe = s->fe; - struct proxy *be = s->be; - struct proxy *prx_log; - struct http_txn *txn = &s->txn; - int tolog, level, err; - char *uri; - const char *svid; - struct tm tm; - int t_request; - int hdr; - int last_isspace = 1; - static char logline[MAX_SYSLOG_LEN] = { 0 }; - static char *tmplog; - struct logformat_node *tmp; - - /* if we don't want to log normal traffic, return now */ - err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || - (s->req->cons->conn_retries != be->conn_retries) || - txn->status >= 500; - if (!err && (fe->options2 & PR_O2_NOLOGNORM)) - return; - - if (LIST_ISEMPTY(&fe->logsrvs)) - return; - prx_log = fe; - - if (addr_to_str(&s->req->prod->addr.from, pn, sizeof(pn)) == AF_UNIX) - snprintf(pn, sizeof(pn), "unix:%d", s->listener->luid); - - /* FIXME: let's limit ourselves to frontend logging for now. */ - tolog = fe->to_log; - - if (!(tolog & LW_SVID)) - svid = "-"; - else switch (s->target.type) { - case TARG_TYPE_SERVER: - svid = s->target.ptr.s->id; - break; - case TARG_TYPE_APPLET: - svid = s->target.ptr.a->name; - break; - default: - svid = ""; - break; - } - - t_request = -1; - if (tv_isge(&s->logs.tv_request, &s->logs.tv_accept)) - t_request = tv_ms_elapsed(&s->logs.tv_accept, &s->logs.tv_request); - - level = LOG_INFO; - if (err && (fe->options2 & PR_O2_LOGERRORS)) - level = LOG_ERR; - - /* fill logbuffer */ - - tmplog = logline; - tmplog = hdr_log(tmplog); - - list_for_each_entry(tmp, &fe->logformat, list) { - char *src = NULL; - switch (tmp->type) { - - case LOG_SEPARATOR: - if (!last_isspace) { - LOGCHAR(' '); - last_isspace = 1; - *tmplog = '\0'; - } - break; - - case LOG_TEXT: // text - src = tmp->arg; - tmplog += strlcpy2(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_CLIENTIP: // %Ci - src = (s->req->prod->addr.from.ss_family == AF_UNIX) ? "unix" : pn; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_CLIENTPORT: // %Cp - tmplog = ltoa_o((s->req->prod->addr.from.ss_family == AF_UNIX) ? s->listener->luid : get_host_port(&s->req->prod->addr.from), - tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_DATE: // %t - get_localtime(s->logs.accept_date.tv_sec, &tm); - tmplog = date2str_log(tmplog, &tm, &(s->logs.accept_date), MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_DATEGMT: // %T - get_gmtime(s->logs.accept_date.tv_sec, &tm); - tmplog = gmt2str_log(tmplog, &tm, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_MS: // %ms - if ((MAX_SYSLOG_LEN - (tmplog - logline)) < 4) { - tmplog = NULL; - goto out; - } - tmplog = utoa_pad((unsigned int)s->logs.accept_date.tv_usec/1000, - tmplog, 4); - last_isspace = 0; - - break; - - case LOG_FRONTEND: // %f - src = fe->id; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - if (!tmplog) - goto out; - last_isspace = 0 ; - break; - - case LOG_BACKEND: // %b - src = be->id; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - if (!tmplog) - goto out; - last_isspace = 0 ; - break; - - case LOG_SERVER: // %s - src = (char *)svid; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_TQ: // %Tq - tmplog = ltoa_o(t_request, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_TW: // %Tw - tmplog = ltoa_o((s->logs.t_queue >= 0) ? s->logs.t_queue - t_request : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_TC: // %Tc - tmplog = ltoa_o((s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_TR: // %Tr - tmplog = ltoa_o((s->logs.t_data >= 0) ? s->logs.t_data - s->logs.t_connect : -1, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_TT: // %Tt - if (!(tolog & LW_BYTES)) - *(tmplog++) = '+'; - tmplog = ltoa_o(s->logs.t_close, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_STATUS: // %st - tmplog = ultoa_o(txn->status, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_BYTES: // %B - if (!(tolog & LW_BYTES)) - *(tmplog++) = '+'; - tmplog = lltoa(s->logs.bytes_out, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_CCLIENT: // %cc - src = txn->cli_cookie; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - last_isspace = 0; - break; - - case LOG_CSERVER: // %cs - src = txn->srv_cookie; - tmplog = logformat_write_string(tmplog, src, MAX_SYSLOG_LEN - (tmplog - logline), tmp); - last_isspace = 0; - break; - - case LOG_TERMSTATE: // %ts - if (MAX_SYSLOG_LEN - (tmplog - logline) < 5) - goto out; - *(tmplog++) = sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT]; - *(tmplog++) = sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT]; - *(tmplog++) = (be->options & PR_O_COOK_ANY) ? sess_cookie[(txn->flags & TX_CK_MASK) >> TX_CK_SHIFT] : '-'; - *(tmplog++) = (be->options & PR_O_COOK_ANY) ? sess_set_cookie[(txn->flags & TX_SCK_MASK) >> TX_SCK_SHIFT] : '-'; - *tmplog = '\0'; - last_isspace = 0; - break; - - case LOG_ACTCONN: // %ac - tmplog = ltoa_o(actconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_FECONN: // %fc - tmplog = ltoa_o(fe->feconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_BECONN: // %bc - tmplog = ltoa_o(be->beconn, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_SRVCONN: // %sc - tmplog = ultoa_o(target_srv(&s->target) ? target_srv(&s->target)->cur_sess : 0, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_RETRIES: // %rq - if (s->flags & SN_REDISP) - *(tmplog++) = '+'; - tmplog = ltoa_o((s->req->cons->conn_retries>0)?(be->conn_retries - s->req->cons->conn_retries):be->conn_retries, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - last_isspace = 0; - break; - - case LOG_SRVQUEUE: // %sq - tmplog = ltoa_o(s->logs.srv_queue_size, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_BCKQUEUE: // %bq - tmplog = ltoa_o(s->logs.prx_queue_size, tmplog, MAX_SYSLOG_LEN - (tmplog - logline)); - if (!tmplog) - goto out; - last_isspace = 0; - break; - - case LOG_HDRREQUEST: // %hr - /* request header */ - if (fe->to_log & LW_REQHDR && txn->req.cap) { - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - LOGCHAR('{'); - for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { - if (hdr) - LOGCHAR('|'); - if (txn->req.cap[hdr] != NULL) - tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, - '#', hdr_encode_map, txn->req.cap[hdr]); - } - LOGCHAR('}'); - last_isspace = 0; - } - *tmplog = '\0'; - break; - - case LOG_HDRREQUESTLIST: // %hrl - /* request header list */ - if (fe->to_log & LW_REQHDR && txn->req.cap) { - for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { - if (hdr > 0) - LOGCHAR(' '); - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - if (txn->req.cap[hdr] != NULL) { - tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, - '#', hdr_encode_map, txn->req.cap[hdr]); - } else if (!(tmp->options & LOG_OPT_QUOTE)) - LOGCHAR('-'); - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - *tmplog = '\0'; - last_isspace = 0; - } - } - break; - - case LOG_HDRRESPONS: // %hs - /* response header */ - if (fe->to_log & LW_RSPHDR && - txn->rsp.cap) { - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - LOGCHAR('{'); - for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { - if (hdr) - LOGCHAR('|'); - if (txn->rsp.cap[hdr] != NULL) - tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, - '#', hdr_encode_map, txn->rsp.cap[hdr]); - } - LOGCHAR('}'); - last_isspace = 0; - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - } - *tmplog = '\0'; - break; - - case LOG_HDRRESPONSLIST: // %hsl - /* response header list */ - if (fe->to_log & LW_RSPHDR && txn->rsp.cap) { - for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { - if (hdr > 0) - LOGCHAR(' '); - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - if (txn->rsp.cap[hdr] != NULL) { - tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, - '#', hdr_encode_map, txn->rsp.cap[hdr]); - } else if (!(tmp->options & LOG_OPT_QUOTE)) - LOGCHAR('-'); - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - *tmplog = '\0'; - last_isspace = 0; - } - } - break; - - case LOG_REQ: // %r - /* Request */ - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - uri = txn->uri ? txn->uri : ""; - tmplog = encode_string(tmplog, logline + MAX_SYSLOG_LEN, - '#', url_encode_map, uri); - if (tmp->options & LOG_OPT_QUOTE) - LOGCHAR('"'); - *tmplog = '\0'; - last_isspace = 0; - break; - } - } - -out: - - if (tmplog == NULL) // if previous error - tmplog = logline + MAX_SYSLOG_LEN - 1; - - __send_log(prx_log, level, logline, tmplog - logline + 1); - s->logs.logwait = 0; - -} - /* * Capture headers from message starting at according to header list * , and fill the structure appropriately.