[MINOR] stats socket: add show sess <id> to dump details about a session

When trying to spot some complex bugs, it's often needed to access
information on stuck sessions, which is quite difficult. This new
command helps one get detailed information about a session, with
flags, timers, states, etc... The buffer data are not dumped yet.
This commit is contained in:
Willy Tarreau 2010-03-05 17:53:32 +01:00
parent d426a18a04
commit 66dc20a17b
3 changed files with 255 additions and 2 deletions

View File

@ -7803,6 +7803,13 @@ show sess
be huge. This command is restricted and can only be issued on sockets
configured for levels "operator" or "admin".
show sess <id>
Display a lot of internal information about the specified session identifier.
This identifier is the first field at the beginning of the lines in the dumps
of "show sess" (it corresponds to the session pointer). Those information are
useless to most users but may be used by haproxy developers to troubleshoot a
complex bug. The output format is intentionally not documented so that it can
freely evolve depending on demands.
show stat [<iid> <type> <sid>]
Dump statistics in the CSV format. By passing <id>, <type> and <sid>, it is

View File

@ -212,7 +212,11 @@ struct session {
int iid, type, sid; /* proxy id, type and service id if bounding of stats is enabled */
} stats;
struct {
struct bref bref;
struct bref bref; /* back-reference from the session being dumped */
void *target; /* session we want to dump, or NULL for all */
unsigned int uid; /* if non-null, the uniq_id of the session being dumped */
int section; /* section of the session being dumped */
int pos; /* last position of the current session's buffer */
} sess;
struct {
int iid; /* if >= 0, ID of the proxy to filter on */

View File

@ -61,7 +61,7 @@ const char stats_sock_usage_msg[] =
" show info : report information about the running process\n"
" show stat : report counters for each proxy and server\n"
" show errors : report last request and response errors for each proxy\n"
" show sess : report the list of current sessions\n"
" show sess [id] : report the list of current sessions or dump this session\n"
" get weight : report a server's current weight\n"
" set weight : change a server's weight\n"
" set timeout : change a timeout setting\n"
@ -316,6 +316,12 @@ int stats_sock_parse_request(struct stream_interface *si, char *line)
si->st0 = STAT_CLI_PRINT;
return 1;
}
if (*args[2])
s->data_ctx.sess.target = (void *)strtoul(args[2], NULL, 0);
else
s->data_ctx.sess.target = NULL;
s->data_ctx.sess.section = 0; /* start with session status */
s->data_ctx.sess.pos = 0;
si->st0 = STAT_CLI_O_SESS; // stats_dump_sess_to_buffer
}
else if (strcmp(args[1], "errors") == 0) {
@ -2298,6 +2304,209 @@ int stats_dump_proxy(struct session *s, struct proxy *px, struct uri_auth *uri)
}
}
/* This function is called to send output to the response buffer. It dumps a
* complete session state onto the output buffer <rep>. The session has to be
* set in data_ctx.sess.target. It returns 0 if the output buffer is full and
* it needs to be called again, otherwise non-zero. It is designed to be called
* from stats_dump_sess_to_buffer() below.
*/
/* returns 1 if dump is not complete */
int stats_dump_full_sess_to_buffer(struct session *s, struct buffer *rep)
{
struct tm tm;
struct chunk msg;
struct session *sess;
extern const char *monthname[12];
char pn[INET6_ADDRSTRLEN];
chunk_init(&msg, trash, sizeof(trash));
sess = s->data_ctx.sess.target;
if (s->data_ctx.sess.section > 0 && s->data_ctx.sess.uid != sess->uniq_id) {
/* session changed, no need to go any further */
chunk_printf(&msg, " *** session terminated while we were watching it ***\n");
if (buffer_feed_chunk(rep, &msg) >= 0)
return 0;
s->data_ctx.sess.target = NULL;
s->data_ctx.sess.uid = 0;
return 1;
}
switch (s->data_ctx.sess.section) {
case 0: /* main status of the session */
s->data_ctx.sess.uid = sess->uniq_id;
s->data_ctx.sess.section = 1;
/* fall through */
case 1:
chunk_printf(&msg,
"%p: id=%u, proto=%s",
sess,
sess->uniq_id,
sess->listener->proto->name);
switch (sess->listener->proto->sock_family) {
case AF_INET:
inet_ntop(AF_INET,
(const void *)&((struct sockaddr_in *)&sess->cli_addr)->sin_addr,
pn, sizeof(pn));
chunk_printf(&msg,
" source=%s:%d\n",
pn,
ntohs(((struct sockaddr_in *)&sess->cli_addr)->sin_port));
break;
case AF_INET6:
inet_ntop(AF_INET6,
(const void *)&((struct sockaddr_in6 *)(&sess->cli_addr))->sin6_addr,
pn, sizeof(pn));
chunk_printf(&msg,
" source=%s:%d\n",
pn,
ntohs(((struct sockaddr_in6 *)&sess->cli_addr)->sin6_port));
break;
case AF_UNIX:
default:
/* no more information to print right now */
chunk_printf(&msg, "\n");
break;
}
chunk_printf(&msg,
" flags=0x%x, conn_retries=%d, srv_conn=%p, pend_pos=%p\n",
sess->flags, sess->conn_retries, sess->srv_conn, sess->pend_pos);
chunk_printf(&msg,
" frontend=%s (id=%u mode=%s), listener=%s (id=%u)\n",
sess->fe->id, sess->fe->uuid, sess->fe->mode ? "http" : "tcp",
sess->listener ? sess->listener->name ? sess->listener->name : "?" : "?",
sess->listener ? sess->listener->luid : 0);
chunk_printf(&msg,
" backend=%s (id=%u mode=%s) server=%s (id=%u)\n",
sess->be->id, sess->be->uuid, sess->be->mode ? "http" : "tcp",
sess->srv ? sess->srv->id : "<none>",
sess->srv ? sess->srv->puid : 0);
chunk_printf(&msg,
" task=%p (state=0x%02x nice=%d calls=%d exp=%s%s)\n",
sess->task,
sess->task->state,
sess->task->nice, sess->task->calls,
sess->task->expire ?
tick_is_expired(sess->task->expire, now_ms) ? "<PAST>" :
human_time(TICKS_TO_MS(sess->task->expire - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>",
task_in_rq(sess->task) ? ", running" : "");
get_localtime(sess->logs.accept_date.tv_sec, &tm);
chunk_printf(&msg,
" task created [%02d/%s/%04d:%02d:%02d:%02d.%06d] (age=%s)\n",
tm.tm_mday, monthname[tm.tm_mon], tm.tm_year+1900,
tm.tm_hour, tm.tm_min, tm.tm_sec, (int)(sess->logs.accept_date.tv_usec),
human_time(now.tv_sec - sess->logs.accept_date.tv_sec, 1));
chunk_printf(&msg,
" si[0]=%p (state=%d flags=0x%02x fd=%d exp=%s, et=0x%03x)\n",
&sess->si[0],
sess->si[0].state,
sess->si[0].flags,
sess->si[0].fd,
sess->si[0].exp ?
tick_is_expired(sess->si[0].exp, now_ms) ? "<PAST>" :
human_time(TICKS_TO_MS(sess->si[0].exp - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>",
sess->si[0].err_type);
chunk_printf(&msg,
" si[1]=%p (state=%d flags=0x%02x fd=%d exp=%s, et=0x%03x)\n",
&sess->si[1],
sess->si[1].state,
sess->si[1].flags,
sess->si[1].fd,
sess->si[1].exp ?
tick_is_expired(sess->si[1].exp, now_ms) ? "<PAST>" :
human_time(TICKS_TO_MS(sess->si[1].exp - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>",
sess->si[1].err_type);
chunk_printf(&msg,
" txn=%p (flags=0x%x meth=%d status=%d req.st=%d rsp.st=%d)\n",
&sess->txn, sess->txn.flags, sess->txn.meth, sess->txn.status,
sess->txn.req.msg_state, sess->txn.rsp.msg_state);
chunk_printf(&msg,
" req=%p (f=0x%06x an=0x%x l=%d sndmx=%d pipe=%d fwd=%ld)\n"
" an_exp=%s",
sess->req,
sess->req->flags, sess->req->analysers,
sess->req->l, sess->req->send_max,
sess->req->pipe ? sess->req->pipe->data : 0,
sess->req->to_forward,
sess->req->analyse_exp ?
human_time(TICKS_TO_MS(sess->req->analyse_exp - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>");
chunk_printf(&msg,
" rex=%s",
sess->req->rex ?
human_time(TICKS_TO_MS(sess->req->rex - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>");
chunk_printf(&msg,
" wex=%s\n"
" data=%p r=%d w=%d lr=%d total=%lld\n",
sess->req->wex ?
human_time(TICKS_TO_MS(sess->req->wex - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>",
sess->req->data,
sess->req->r - sess->req->data,
sess->req->w - sess->req->data,
sess->req->lr - sess->req->data,
sess->req->total);
chunk_printf(&msg,
" res=%p (f=0x%06x an=0x%x l=%d sndmx=%d pipe=%d fwd=%ld)\n"
" an_exp=%s",
sess->rep,
sess->rep->flags, sess->rep->analysers,
sess->rep->l, sess->rep->send_max,
sess->rep->pipe ? sess->rep->pipe->data : 0,
sess->rep->to_forward,
sess->rep->analyse_exp ?
human_time(TICKS_TO_MS(sess->rep->analyse_exp - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>");
chunk_printf(&msg,
" rex=%s",
sess->rep->rex ?
human_time(TICKS_TO_MS(sess->rep->rex - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>");
chunk_printf(&msg,
" wex=%s\n"
" data=%p r=%d w=%d lr=%d total=%lld\n",
sess->rep->wex ?
human_time(TICKS_TO_MS(sess->rep->wex - now_ms),
TICKS_TO_MS(1000)) : "<NEVER>",
sess->rep->data,
sess->rep->r - sess->rep->data,
sess->rep->w - sess->rep->data,
sess->rep->lr - sess->rep->data,
sess->rep->total);
if (buffer_feed_chunk(rep, &msg) >= 0)
return 0;
/* use other states to dump the contents */
}
/* end of dump */
s->data_ctx.sess.uid = 0;
return 1;
}
/* This function is called to send output to the response buffer.
* It dumps the sessions states onto the output buffer <rep>.
@ -2352,6 +2561,22 @@ int stats_dump_sess_to_buffer(struct session *s, struct buffer *rep)
curr_sess = LIST_ELEM(s->data_ctx.sess.bref.ref, struct session *, list);
if (s->data_ctx.sess.target) {
if (s->data_ctx.sess.target != curr_sess)
goto next_sess;
LIST_ADDQ(&curr_sess->back_refs, &s->data_ctx.sess.bref.users);
/* call the proper dump() function and return if we're missing space */
if (!stats_dump_full_sess_to_buffer(s, rep))
return 0;
/* session dump complete */
LIST_DEL(&s->data_ctx.sess.bref.users);
LIST_INIT(&s->data_ctx.sess.bref.users);
s->data_ctx.sess.target = NULL;
break;
}
chunk_printf(&msg,
"%p: proto=%s",
curr_sess,
@ -2476,8 +2701,25 @@ int stats_dump_sess_to_buffer(struct session *s, struct buffer *rep)
return 0;
}
next_sess:
s->data_ctx.sess.bref.ref = curr_sess->list.n;
}
if (s->data_ctx.sess.target) {
/* specified session not found */
if (s->data_ctx.sess.section > 0)
chunk_printf(&msg, " *** session terminated while we were watching it ***\n");
else
chunk_printf(&msg, "Session not found.\n");
if (buffer_feed_chunk(rep, &msg) >= 0)
return 0;
s->data_ctx.sess.target = NULL;
s->data_ctx.sess.uid = 0;
return 1;
}
s->data_state = DATA_ST_FIN;
/* fall through */