From: Willy Tarreau Date: Fri, 28 Dec 2012 08:40:16 +0000 (+0100) Subject: BUG/MINOR: log: make log-format, unique-id-format and add-header more independant X-Git-Tag: v1.5-dev17~8 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=d79a3b248eaeb5d5c8f26ad24e5f9a823d122932;p=thirdparty%2Fhaproxy.git BUG/MINOR: log: make log-format, unique-id-format and add-header more independant It happens that all of them call parse_logformat_line() which sets proxy->to_log with a number of flags affecting the line format for all three users. For example, having a unique-id specified disables the default log-format since fe->to_log is tested when the session is established. Similarly, having "option logasap" will cause "+" to be inserted in unique-id or headers referencing some of the fields depending on LW_BYTES. This patch first removes most of the dependency on fe->to_log whenever possible. The first possible cleanup is to stop checking fe->to_log for being null, considering that it always contains at least LW_INIT when any such usage is made of the log-format! Also, some checks are wrong. s->logs.logwait cannot be nulled by "logwait &= ~LW_*" since LW_INIT is always there. This results in getting the wrong log at the end of a request or session when a unique-id or add-header is set, because logwait is still not null but the log-format is not checked. Further cleanups are required. Most LW_* flags should be removed or at least replaced with what they really mean (eg: depend on client-side connection, depend on server-side connection, etc...) and this should only affect logging, not other mechanisms. This patch fixes the default log-format and tries to limit interferences between the log formats, but does not pretend to do more for the moment, since it's the most visible breakage. --- diff --git a/include/types/log.h b/include/types/log.h index 2a3a14791e..66b418dec9 100644 --- a/include/types/log.h +++ b/include/types/log.h @@ -127,8 +127,12 @@ struct logformat_node { #define LOG_OPT_RES_CAP 0x00000010 -/* fields that need to be logged. They appear as flags in session->logs.logwait */ -#define LW_INIT 1 /* date */ +/* Fields that need to be extracted from the incoming connection or request for + * logging or for sending specific header information. They're set in px->to_log + * and appear as flags in session->logs.logwait, which are removed once the + * required information has been collected. + */ +#define LW_INIT 1 /* anything */ #define LW_CLIP 2 /* CLient IP */ #define LW_SVIP 4 /* SerVer IP */ #define LW_SVID 8 /* server ID */ diff --git a/src/cfgparse.c b/src/cfgparse.c index afcf60e6f6..4954e7ace8 100644 --- a/src/cfgparse.c +++ b/src/cfgparse.c @@ -6667,7 +6667,7 @@ out_uri_auth_compat: curproxy->to_log &= ~LW_BYTES; if ((curproxy->mode == PR_MODE_TCP || curproxy->mode == PR_MODE_HTTP) && - (curproxy->cap & PR_CAP_FE) && curproxy->to_log && LIST_ISEMPTY(&curproxy->logsrvs)) { + (curproxy->cap & PR_CAP_FE) && !LIST_ISEMPTY(&curproxy->logformat) && LIST_ISEMPTY(&curproxy->logsrvs)) { Warning("config : log format ignored for %s '%s' since it has no log address.\n", proxy_type_str(curproxy), curproxy->id); err_code |= ERR_WARN; diff --git a/src/frontend.c b/src/frontend.c index a85cccee01..e7779e4858 100644 --- a/src/frontend.c +++ b/src/frontend.c @@ -130,10 +130,10 @@ int frontend_accept(struct session *s) if ((s->fe->mode == PR_MODE_TCP || s->fe->mode == PR_MODE_HTTP) && (!LIST_ISEMPTY(&s->fe->logsrvs))) { - if (likely(s->fe->to_log)) { + if (likely(!LIST_ISEMPTY(&s->fe->logformat))) { /* we have the client ip */ if (s->logs.logwait & LW_CLIP) - if (!(s->logs.logwait &= ~LW_CLIP)) + if (!(s->logs.logwait &= ~(LW_CLIP|LW_INIT))) s->do_log(s); } else { diff --git a/src/log.c b/src/log.c index b733811d3f..b13872f28c 100644 --- a/src/log.c +++ b/src/log.c @@ -854,7 +854,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis struct proxy *fe = s->fe; struct proxy *be = s->be; struct http_txn *txn = &s->txn; - int tolog; char *uri; const char *svid; struct tm tm; @@ -867,21 +866,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis struct logformat_node *tmp; /* FIXME: let's limit ourselves to frontend logging for now. */ - tolog = fe->to_log; - - if (!(tolog & LW_SVID)) - svid = "-"; - else switch (obj_type(s->target)) { - case OBJ_TYPE_SERVER: - svid = objt_server(s->target)->id; - break; - case OBJ_TYPE_APPLET: - svid = objt_applet(s->target)->name; - break; - default: - svid = ""; - break; - } t_request = -1; if (tv_isge(&s->logs.tv_request, &s->logs.tv_accept)) @@ -1133,7 +1117,17 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis break; case LOG_FMT_SERVER: // %s - src = (char *)svid; + switch (obj_type(s->target)) { + case OBJ_TYPE_SERVER: + src = objt_server(s->target)->id; + break; + case OBJ_TYPE_APPLET: + src = objt_applet(s->target)->name; + break; + default: + src = ""; + break; + } ret = lf_text(tmplog, src, dst + maxsize - tmplog, tmp); if (ret == NULL) goto out; @@ -1177,7 +1171,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis break; case LOG_FMT_TT: // %Tt - if (!(tolog & LW_BYTES)) + if (!(fe->to_log & LW_BYTES)) LOGCHAR('+'); ret = ltoa_o(s->logs.t_close, tmplog, dst + maxsize - tmplog); if (ret == NULL) @@ -1195,7 +1189,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis break; case LOG_FMT_BYTES: // %B - if (!(tolog & LW_BYTES)) + if (!(fe->to_log & LW_BYTES)) LOGCHAR('+'); ret = lltoa(s->logs.bytes_out, tmplog, dst + maxsize - tmplog); if (ret == NULL) @@ -1205,8 +1199,6 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis break; case LOG_FMT_BYTES_UP: // %U - if (!(tolog & LW_BYTES)) - LOGCHAR('+'); ret = lltoa(s->logs.bytes_in, tmplog, dst + maxsize - tmplog); if (ret == NULL) goto out; @@ -1311,7 +1303,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis case LOG_FMT_HDRREQUEST: // %hr /* request header */ - if (fe->to_log & LW_REQHDR && txn->req.cap) { + if (fe->nb_req_cap && txn->req.cap) { if (tmp->options & LOG_OPT_QUOTE) LOGCHAR('"'); LOGCHAR('{'); @@ -1337,7 +1329,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis case LOG_FMT_HDRREQUESTLIST: // %hrl /* request header list */ - if (fe->to_log & LW_REQHDR && txn->req.cap) { + if (fe->nb_req_cap && txn->req.cap) { for (hdr = 0; hdr < fe->nb_req_cap; hdr++) { if (hdr > 0) LOGCHAR(' '); @@ -1361,8 +1353,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis case LOG_FMT_HDRRESPONS: // %hs /* response header */ - if (fe->to_log & LW_RSPHDR && - txn->rsp.cap) { + if (fe->nb_rsp_cap && txn->rsp.cap) { if (tmp->options & LOG_OPT_QUOTE) LOGCHAR('"'); LOGCHAR('{'); @@ -1386,7 +1377,7 @@ int build_logline(struct session *s, char *dst, size_t maxsize, struct list *lis case LOG_FMT_HDRRESPONSLIST: // %hsl /* response header list */ - if (fe->to_log & LW_RSPHDR && txn->rsp.cap) { + if (fe->nb_rsp_cap && txn->rsp.cap) { for (hdr = 0; hdr < fe->nb_rsp_cap; hdr++) { if (hdr > 0) LOGCHAR(' '); diff --git a/src/proto_http.c b/src/proto_http.c index 69ef88136f..be26442446 100644 --- a/src/proto_http.c +++ b/src/proto_http.c @@ -2545,16 +2545,15 @@ int http_wait_for_request(struct session *s, struct channel *req, int an_bit) memcpy(txn->uri, req->buf->p, urilen); txn->uri[urilen] = 0; - if (!(s->logs.logwait &= ~LW_REQ)) + if (!(s->logs.logwait &= ~(LW_REQ|LW_INIT))) s->do_log(s); } else { Alert("HTTP logging : out of memory.\n"); } } - if (!LIST_ISEMPTY(&s->fe->format_unique_id)) { - s->unique_id = pool_alloc2(pool2_uniqueid); - } + if (!LIST_ISEMPTY(&s->fe->format_unique_id)) + s->unique_id = pool_alloc2(pool2_uniqueid); /* 4. We may have to convert HTTP/0.9 requests to HTTP/1.0 */ if (unlikely(msg->sl.rq.v_l == 0) && !http_upgrade_v09_to_v10(txn)) @@ -4165,7 +4164,7 @@ void http_end_txn_clean_session(struct session *s) s->logs.bytes_out -= s->rep->buf->i; /* let's do a final log if we need it */ - if (s->logs.logwait && + if (!LIST_ISEMPTY(&s->fe->logformat) && s->logs.logwait && !(s->flags & SN_MONITOR) && (!(s->fe->options & PR_O_NULLNOLOG) || s->req->total)) { s->do_log(s); @@ -5668,7 +5667,7 @@ int http_process_res_common(struct session *t, struct channel *rep, int an_bit, * bytes from the server, then this is the right moment. We have * to temporarily assign bytes_out to log what we currently have. */ - if (t->fe->to_log && !(t->logs.logwait & LW_BYTES)) { + if (!LIST_ISEMPTY(&t->fe->logformat) && !(t->logs.logwait & LW_BYTES)) { t->logs.t_close = t->logs.t_data; /* to get a valid end date */ t->logs.bytes_out = txn->rsp.eoh; t->do_log(t); diff --git a/src/session.c b/src/session.c index 7ef518d4b0..3dc30d5eca 100644 --- a/src/session.c +++ b/src/session.c @@ -944,7 +944,7 @@ static void sess_establish(struct session *s, struct stream_interface *si) if (s->be->mode == PR_MODE_TCP) { /* let's allow immediate data connection in this case */ /* if the user wants to log as soon as possible, without counting * bytes from the server, then this is the right moment. */ - if (s->fe->to_log && !(s->logs.logwait & LW_BYTES)) { + if (!LIST_ISEMPTY(&s->fe->logformat) && !(s->logs.logwait & LW_BYTES)) { s->logs.t_close = s->logs.t_connect; /* to get a valid end date */ s->do_log(s); } @@ -2472,7 +2472,7 @@ struct task *process_session(struct task *t) } /* let's do a final log if we need it */ - if (s->logs.logwait && + if (!LIST_ISEMPTY(&s->fe->logformat) && s->logs.logwait && !(s->flags & SN_MONITOR) && (!(s->fe->options & PR_O_NULLNOLOG) || s->req->total)) { s->do_log(s);