diff --git a/src/cli.c b/src/cli.c index e2ae2eb70..1d80b7602 100644 --- a/src/cli.c +++ b/src/cli.c @@ -3112,6 +3112,8 @@ int pcli_wait_for_response(struct stream *s, struct channel *rep, int an_bit) } if (s->scb->flags & (SC_FL_ABRT_DONE|SC_FL_EOS)) { + uint8_t do_log = 0; + /* stream cleanup */ pcli_write_prompt(s); @@ -3145,7 +3147,14 @@ int pcli_wait_for_response(struct stream *s, struct channel *rep, int an_bit) pendconn_free(s); /* let's do a final log if we need it */ - if (!lf_expr_isempty(&fe->logformat) && s->logs.logwait && + if (fe->to_log == LW_LOGSTEPS) { + if (log_orig_proxy(LOG_ORIG_TXN_CLOSE, fe)) + do_log = 1; + } + else if (!lf_expr_isempty(&fe->logformat) && s->logs.logwait) + do_log = 1; + + if (do_log && !(s->flags & SF_MONITOR) && (!(fe->options & PR_O_NULLNOLOG) || s->req.total)) { s->do_log(s, log_orig(LOG_ORIG_TXN_CLOSE, LOG_ORIG_FL_NONE)); diff --git a/src/frontend.c b/src/frontend.c index 3d18db94a..22270f287 100644 --- a/src/frontend.c +++ b/src/frontend.c @@ -55,7 +55,11 @@ int frontend_accept(struct stream *s) if ((fe->mode == PR_MODE_TCP || fe->mode == PR_MODE_HTTP) && (!LIST_ISEMPTY(&fe->loggers))) { - if (likely(!lf_expr_isempty(&fe->logformat))) { + if (fe->to_log == LW_LOGSTEPS) { + if (log_orig_proxy(LOG_ORIG_TXN_ACCEPT, fe)) + s->do_log(s, log_orig(LOG_ORIG_TXN_ACCEPT, LOG_ORIG_FL_NONE)); + } + else if (likely(!lf_expr_isempty(&fe->logformat))) { /* we have the client ip */ if (s->logs.logwait & LW_CLIP) if (!(s->logs.logwait &= ~(LW_CLIP|LW_INIT))) diff --git a/src/http_ana.c b/src/http_ana.c index 175c01cba..a8d1b18fc 100644 --- a/src/http_ana.c +++ b/src/http_ana.c @@ -82,6 +82,7 @@ static int http_reply_100_continue(struct stream *s); */ int http_wait_for_request(struct stream *s, struct channel *req, int an_bit) { + uint8_t do_log = 0; /* * We will analyze a complete HTTP request to check the its syntax. @@ -264,7 +265,20 @@ int http_wait_for_request(struct stream *s, struct channel *req, int an_bit) * Note: we cannot log anymore if the request has been * classified as invalid. */ - if (unlikely(s->logs.logwait & LW_REQ)) { + if (unlikely(sess->fe->to_log == LW_LOGSTEPS)) { + if (log_orig_proxy(LOG_ORIG_TXN_REQUEST, sess->fe)) + do_log = 1; /* forced log (through "log-steps") */ + } + else if (unlikely(s->logs.logwait & LW_REQ)) { + /* default behavior when log-steps isn't specified: + * don't log systematically, but only if conditions are + * met, ie: not log emitted yet for this txn, all data available + * (unless "option logasap" is used) + */ + do_log = 2; + } + + if (do_log) { /* we have a complete HTTP request that we must log */ if ((txn->uri = pool_alloc(pool_head_requri)) != NULL) { size_t len; @@ -272,7 +286,7 @@ int http_wait_for_request(struct stream *s, struct channel *req, int an_bit) len = http_fmt_req_line(sl, txn->uri, global.tune.requri_len - 1); txn->uri[len] = 0; - if (!(s->logs.logwait &= ~(LW_REQ|LW_INIT))) + if (do_log == 1 || !(s->logs.logwait &= ~(LW_REQ|LW_INIT))) s->do_log(s, log_orig(LOG_ORIG_TXN_REQUEST, LOG_ORIG_FL_NONE)); } else { ha_alert("HTTP logging : out of memory.\n"); @@ -1682,6 +1696,7 @@ int http_process_res_common(struct stream *s, struct channel *rep, int an_bit, s struct htx *htx; struct proxy *cur_proxy; enum rule_result ret = HTTP_RULE_RES_CONT; + uint8_t do_log = 0; if (unlikely(msg->msg_state < HTTP_MSG_BODY)) /* we need more data */ return 0; @@ -1904,11 +1919,18 @@ int http_process_res_common(struct stream *s, struct channel *rep, int an_bit, s rep->analysers &= ~AN_RES_FLT_XFER_DATA; rep->analysers |= AN_RES_HTTP_XFER_BODY; + if (sess->fe->to_log == LW_LOGSTEPS) { + if (log_orig_proxy(LOG_ORIG_TXN_RESPONSE, sess->fe)) + do_log = 1; + } + else if ((!lf_expr_isempty(&sess->fe->logformat) && !(s->logs.logwait & LW_BYTES))) + do_log = 1; + /* if the user wants to log as soon as possible, without counting * bytes from the server, then this is the right moment. We have * to temporarily assign bytes_out to log what we currently have. */ - if (!lf_expr_isempty(&sess->fe->logformat) && !(s->logs.logwait & LW_BYTES)) { + if (do_log) { s->logs.t_close = s->logs.t_data; /* to get a valid end date */ s->logs.bytes_out = htx->data; s->do_log(s, log_orig(LOG_ORIG_TXN_RESPONSE, LOG_ORIG_FL_NONE)); diff --git a/src/stream.c b/src/stream.c index f955b8129..9b48e7d78 100644 --- a/src/stream.c +++ b/src/stream.c @@ -896,6 +896,7 @@ void back_establish(struct stream *s) struct connection *conn = sc_conn(s->scb); struct channel *req = &s->req; struct channel *rep = &s->res; + uint8_t do_log = 0; DBG_TRACE_ENTER(STRM_EV_STRM_PROC|STRM_EV_CS_ST, s); /* First, centralize the timers information, and clear any irrelevant @@ -916,19 +917,28 @@ void back_establish(struct stream *s) if (objt_server(s->target)) health_adjust(__objt_server(s->target), HANA_STATUS_L4_OK); + if (strm_fe(s)->to_log == LW_LOGSTEPS) { + if (log_orig_proxy(LOG_ORIG_TXN_CONNECT, strm_fe(s))) + do_log = 1; + } + if (!IS_HTX_STRM(s)) { /* 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 (!lf_expr_isempty(&strm_fe(s)->logformat) && !(s->logs.logwait & LW_BYTES)) { - /* note: no pend_pos here, session is established */ - s->logs.t_close = s->logs.t_connect; /* to get a valid end date */ - s->do_log(s, log_orig(LOG_ORIG_TXN_CONNECT, LOG_ORIG_FL_NONE)); - } + if (strm_fe(s)->to_log != LW_LOGSTEPS && + !lf_expr_isempty(&strm_fe(s)->logformat) && !(s->logs.logwait & LW_BYTES)) + do_log = 1; } else { s->scb->flags |= SC_FL_RCV_ONCE; /* a single read is enough to get response headers */ } + if (do_log) { + /* note: no pend_pos here, session is established */ + s->logs.t_close = s->logs.t_connect; /* to get a valid end date */ + s->do_log(s, log_orig(LOG_ORIG_TXN_CONNECT, LOG_ORIG_FL_NONE)); + } + rep->analysers |= strm_fe(s)->fe_rsp_ana | s->be->be_rsp_ana; se_have_more_data(s->scb->sedesc); @@ -2564,6 +2574,8 @@ struct task *process_stream(struct task *t, void *context, unsigned int state) } if (!(s->flags & SF_IGNORE)) { + uint8_t do_log = 0; + s->logs.t_close = ns_to_ms(now_ns - s->logs.accept_ts); stream_process_counters(s); @@ -2586,7 +2598,14 @@ struct task *process_stream(struct task *t, void *context, unsigned int state) } /* let's do a final log if we need it */ - if (!lf_expr_isempty(&sess->fe->logformat) && s->logs.logwait && + if (sess->fe->to_log == LW_LOGSTEPS) { + if (log_orig_proxy(LOG_ORIG_TXN_CLOSE, sess->fe)) + do_log = 1; + } + else if (!lf_expr_isempty(&sess->fe->logformat) && s->logs.logwait) + do_log = 1; + + if (do_log && !(s->flags & SF_MONITOR) && (!(sess->fe->options & PR_O_NULLNOLOG) || req->total)) { /* we may need to know the position in the queue */