Mercurial > hg > nginx
changeset 5928:8dfee01ff0bd
Upstream: improved subrequest logging.
To ensure proper logging make sure to set current_request in all event
handlers, including resolve, ssl handshake, cache lock wait timer and
aio read handlers. A macro ngx_http_set_log_request() introduced to
simplify this.
author | Maxim Dounin <mdounin@mdounin.ru> |
---|---|
date | Tue, 02 Dec 2014 05:54:54 +0300 |
parents | ac2a8e4d8f01 |
children | f436e9a60b8f |
files | src/http/ngx_http_file_cache.c src/http/ngx_http_request.c src/http/ngx_http_request.h src/http/ngx_http_upstream.c |
diffstat | 4 files changed, 45 insertions(+), 21 deletions(-) [+] |
line wrap: on
line diff
--- a/src/http/ngx_http_file_cache.c Mon Dec 01 14:51:36 2014 +0300 +++ b/src/http/ngx_http_file_cache.c Tue Dec 02 05:54:54 2014 +0300 @@ -14,6 +14,8 @@ static ngx_int_t ngx_http_file_cache_lock(ngx_http_request_t *r, ngx_http_cache_t *c); static void ngx_http_file_cache_lock_wait_handler(ngx_event_t *ev); +static void ngx_http_file_cache_lock_wait(ngx_http_request_t *r, + ngx_http_cache_t *c); static ngx_int_t ngx_http_file_cache_read(ngx_http_request_t *r, ngx_http_cache_t *c); static ssize_t ngx_http_file_cache_aio_read(ngx_http_request_t *r, @@ -448,25 +450,35 @@ static void ngx_http_file_cache_lock_wait_handler(ngx_event_t *ev) { - ngx_uint_t wait; - ngx_msec_t now, timer; - ngx_http_cache_t *c; - ngx_http_request_t *r; - ngx_http_file_cache_t *cache; + ngx_connection_t *c; + ngx_http_request_t *r; r = ev->data; - c = r->cache; + c = r->connection; + + ngx_http_set_log_request(c->log, r); + + ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, + "http file cache wait: \"%V?%V\"", &r->uri, &r->args); + + ngx_http_file_cache_lock_wait(r, r->cache); +} + + +static void +ngx_http_file_cache_lock_wait(ngx_http_request_t *r, ngx_http_cache_t *c) +{ + ngx_uint_t wait; + ngx_msec_t now, timer; + ngx_http_file_cache_t *cache; now = ngx_current_msec; - ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0, - "http file cache wait handler wt:%M cur:%M", - c->wait_time, now); - timer = c->wait_time - now; if ((ngx_msec_int_t) timer <= 0) { - ngx_log_error(NGX_LOG_INFO, ev->log, 0, "cache lock timeout"); + ngx_log_error(NGX_LOG_INFO, r->connection->log, 0, + "cache lock timeout"); c->lock_timeout = 0; goto wakeup; } @@ -485,7 +497,7 @@ ngx_shmtx_unlock(&cache->shpool->mutex); if (wait) { - ngx_add_timer(ev, (timer > 500) ? 500 : timer); + ngx_add_timer(&c->wait_event, (timer > 500) ? 500 : timer); return; } @@ -665,10 +677,17 @@ ngx_http_cache_aio_event_handler(ngx_event_t *ev) { ngx_event_aio_t *aio; + ngx_connection_t *c; ngx_http_request_t *r; aio = ev->data; r = aio->data; + c = r->connection; + + ngx_http_set_log_request(c->log, r); + + ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, + "http file cache aio: \"%V?%V\"", &r->uri, &r->args); r->main->blocked--; r->aio = 0;
--- a/src/http/ngx_http_request.c Mon Dec 01 14:51:36 2014 +0300 +++ b/src/http/ngx_http_request.c Tue Dec 02 05:54:54 2014 +0300 @@ -2169,13 +2169,11 @@ { ngx_connection_t *c; ngx_http_request_t *r; - ngx_http_log_ctx_t *ctx; c = ev->data; r = c->data; - ctx = c->log->data; - ctx->current_request = r; + ngx_http_set_log_request(c->log, r); ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http run request: \"%V?%V\"", &r->uri, &r->args); @@ -2195,7 +2193,6 @@ ngx_http_run_posted_requests(ngx_connection_t *c) { ngx_http_request_t *r; - ngx_http_log_ctx_t *ctx; ngx_http_posted_request_t *pr; for ( ;; ) { @@ -2215,8 +2212,7 @@ r = pr->request; - ctx = c->log->data; - ctx->current_request = r; + ngx_http_set_log_request(c->log, r); ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http posted request: \"%V?%V\"", &r->uri, &r->args);
--- a/src/http/ngx_http_request.h Mon Dec 01 14:51:36 2014 +0300 +++ b/src/http/ngx_http_request.h Tue Dec 02 05:54:54 2014 +0300 @@ -595,4 +595,8 @@ } +#define ngx_http_set_log_request(log, r) \ + ((ngx_http_log_ctx_t *) log->data)->current_request = r + + #endif /* _NGX_HTTP_REQUEST_H_INCLUDED_ */
--- a/src/http/ngx_http_upstream.c Mon Dec 01 14:51:36 2014 +0300 +++ b/src/http/ngx_http_upstream.c Tue Dec 02 05:54:54 2014 +0300 @@ -942,6 +942,11 @@ u = r->upstream; ur = u->resolved; + ngx_http_set_log_request(c->log, r); + + ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, + "http upstream resolve: \"%V?%V\"", &r->uri, &r->args); + if (ctx->state) { ngx_log_error(NGX_LOG_ERR, r->connection->log, 0, "%V could not be resolved (%i: %s)", @@ -1003,7 +1008,6 @@ { ngx_connection_t *c; ngx_http_request_t *r; - ngx_http_log_ctx_t *ctx; ngx_http_upstream_t *u; c = ev->data; @@ -1012,8 +1016,7 @@ u = r->upstream; c = r->connection; - ctx = c->log->data; - ctx->current_request = r; + ngx_http_set_log_request(c->log, r); ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http upstream request: \"%V?%V\"", &r->uri, &r->args); @@ -1447,6 +1450,8 @@ r = c->data; u = r->upstream; + ngx_http_set_log_request(c->log, r); + if (c->ssl->handshaked) { if (u->conf->ssl_verify) {