[BUG] queue management: wake oldest request in queues

When a server terminates a connection, the next session in its
own queue was immediately processed. Because of this, if all
server queues are always filled, then no new anonymous request
will be processed. Consider oldest request between global and
server queues to choose from which to pick the request.

An improvement over this will consist in adding a configurable
offset when comparing expiration dates, so that cookie-less
requests can get either less or more priority.

include/types/session.h

@@ -103,7 +103,7 @@ struct session {
 	struct {
 		int logwait;			/* log fields waiting to be collected : LW_* */
 		struct timeval tv_accept;	/* date of the accept() (beginning of the session) */
-		long  t_request;		/* delay before the end of the request arrives, -1 if never occurs */
+		struct timeval tv_request;	/* date the request arrives, {0,0} if never occurs */
 		long  t_queue;			/* delay before the session gets out of the connect queue, -1 if never occurs */
 		long  t_connect;		/* delay before the connect() to the server succeeds, -1 if never occurs */
 		long  t_data;			/* delay before the first data byte from the server ... */

src/client.c

@@ -202,7 +202,7 @@ int event_accept(int fd) {
 			s->logs.logwait = p->to_log;
 
 		s->logs.tv_accept = now;
-		s->logs.t_request = -1;
+		tv_zero(&s->logs.tv_request);
 		s->logs.t_queue = -1;
 		s->logs.t_connect = -1;
 		s->logs.t_data = -1;

src/proto_http.c

@@ -756,6 +756,7 @@ static void http_sess_log(struct session *s)
 	char *svid;
 	struct tm tm;
 	static char tmpline[MAX_SYSLOG_LEN];
+	int t_request;
 	int hdr;
 
 	if (fe->logfac1 < 0 && fe->logfac2 < 0)
@@ -821,6 +822,10 @@ static void http_sess_log(struct session *s)
 		(s->data_source != DATA_SRC_STATS) ?
 		(s->srv != NULL) ? s->srv->id : "<NOSRV>" : "<STATS>" : "-";
 
+	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);
+
 	send_log(prx_log, LOG_INFO,
 		 "%s:%d [%02d/%s/%04d:%02d:%02d:%02d.%03d]"
 		 " %s %s/%s %d/%d/%d/%d/%s%d %d %s%lld"
@@ -832,8 +837,8 @@ static void http_sess_log(struct session *s)
 		 tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900,
 		 tm.tm_hour, tm.tm_min, tm.tm_sec, s->logs.tv_accept.tv_usec/1000,
 		 fe->id, be->id, svid,
-		 s->logs.t_request,
-		 (s->logs.t_queue >= 0) ? s->logs.t_queue - s->logs.t_request : -1,
+		 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,
 		 (tolog & LW_BYTES) ? "" : "+", s->logs.t_close,
@@ -1884,7 +1889,7 @@ int process_cli(struct session *t)
 
 					txn->status = rule->code;
 					/* let's log the request time */
-					t->logs.t_request = tv_ms_elapsed(&t->logs.tv_accept, &now);
+					t->logs.tv_request = now;
 					client_retnclose(t, &rdr);
 					goto return_prx_cond;
 				}
@@ -1899,7 +1904,7 @@ int process_cli(struct session *t)
 				if (ret) {
 					txn->status = 403;
 					/* let's log the request time */
-					t->logs.t_request = tv_ms_elapsed(&t->logs.tv_accept, &now);
+					t->logs.tv_request = now;
 					client_retnclose(t, error_message(t, HTTP_ERR_403));
 					goto return_prx_cond;
 				}
@@ -1928,7 +1933,7 @@ int process_cli(struct session *t)
 				/* no need to go further */
 				txn->status = 403;
 				/* let's log the request time */
-				t->logs.t_request = tv_ms_elapsed(&t->logs.tv_accept, &now);
+				t->logs.tv_request = now;
 				client_retnclose(t, error_message(t, HTTP_ERR_403));
 				goto return_prx_cond;
 			}
@@ -2238,7 +2243,7 @@ int process_cli(struct session *t)
 		t->cli_state = CL_STDATA;
 		req->rlim = req->data + BUFSIZE; /* no more rewrite needed */
 
-		t->logs.t_request = tv_ms_elapsed(&t->logs.tv_accept, &now);
+		t->logs.tv_request = now;
 
 		if (!tv_isset(&t->fe->timeout.client) ||
 		    (t->srv_state < SV_STDATA && tv_isset(&t->be->timeout.server))) {
@@ -5162,7 +5167,7 @@ int stats_check_uri_auth(struct session *t, struct proxy *backend)
 	 */
 	t->cli_state = CL_STSHUTR;
 	t->req->rlim = t->req->data + BUFSIZE; /* no more rewrite needed */
-	t->logs.t_request = tv_ms_elapsed(&t->logs.tv_accept, &now);
+	t->logs.tv_request = now;
 	t->data_source = DATA_SRC_STATS;
 	t->data_state  = DATA_ST_INIT;
 	produce_content(t);

src/queue.c

@@ -91,21 +91,29 @@ void process_srv_queue(struct task *t, struct timeval *next)
 /* Detaches the next pending connection from either a server or a proxy, and
  * returns its associated session. If no pending connection is found, NULL is
  * returned. Note that neither <srv> nor <px> can be NULL.
+ * Priority is given to the oldest request in the queue if both <srv> and <px>
+ * have pending requests. This ensures that no request will be left unserved.
  */
 struct session *pendconn_get_next_sess(struct server *srv, struct proxy *px)
 {
-	struct pendconn *p;
+	struct pendconn *ps, *pp;
 	struct session *sess;
 
-	p = pendconn_from_srv(srv);
-	if (!p) {
-		p = pendconn_from_px(px);
-		if (!p)
+	ps = pendconn_from_srv(srv);
+	pp = pendconn_from_px(px);
+	/* we want to get the definitive pendconn in <ps> */
+	if (!pp) {
+		if (!ps)
 			return NULL;
-		p->sess->srv = srv;
+	} else {
+		/* pendconn exists in the proxy queue */
+		if (!ps || tv_islt(&pp->sess->logs.tv_request, &ps->sess->logs.tv_request)) {
+			ps = pp;
+			ps->sess->srv = srv;
+		}
 	}
-	sess = p->sess;
-	pendconn_free(p);
+	sess = ps->sess;
+	pendconn_free(ps);
 	return sess;
 }