[MEDIUM]: Count retries and redispatches also for servers, fix redistribute_pending, extend logs, %d->%u cleanup

This patch extends a little previously added functionality to also
count retries and redispatches for servers. Now it is possible to know
which server causes redispatches as it is not always the same that takes
most retries.

While working with the code I found that redistribute_pending() does not increment
srv->redispatches && be->redispatches. I don't know how to test it but
I think the fix is correct. If not I can withdraw it.

I also extended logs to show how many retries were done and if redispatching
was necessary ('+'). I'm using an additional session flag SN_REDISP to match
redispatched connections. I had to rearrange all defines in session.h to make
more room for it.

The documentation about logs was also fixed a little (sorry, english only),
as current version uses totally different format. BTW: examples are still
outdated, maybe next time...

Finally, I changed %d -> %u for retries/redispatches as those variables
are declared as unsigned.
This commit is contained in:
Krzysztof Piotr Oledzki 2008-01-06 16:36:16 +01:00 committed by Willy Tarreau
parent 98937b8757
commit 25b501a6b1
9 changed files with 133 additions and 60 deletions

View File

@ -1924,6 +1924,33 @@ no option logasap
logging.
option redispatch
no option redispatch
Enable or disable session redistribution in case of connection failure
May be used in sections: defaults | frontend | listen | backend
yes | no | yes | yes
Arguments: none
In HTTP mode, if a server designated by a cookie is down, clients may
definitely stick to it because they cannot flush the cookie, so they will not
be able to access the service anymore.
Specifying "option redispatch" will allow the proxy to break their
persistence and redistribute them to a working server.
It also allows to retry last connection to another server in case of multiple
connection failures. Of course, it requires having "retries" set to a nonzero
value.
This form is the preferred form, which replaces both the "redispatch" and
"redisp" keywords.
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.
See also : "redispatch", "retries"
option srvtcpka
no option srvtcpka
Enable or disable the sending of TCP keepalive packets on the server side
@ -1995,6 +2022,30 @@ option tcpka
See also : "option clitcpka", "option srvtcpka"
redisp (deprecated)
redispatch (deprecated)
Enable or disable session redistribution in case of connection failure
May be used in sections: defaults | frontend | listen | backend
yes | no | yes | yes
Arguments: none
In HTTP mode, if a server designated by a cookie is down, clients may
definitely stick to it because they cannot flush the cookie, so they will not
be able to access the service anymore.
Specifying "redispatch" will allow the proxy to break their persistence and
redistribute them to a working server.
It also allows to retry last connection to another server in case of multiple
connection failures. Of course, it requires having "retries" set to a nonzero
value.
This form is deprecated, do not use it in any new configuration, use the new
"option redispatch" instead.
See also : "option redispatch"
timeout client <timeout>
timeout clitimeout <timeout> (deprecated)
Set the maximum inactivity time on the client side.

View File

@ -1679,10 +1679,10 @@ Example of HTTP logging :
option dontlognull
log 192.168.2.200 local3
>>> haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57] relais-http Srv1 9/0/7/147/723 200 243 - - ---- 2/3/3 0/0 "HEAD / HTTP/1.0"
>>> haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57] relais-http Srv1 9/0/7/147/723 200 243 - - ---- 34/34/15/8/3 0/0 "HEAD / HTTP/1.0"
More complete example
haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31] relais-http Srv1 3183/-1/-1/-1/11215 503 0 - - SC-- 137/202/205 0/0 {w.ods.org|Mozilla} {} "HEAD / HTTP/1.0"
haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31] relais-http Srv1 3183/-1/-1/-1/11215 503 0 - - SC-- 205/202/150/137/+4 0/0 {w.ods.org|Mozilla} {} "HEAD / HTTP/1.0"
Field Format Example
@ -1697,7 +1697,7 @@ More complete example
9 captured_request_cookie -
10 captured_response_cookie -
11 termination_state SC--
12 srv_conn '/' listener_conn '/' process_conn 137/202/205
12 actconn '/' feconn '/' beconn '/' srv_conn '/' retries 205/202/150/137/+4
13 position in srv_queue / listener_queue 0/0
14 '{' captured_request_headers '}' {w.ods.org|Mozilla}
15 '{' captured_response_headers '}' {}
@ -1706,6 +1706,10 @@ More complete example
Note for log parsers: the URI is ALWAYS the end of the line starting with the
first double quote '"'.
The retries count may have additional '+' sign means that the connection had been
redispatched from one server to another shortly before retries limit (retries 4
in above example) was depleted.
The problem when logging at end of connection is that you have no clue about
what is happening during very long sessions. To workaround this problem, a
new option 'logasap' has been introduced in 1.1.28/1.2.1. When specified, the
@ -1716,7 +1720,7 @@ case, the number of bytes reported is the number of header bytes sent to the
client.
In order to avoid confusion with normal logs, the total time field and the
number of bytes are prefixed with a '+' sign which mean that real numbers are
number of bytes are prefixed with a '+' sign which means that real numbers are
certainly bigger.
Example :
@ -1729,7 +1733,7 @@ Example :
option logasap
log 192.168.2.200 local3
>>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17] relais-http Srv1 9/10/7/14/+30 200 +243 - - ---- 1/1/3 1/0 "GET /image.iso HTTP/1.0"
>>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17] relais-http Srv1 9/10/7/14/+30 200 +243 - - ---- 3/1/1/1/0 1/0 "GET /image.iso HTTP/1.0"
4.2.3) Timing events
--------------------

View File

@ -113,7 +113,7 @@ struct server {
time_t last_change; /* last time, when the state was changed */
unsigned failed_conns, failed_resp; /* failed connect() and responses */
unsigned retries; /* retried connections */
unsigned retries, redispatches; /* retried and redispatched connections */
unsigned failed_secu; /* blocked responses because of security concerns */
unsigned cum_sess; /* cumulated number of sessions really sent to this server */
unsigned cum_lbconn; /* cumulated number of sessions directed by load balancing */

View File

@ -39,7 +39,7 @@
#include <types/task.h>
/* various session flags, bits values 0x01 to 0x20 (shift 0) */
/* various session flags, bits values 0x01 to 0x100 (shift 0) */
#define SN_DIRECT 0x00000001 /* connection made on the server matching the client cookie */
#define SN_ASSIGNED 0x00000002 /* no need to assign a server to this session */
#define SN_ADDR_SET 0x00000004 /* this session's server address has been set */
@ -48,36 +48,40 @@
#define SN_MONITOR 0x00000020 /* this session comes from a monitoring system */
#define SN_SELF_GEN 0x00000040 /* the proxy generates data for the client (eg: stats) */
#define SN_FRT_ADDR_SET 0x00000080 /* set if the frontend address has been filled */
/* session termination conditions, bits values 0x100 to 0x700 (0-7 shift 8) */
#define SN_ERR_NONE 0x00000000
#define SN_ERR_CLITO 0x00000100 /* client time-out */
#define SN_ERR_CLICL 0x00000200 /* client closed (read/write error) */
#define SN_ERR_SRVTO 0x00000300 /* server time-out, connect time-out */
#define SN_ERR_SRVCL 0x00000400 /* server closed (connect/read/write error) */
#define SN_ERR_PRXCOND 0x00000500 /* the proxy decided to close (deny...) */
#define SN_ERR_RESOURCE 0x00000600 /* the proxy encountered a lack of a local resources (fd, mem, ...) */
#define SN_ERR_INTERNAL 0x00000700 /* the proxy encountered an internal error */
#define SN_ERR_MASK 0x00000700 /* mask to get only session error flags */
#define SN_ERR_SHIFT 8 /* bit shift */
#define SN_REDISP 0x00000100 /* set if this session was redispatched from one server to another */
/* unused: 0x00000200 */
/* unused: 0x00000400 */
/* unused: 0x00000800 */
/* session state at termination, bits values 0x1000 to 0x7000 (0-7 shift 12) */
#define SN_FINST_R 0x00001000 /* session ended during client request */
#define SN_FINST_C 0x00002000 /* session ended during server connect */
#define SN_FINST_H 0x00003000 /* session ended during server headers */
#define SN_FINST_D 0x00004000 /* session ended during data phase */
#define SN_FINST_L 0x00005000 /* session ended while pushing last data to client */
#define SN_FINST_Q 0x00006000 /* session ended while waiting in queue for a server slot */
#define SN_FINST_T 0x00007000 /* session ended tarpitted */
#define SN_FINST_MASK 0x00007000 /* mask to get only final session state flags */
#define SN_FINST_SHIFT 12 /* bit shift */
/* session termination conditions, bits values 0x1000 to 0x7000 (0-7 shift 12) */
#define SN_ERR_NONE 0x00000000
#define SN_ERR_CLITO 0x00001000 /* client time-out */
#define SN_ERR_CLICL 0x00002000 /* client closed (read/write error) */
#define SN_ERR_SRVTO 0x00003000 /* server time-out, connect time-out */
#define SN_ERR_SRVCL 0x00004000 /* server closed (connect/read/write error) */
#define SN_ERR_PRXCOND 0x00005000 /* the proxy decided to close (deny...) */
#define SN_ERR_RESOURCE 0x00006000 /* the proxy encountered a lack of a local resources (fd, mem, ...) */
#define SN_ERR_INTERNAL 0x00007000 /* the proxy encountered an internal error */
#define SN_ERR_MASK 0x00007000 /* mask to get only session error flags */
#define SN_ERR_SHIFT 12 /* bit shift */
/* unused: 0x00008000 */
/* session state at termination, bits values 0x10000 to 0x70000 (0-7 shift 16) */
#define SN_FINST_R 0x00010000 /* session ended during client request */
#define SN_FINST_C 0x00020000 /* session ended during server connect */
#define SN_FINST_H 0x00030000 /* session ended during server headers */
#define SN_FINST_D 0x00040000 /* session ended during data phase */
#define SN_FINST_L 0x00050000 /* session ended while pushing last data to client */
#define SN_FINST_Q 0x00060000 /* session ended while waiting in queue for a server slot */
#define SN_FINST_T 0x00070000 /* session ended tarpitted */
#define SN_FINST_MASK 0x00070000 /* mask to get only final session state flags */
#define SN_FINST_SHIFT 16 /* bit shift */
/* unused: 0x00080000 */
/* Note: those flags must move to another place */
#define SN_STAT_HIDEDWN 0x00010000 /* hide 'down' servers in the stats page */
#define SN_STAT_NORFRSH 0x00020000 /* do not automatically refresh the stats page */
#define SN_STAT_FMTCSV 0x00040000 /* dump the stats in CSV format instead of HTML */
#define SN_STAT_HIDEDWN 0x00100000 /* hide 'down' servers in the stats page */
#define SN_STAT_NORFRSH 0x00200000 /* do not automatically refresh the stats page */
#define SN_STAT_FMTCSV 0x00400000 /* dump the stats in CSV format instead of HTML */
/* WARNING: if new fields are added, they must be initialized in event_accept()

View File

@ -1425,13 +1425,15 @@ int srv_retryable_connect(struct session *t)
if (may_dequeue_tasks(t->srv, t->be))
task_wakeup(t->srv->queue_mgt);
if (t->srv)
if (t->srv) {
t->srv->cum_sess++;
if (t->srv)
t->srv->failed_conns++;
t->srv->redispatches++;
}
t->be->redispatches++;
t->flags &= ~(SN_DIRECT | SN_ASSIGNED | SN_ADDR_SET);
t->flags |= SN_REDISP;
t->srv = NULL; /* it's left to the dispatcher to choose a server */
http_flush_cookie_flags(&t->txn);
return 0;

View File

@ -71,7 +71,13 @@ static int redistribute_pending(struct server *s)
/* The REDISP option was specified. We will ignore
* cookie and force to balance or use the dispatcher.
*/
sess->srv->redispatches++;
sess->be->redispatches++;
sess->flags &= ~(SN_DIRECT | SN_ASSIGNED | SN_ADDR_SET);
sess->flags |= SN_REDISP;
sess->srv = NULL; /* it's left to the dispatcher to choose a server */
http_flush_cookie_flags(&sess->txn);
pendconn_free(pc);

View File

@ -779,7 +779,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
/* errors : request, connect, response */
"<td align=right></td><td align=right>%d</td><td align=right>%d</td>\n"
/* warnings: retries, redispatches */
"<td align=right>%d</td><td align=right></td>"
"<td align=right>%u</td><td align=right>%u</td>"
"",
(sv->state & SRV_BACKUP) ? "backup" : "active",
sv_state, sv->id,
@ -789,7 +789,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
sv->bytes_in, sv->bytes_out,
sv->failed_secu,
sv->failed_conns, sv->failed_resp,
sv->retries);
sv->retries, sv->redispatches);
/* status */
chunk_printf(&msg, sizeof(trash), "<td nowrap>");
@ -856,7 +856,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
/* errors : request, connect, response */
",%d,%d,"
/* warnings: retries, redispatches */
"%d,,"
"%u,%u,"
"",
px->id, sv->id,
sv->nbpend, sv->nbpend_max,
@ -864,7 +864,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
sv->bytes_in, sv->bytes_out,
sv->failed_secu,
sv->failed_conns, sv->failed_resp,
sv->retries);
sv->retries, sv->redispatches);
/* status */
chunk_printf(&msg, sizeof(trash),
@ -940,7 +940,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
/* errors : request, connect, response */
"<td align=right></td><td align=right>%d</td><td align=right>%d</td>\n"
/* warnings: retries, redispatches */
"<td align=right>%d</td><td align=right>%d</td>"
"<td align=right>%u</td><td align=right>%u</td>"
/* backend status: reflect backend status (up/down): we display UP
* if the backend has known working servers or if it has no server at
* all (eg: for stats). Then we display the total weight, number of
@ -982,7 +982,7 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri,
/* errors : request, connect, response */
",%d,%d,"
/* warnings: retries, redispatches */
"%d,%d,"
"%u,%u,"
/* backend status: reflect backend status (up/down): we display UP
* if the backend has known working servers or if it has no server at
* all (eg: for stats). Then we display the total weight, number of

View File

@ -356,7 +356,7 @@ void tcp_sess_log(struct session *s)
send_log(prx_log, LOG_INFO, "%s:%d [%02d/%s/%04d:%02d:%02d:%02d.%03d]"
" %s %s/%s %d/%d/%s%d %s%lld"
" %c%c %d/%d/%d/%d %d/%d\n",
" %c%c %d/%d/%d/%d/%s%u %d/%d\n",
pn,
(s->cli_addr.ss_family == AF_INET) ?
ntohs(((struct sockaddr_in *)&s->cli_addr)->sin_port) :
@ -371,6 +371,8 @@ void tcp_sess_log(struct session *s)
sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT],
sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT],
actconn, fe->feconn, be->beconn, s->srv ? s->srv->cur_sess : 0,
(s->flags & SN_REDISP)?"+":"",
(s->conn_retries>0)?(be->conn_retries - s->conn_retries):be->conn_retries,
s->logs.srv_queue_size, s->logs.prx_queue_size);
s->logs.logwait = 0;

View File

@ -770,7 +770,7 @@ static void http_sess_log(struct session *s)
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"
" %s %s %c%c%c%c %d/%d/%d/%d %d/%d%s\n",
" %s %s %c%c%c%c %d/%d/%d/%d/%s%u %d/%d%s\n",
pn,
(s->cli_addr.ss_family == AF_INET) ?
ntohs(((struct sockaddr_in *)&s->cli_addr)->sin_port) :
@ -792,6 +792,8 @@ static void http_sess_log(struct session *s)
(be->options & PR_O_COOK_ANY) ? sess_cookie[(txn->flags & TX_CK_MASK) >> TX_CK_SHIFT] : '-',
(be->options & PR_O_COOK_ANY) ? sess_set_cookie[(txn->flags & TX_SCK_MASK) >> TX_SCK_SHIFT] : '-',
actconn, fe->feconn, be->beconn, s->srv ? s->srv->cur_sess : 0,
(s->flags & SN_REDISP)?"+":"",
(s->conn_retries>0)?(be->conn_retries - s->conn_retries):be->conn_retries,
s->logs.srv_queue_size, s->logs.prx_queue_size, tmpline);
s->logs.logwait = 0;
@ -2507,13 +2509,15 @@ int process_srv(struct session *t)
if (may_dequeue_tasks(t->srv, t->be))
task_wakeup(t->srv->queue_mgt);
if (t->srv)
if (t->srv) {
t->srv->cum_sess++;
if (t->srv)
t->srv->failed_conns++;
t->srv->redispatches++;
}
t->be->redispatches++;
t->flags &= ~(SN_DIRECT | SN_ASSIGNED | SN_ADDR_SET);
t->flags |= SN_REDISP;
t->srv = NULL; /* it's left to the dispatcher to choose a server */
http_flush_cookie_flags(txn);