From 2b6c0574a38d6187fc8463c86d9160207570b82d Mon Sep 17 00:00:00 2001
From: Krzysztof Piotr Oledzki <ole#ans.pl>
Date: Wed, 26 Dec 2007 00:32:47 +0100
Subject: [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.
--- doc/configuration.txt | 20 ++++++++++++++++- doc/haproxy-en.txt | 46 +++++++++++++++++++++------------------ include/types/server.h | 2 +- include/types/session.h | 54 +++++++++++++++++++++++++--------------------- src/backend.c | 5 +++- src/checks.c | 6 +++++ src/dumpstats.c | 12 +++++----- src/log.c | 4 ++- src/proto_http.c | 9 ++++++- 9 files changed, 100 insertions(+), 58 deletions(-) diff --git a/doc/configuration.txt b/doc/configuration.txt index fb2427d..5197754 100644 --- a/doc/configuration.txt +++ b/doc/configuration.txtReceived on 2007/12/26 00:37
@@ -1190,7 +1190,25 @@ option contstats
during a whole session. Recounting touches a hotpath directly so it is not enabled by default, as it has small performance impact (~0.5%). - +option redispatch +redisp (deprecated) +redispatch (deprecated) + Enable session redistributing + May be used in sections: defaults | frontend | listen | backend + yes | no | yes | no + 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 mutiple connection failures. Of course, it requires having 'retries' + set to a nonzero value. + timeout client <timeout> timeout clitimeout <timeout> (deprecated) Set the maximum inactivity time on the client side. diff --git a/doc/haproxy-en.txt b/doc/haproxy-en.txt index 73da3d9..20cadd8 100644 --- a/doc/haproxy-en.txt +++ b/doc/haproxy-en.txt
@@ -1679,33 +1679,37 @@ 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 + Field Format Example - 1 process_name '[' pid ']:' haproxy[18989]: - 2 client_ip ':' client_port 10.0.0.1:34552 - 3 '[' date ']' [15/Oct/2003:15:26:31] - 4 listener_name relais-http - 5 server_name Srv1 - 6 Tq '/' Tw '/' Tc '/' Tr '/' Tt 3183/-1/-1/-1/11215 - 7 HTTP_return_code 503 - 8 bytes_read 0 - 9 captured_request_cookie - - 10 captured_response_cookie - - 11 termination_state SC-- - 12 srv_conn '/' listener_conn '/' process_conn 137/202/205 - 13 position in srv_queue / listener_queue 0/0 - 14 '{' captured_request_headers '}' {w.ods.org|Mozilla} - 15 '{' captured_response_headers '}' {} - 16 '"' HTTP_request '"' "HEAD / HTTP/1.0" + 1 process_name '[' pid ']:' haproxy[18989]: + 2 client_ip ':' client_port 10.0.0.1:34552 + 3 '[' date ']' [15/Oct/2003:15:26:31] + 4 listener_name relais-http + 5 server_name Srv1 + 6 Tq '/' Tw '/' Tc '/' Tr '/' Tt 3183/-1/-1/-1/11215 + 7 HTTP_return_code 503 + 8 bytes_read 0 + 9 captured_request_cookie - + 10 captured_response_cookie - + 11 termination_state SC-- + 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 '}' {} + 16 '"' HTTP_request '"' "HEAD / HTTP/1.0" 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 -------------------- diff --git a/include/types/server.h b/include/types/server.h index 5c47d17..483e260 100644 --- a/include/types/server.h +++ b/include/types/server.h
@@ -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 */ diff --git a/include/types/session.h b/include/types/session.h index 347bbaa..e087cfe 100644 --- a/include/types/session.h +++ b/include/types/session.h
@@ -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 */ +#define SN_REDISP 0x00000100 /* set if this session was redispatched from one server to another */ +/* unused: 0x00000200 */ +/* unused: 0x00000400 */ +/* unused: 0x00000800 */ -/* session termination conditions, bits values 0x100 to 0x700 (0-7 shift 8) */ +/* session termination conditions, bits values 0x1000 to 0x7000 (0-7 shift 12) */ #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 */ -/* unused: 0x00000800 */ +#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 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 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: 0x00008000 */ /* 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() diff --git a/src/backend.c b/src/backend.c index 6ba3937..e9fe544 100644 --- a/src/backend.c +++ b/src/backend.c
@@ -1419,11 +1419,14 @@ 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->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; diff --git a/src/checks.c b/src/checks.c index 6a73504..c631946 100644 --- a/src/checks.c +++ b/src/checks.c
@@ -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); diff --git a/src/dumpstats.c b/src/dumpstats.c index f752271..27e15f7 100644 --- a/src/dumpstats.c +++ b/src/dumpstats.c
@@ -740,7 +740,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,
@@ -750,7 +750,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>");
@@ -817,7 +817,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,
@@ -825,7 +825,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),
@@ -901,7 +901,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
@@ -943,7 +943,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 diff --git a/src/log.c b/src/log.c index c7ea25c..de75aa2 100644 --- a/src/log.c +++ b/src/log.c
@@ -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; diff --git a/src/proto_http.c b/src/proto_http.c index f387d0b..ec46501 100644 --- a/src/proto_http.c +++ b/src/proto_http.c
@@ -769,7 +769,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) :
@@ -791,6 +791,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;
@@ -2505,11 +2507,14 @@ 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->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); -- 1.5.3.7
This archive was generated by hypermail 2.2.0 : 2007/12/26 00:45 CET