Mercurial > dovecot > core-2.2
changeset 17625:b162e39909d7
lib-http: Debug log now includes where HTTP requests spent their time on.
author | Timo Sirainen <tss@iki.fi> |
---|---|
date | Fri, 11 Jul 2014 14:17:17 +0300 |
parents | 94cdc5bcb308 |
children | 535562da7b29 |
files | src/lib-http/http-client-connection.c src/lib-http/http-client-private.h src/lib-http/http-client-request.c |
diffstat | 3 files changed, 13 insertions(+), 3 deletions(-) [+] |
line wrap: on
line diff
--- a/src/lib-http/http-client-connection.c Fri Jul 11 12:10:02 2014 +0300 +++ b/src/lib-http/http-client-connection.c Fri Jul 11 14:17:17 2014 +0300 @@ -400,7 +400,9 @@ i_assert(conn->incoming_payload != NULL); i_assert(conn->conn.io == NULL); - http_client_connection_debug(conn, "Response payload stream destroyed"); + http_client_connection_debug(conn, + "Response payload stream destroyed (%u ms after initial response)", + timeval_diff_msecs(&ioloop_timeval, &req->response_time)); /* caller is allowed to change the socket fd to blocking while reading the payload. make sure here that it's switched back. */ @@ -548,6 +550,7 @@ http_client_connection_unref(&conn); return; } + req->response_time = ioloop_timeval; /* Got some response; cancel response timeout */ if (conn->to_response != NULL) @@ -584,8 +587,10 @@ } http_client_connection_debug(conn, - "Got %u response for request %s", - response.status, http_client_request_label(req)); + "Got %u response for request %s (took %u ms + %u ms in queue)", + response.status, http_client_request_label(req), + timeval_diff_msecs(&req->response_time, &req->sent_time), + timeval_diff_msecs(&req->sent_time, &req->submit_time)); /* make sure connection output is unlocked if 100-continue failed */ if (req->payload_sync && !conn->payload_continue)
--- a/src/lib-http/http-client-private.h Fri Jul 11 12:10:02 2014 +0300 +++ b/src/lib-http/http-client-private.h Fri Jul 11 14:17:17 2014 +0300 @@ -71,6 +71,9 @@ struct ostream *payload_output; struct timeval release_time; + struct timeval submit_time; + struct timeval sent_time; + struct timeval response_time; unsigned int attempts; unsigned int redirects;
--- a/src/lib-http/http-client-request.c Fri Jul 11 12:10:02 2014 +0300 +++ b/src/lib-http/http-client-request.c Fri Jul 11 14:17:17 2014 +0300 @@ -433,6 +433,7 @@ void http_client_request_submit(struct http_client_request *req) { req->client->pending_requests++; + req->submit_time = ioloop_timeval; http_client_request_do_submit(req); http_client_request_debug(req, "Submitted"); @@ -724,6 +725,7 @@ iov[2].iov_len = 2; req->state = HTTP_REQUEST_STATE_PAYLOAD_OUT; + req->sent_time = ioloop_timeval; o_stream_cork(output); if (o_stream_sendv(output, iov, N_ELEMENTS(iov)) < 0) { *error_r = t_strdup_printf("write(%s) failed: %s",