diff --git a/doc/configuration.txt b/doc/configuration.txt index c9e9f7662..d597db5fd 100644 --- a/doc/configuration.txt +++ b/doc/configuration.txt @@ -2345,11 +2345,16 @@ no option httpclose See also : "option forceclose" -option httplog +option httplog [ clf ] Enable logging of HTTP request, session state and timers May be used in sections : defaults | frontend | listen | backend yes | yes | yes | yes - Arguments : none + Arguments : + clf if the "clf" argument is added, then the output format will be + the CLF format instead of HAProxy's default HTTP format. You can + use this when you need to feed HAProxy's logs through a specific + log analyser which only support the CLF format and which is not + extensible. By default, the log output format is very poor, as it only contains the source and destination addresses, and the instance name. By specifying @@ -2361,6 +2366,11 @@ option httplog This option may be set either in the frontend or the backend. + If this option has been enabled in a "defaults" section, it can be disabled + in a specific instance by prepending the "no" keyword before it. Specifying + only "option httplog" will automatically clear the 'clf' mode if it was set + by default. + See also : section 8 about logging. @@ -5224,7 +5234,7 @@ facilities. 8.2. Log formats ---------------- -HAProxy supports 3 log formats. Several fields are common between these formats +HAProxy supports 4 log formats. Several fields are common between these formats and will be detailed in the next sections. A few of them may slightly vary with the configuration, due to indicators specific to certain options. The supported formats are the following ones : @@ -5247,6 +5257,11 @@ formats are the following ones : the request, the status code, and captures of headers and cookies. This format is recommended for HTTP proxies. + - the CLF HTTP format, which is equivalent to the HTTP format, but with the + fields arranged in the same order as the CLF format. In this mode, all + timers, captures, flags, etc... appear one per field after the end of the + common fields, in the same order they appear in the standard HTTP format. + Next sections will go deeper into details for each of these formats. Format specification will be performed on a "field" basis. Unless stated otherwise, a field is a portion of text delimited by any number of spaces. Since syslog diff --git a/include/common/standard.h b/include/common/standard.h index d9b9e096a..447061e94 100644 --- a/include/common/standard.h +++ b/include/common/standard.h @@ -286,6 +286,16 @@ static inline void get_localtime(const time_t now, struct tm *tm) localtime_r(&now, tm); } +/* This function converts the time_t value into a broken out struct tm + * which must be allocated by the caller. It is highly recommended to use this + * function intead of gmtime() because that one requires a time_t* which + * is not always compatible with tv_sec depending on OS/hardware combinations. + */ +static inline void get_gmtime(const time_t now, struct tm *tm) +{ + gmtime_r(&now, tm); +} + /* This function parses a time value optionally followed by a unit suffix among * "d", "h", "m", "s", "ms" or "us". It converts the value into the unit * expected by the caller. The computation does its best to avoid overflows. diff --git a/include/types/proxy.h b/include/types/proxy.h index 43f31a6e0..c9bd0a9bb 100644 --- a/include/types/proxy.h +++ b/include/types/proxy.h @@ -120,6 +120,7 @@ #define PR_O2_SMARTACC 0x00000080 /* don't immediately ACK request after accept */ #define PR_O2_SMARTCON 0x00000100 /* don't immediately send empty ACK after connect */ #define PR_O2_RDPC_PRST 0x00000200 /* Actvate rdp cookie analyser */ +#define PR_O2_CLFLOG 0x00000400 /* log into clf format */ /* This structure is used to apply fast weighted round robin on a server group */ struct fwrr_group { diff --git a/src/cfgparse.c b/src/cfgparse.c index 114d8766f..7e9bea527 100644 --- a/src/cfgparse.c +++ b/src/cfgparse.c @@ -1734,9 +1734,19 @@ int cfg_parse_listen(const char *file, int linenum, char **args, int kwm) return -1; } - if (!strcmp(args[1], "httplog")) + if (!strcmp(args[1], "httplog")) { /* generate a complete HTTP log */ + curproxy->options2 &= ~PR_O2_CLFLOG; curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_REQ | LW_PXID | LW_RESP | LW_BYTES; + if (*(args[2]) != '\0') { + if (!strcmp(args[2], "clf")) { + curproxy->options2 |= PR_O2_CLFLOG; + } else { + Alert("parsing [%s:%d] : keyword '%s' only supports option 'clf'.\n", file, linenum, args[2]); + return -1; + } + } + } else if (!strcmp(args[1], "tcplog")) /* generate a detailed TCP log */ curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_PXID | LW_BYTES; diff --git a/src/proto_http.c b/src/proto_http.c index 0711bdc83..a3948f51f 100644 --- a/src/proto_http.c +++ b/src/proto_http.c @@ -726,6 +726,215 @@ const char sess_set_cookie[8] = "N1I3PD5R"; /* No set-cookie, unknown, Set-Cooki struct pool_head *pool2_requri; struct pool_head *pool2_capture; +void http_sess_clflog(struct session *s) +{ + char pn[INET6_ADDRSTRLEN + strlen(":65535")]; + 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, *h; + char *svid; + struct tm tm; + static char tmpline[MAX_SYSLOG_LEN]; + int hdr; + size_t w; + int t_request; + + prx_log = fe; + err = (s->flags & (SN_ERR_MASK | SN_REDISP)) || + (s->conn_retries != be->conn_retries) || + txn->status >= 500; + + if (s->cli_addr.ss_family == AF_INET) + inet_ntop(AF_INET, + (const void *)&((struct sockaddr_in *)&s->cli_addr)->sin_addr, + pn, sizeof(pn)); + else + inet_ntop(AF_INET6, + (const void *)&((struct sockaddr_in6 *)(&s->cli_addr))->sin6_addr, + pn, sizeof(pn)); + + get_gmtime(s->logs.accept_date.tv_sec, &tm); + + /* FIXME: let's limit ourselves to frontend logging for now. */ + tolog = fe->to_log; + + h = tmpline; + + w = snprintf(h, sizeof(tmpline), + "%s - - [%02d/%s/%04d:%02d:%02d:%02d +0000]", + pn, + tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900, + tm.tm_hour, tm.tm_min, tm.tm_sec); + if (w < 0 || w >= sizeof(tmpline) - (h - tmpline)) + goto trunc; + h += w; + + if (h >= tmpline + sizeof(tmpline) - 4) + goto trunc; + + *(h++) = ' '; + *(h++) = '\"'; + uri = txn->uri ? txn->uri : ""; + h = encode_string(h, tmpline + sizeof(tmpline) - 1, + '#', url_encode_map, uri); + *(h++) = '\"'; + + w = snprintf(h, sizeof(tmpline) - (h - tmpline), " %d %lld", txn->status, s->logs.bytes_out); + if (w < 0 || w >= sizeof(tmpline) - (h - tmpline)) + goto trunc; + h += w; + + if (h >= tmpline + sizeof(tmpline) - 9) + goto trunc; + memcpy(h, " \"-\" \"-\"", 8); + h += 8; + + w = snprintf(h, sizeof(tmpline) - (h - tmpline), + " %d %03d", + (s->cli_addr.ss_family == AF_INET) ? + ntohs(((struct sockaddr_in *)&s->cli_addr)->sin_port) : + ntohs(((struct sockaddr_in6 *)&s->cli_addr)->sin6_port), + (int)s->logs.accept_date.tv_usec/1000); + if (w < 0 || w >= sizeof(tmpline) - (h - tmpline)) + goto trunc; + h += w; + + w = strlen(fe->id); + if (h >= tmpline + sizeof(tmpline) - 4 - w) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + memcpy(h, fe->id, w); + h += w; + *(h++) = '\"'; + + w = strlen(be->id); + if (h >= tmpline + sizeof(tmpline) - 4 - w) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + memcpy(h, be->id, w); + h += w; + *(h++) = '\"'; + + svid = (tolog & LW_SVID) ? + (s->data_source != DATA_SRC_STATS) ? + (s->srv != NULL) ? s->srv->id : "" : "" : "-"; + + w = strlen(svid); + if (h >= tmpline + sizeof(tmpline) - 4 - w) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + memcpy(h, svid, w); + h += w; + *(h++) = '\"'; + + 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); + w = snprintf(h, sizeof(tmpline) - (h - tmpline), + " %d %ld %ld %ld %ld", + t_request, + (s->logs.t_queue >= 0) ? s->logs.t_queue - t_request : -1, + (s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_queue : -1, + (s->logs.t_data >= 0) ? s->logs.t_data - s->logs.t_connect : -1, + s->logs.t_close); + if (w < 0 || w >= sizeof(tmpline) - (h - tmpline)) + goto trunc; + h += w; + + if (h >= tmpline + sizeof(tmpline) - 8) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + *(h++) = sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT]; + *(h++) = sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT]; + *(h++) = (be->options & PR_O_COOK_ANY) ? sess_cookie[(txn->flags & TX_CK_MASK) >> TX_CK_SHIFT] : '-', + *(h++) = (be->options & PR_O_COOK_ANY) ? sess_set_cookie[(txn->flags & TX_SCK_MASK) >> TX_SCK_SHIFT] : '-'; + *(h++) = '\"'; + + w = snprintf(h, sizeof(tmpline) - (h - tmpline), + " %d %d %d %d %d %ld %ld", + actconn, fe->feconn, be->beconn, s->srv ? s->srv->cur_sess : 0, + (s->conn_retries > 0) ? (be->conn_retries - s->conn_retries) : be->conn_retries, + s->logs.srv_queue_size, s->logs.prx_queue_size); + + if (w < 0 || w >= sizeof(tmpline) - (h - tmpline)) + goto trunc; + h += w; + + if (txn->cli_cookie) { + w = strlen(txn->cli_cookie); + if (h >= tmpline + sizeof(tmpline) - 4 - w) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + memcpy(h, txn->cli_cookie, w); + h += w; + *(h++) = '\"'; + } else { + if (h >= tmpline + sizeof(tmpline) - 5) + goto trunc; + memcpy(h, " \"-\"", 4); + h += 4; + } + + if (txn->srv_cookie) { + w = strlen(txn->srv_cookie); + if (h >= tmpline + sizeof(tmpline) - 4 - w) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + memcpy(h, txn->srv_cookie, w); + h += w; + *(h++) = '\"'; + } else { + if (h >= tmpline + sizeof(tmpline) - 5) + goto trunc; + memcpy(h, " \"-\"", 4); + h += 4; + } + + if ((fe->to_log & LW_REQHDR) && txn->req.cap) { + for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { + if (h >= sizeof (tmpline) + tmpline - 4) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + h = encode_string(h, tmpline + sizeof(tmpline) - 2, + '#', hdr_encode_map, txn->req.cap[hdr]); + *(h++) = '\"'; + } + } + + if ((fe->to_log & LW_RSPHDR) && txn->rsp.cap) { + for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { + if (h >= sizeof (tmpline) + tmpline - 4) + goto trunc; + *(h++) = ' '; + *(h++) = '\"'; + h = encode_string(h, tmpline + sizeof(tmpline) - 2, + '#', hdr_encode_map, txn->rsp.cap[hdr]); + *(h++) = '\"'; + } + } + +trunc: + *h = '\0'; + + level = LOG_INFO; + if (err && (fe->options2 & PR_O2_LOGERRORS)) + level = LOG_ERR; + + send_log(prx_log, level, "%s\n", tmpline); + + s->logs.logwait = 0; +} + /* * send a log for the session when we have enough info about it. * Will not log if the frontend has no log defined. @@ -756,6 +965,9 @@ void http_sess_log(struct session *s) return; prx_log = fe; + if (prx_log->options2 & PR_O2_CLFLOG) + return http_sess_clflog(s); + if (s->cli_addr.ss_family == AF_INET) inet_ntop(AF_INET, (const void *)&((struct sockaddr_in *)&s->cli_addr)->sin_addr,