From 66425e31b5216fa5e24d02f28ef25650936a6ae6 Mon Sep 17 00:00:00 2001 From: Willy Tarreau Date: Wed, 25 Jul 2018 06:55:12 +0200 Subject: [PATCH] MINOR: queue: make sure the pendconn is released before logging We'll soon need to rely on the pendconn position at the time of dequeuing to figure the position a stream took in the queue. Usually it's not a problem since pendconn_free() is called once the connection starts, but it will make a difference for failed dequeues (eg: queue timeout reached). Thus it's important to call pendconn_free() before logging in cases we are not certain whether it was already performed, and to call pendconn_unlink() after we know the pendconn will not be used so that we collect the queue state as accurately as possible. As a benefit it will also make the server's and backend's queues count more accurate in these cases. --- src/proto_http.c | 5 +++-- src/stream.c | 14 ++++++++++++++ 2 files changed, 17 insertions(+), 2 deletions(-) diff --git a/src/proto_http.c b/src/proto_http.c index 42c9d1a62..9cbf3edda 100644 --- a/src/proto_http.c +++ b/src/proto_http.c @@ -4403,6 +4403,9 @@ void http_end_txn_clean_session(struct stream *s) s->logs.bytes_in -= ci_data(&s->req); s->logs.bytes_out -= ci_data(&s->res); + /* we may need to know the position in the queue */ + pendconn_free(s); + /* let's do a final log if we need it */ if (!LIST_ISEMPTY(&fe->logformat) && s->logs.logwait && !(s->flags & SF_MONITOR) && @@ -4429,8 +4432,6 @@ void http_end_txn_clean_session(struct stream *s) s->logs.bytes_in = s->req.total = ci_data(&s->req); s->logs.bytes_out = s->res.total = ci_data(&s->res); - pendconn_free(s); - if (objt_server(s->target)) { if (s->flags & SF_CURR_SESS) { s->flags &= ~SF_CURR_SESS; diff --git a/src/stream.c b/src/stream.c index d794c28a9..aa021b0b3 100644 --- a/src/stream.c +++ b/src/stream.c @@ -799,6 +799,7 @@ static void sess_establish(struct stream *s) /* if the user wants to log as soon as possible, without counting * bytes from the server, then this is the right moment. */ if (!LIST_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); } @@ -910,6 +911,9 @@ static void sess_update_stream_int(struct stream *s) s->logs.t_queue = tv_ms_elapsed(&s->logs.tv_accept, &now); + /* we may need to know the position in the queue for logging */ + pendconn_cond_unlink(s->pend_pos); + /* no stream was ever accounted for this server */ si->state = SI_ST_CLO; if (s->srv_error) @@ -950,6 +954,10 @@ static void sess_update_stream_int(struct stream *s) /* ... and timeout expired */ si->exp = TICK_ETERNITY; s->logs.t_queue = tv_ms_elapsed(&s->logs.tv_accept, &now); + + /* we may need to know the position in the queue for logging */ + pendconn_cond_unlink(s->pend_pos); + if (srv) HA_ATOMIC_ADD(&srv->counters.failed_conns, 1); HA_ATOMIC_ADD(&s->be->be_counters.failed_conns, 1); @@ -967,6 +975,10 @@ static void sess_update_stream_int(struct stream *s) /* Connection remains in queue, check if we have to abort it */ if (check_req_may_abort(req, s)) { s->logs.t_queue = tv_ms_elapsed(&s->logs.tv_accept, &now); + + /* we may need to know the position in the queue for logging */ + pendconn_cond_unlink(s->pend_pos); + si->err_type |= SI_ET_QUEUE_ABRT; goto abort_connection; } @@ -2503,6 +2515,8 @@ struct task *process_stream(struct task *t, void *context, unsigned short state) if (!LIST_ISEMPTY(&sess->fe->logformat) && s->logs.logwait && !(s->flags & SF_MONITOR) && (!(sess->fe->options & PR_O_NULLNOLOG) || req->total)) { + /* we may need to know the position in the queue */ + pendconn_free(s); s->do_log(s); }