details: http://hg.nginx.org/nginx/rev/8dfee01ff0bd
branches:
changeset: 5928:8dfee01ff0bd
user: Maxim Dounin <mdounin@mdounin.ru>
date: Tue Dec 02 05:54:54 2014 +0300
description:
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.

diffstat:

src/http/ngx_http_file_cache.c | 43 ++++++++++++++++++++++++++++++-----------
src/http/ngx_http_request.c | 8 +-----
src/http/ngx_http_request.h | 4 +++
src/http/ngx_http_upstream.c | 11 +++++++--
4 files changed, 45 insertions(+), 21 deletions(-)

diffs (176 lines):

diff --git a/src/http/ngx_http_file_cache.c b/src/http/ngx_http_file_cache.c
--- a/src/http/ngx_http_file_cache.c
+++ b/src/http/ngx_http_file_cache.c
@@ -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 @@ ngx_http_file_cache_lock(ngx_http_reques
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_http_file_cache_lock_wait_handler(ng
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 @@ static void
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;
diff --git a/src/http/ngx_http_request.c b/src/http/ngx_http_request.c
--- a/src/http/ngx_http_request.c
+++ b/src/http/ngx_http_request.c
@@ -2169,13 +2169,11 @@ ngx_http_request_handler(ngx_event_t *ev
{
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 @@ void
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 @@ ngx_http_run_posted_requests(ngx_connect

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);
diff --git a/src/http/ngx_http_request.h b/src/http/ngx_http_request.h
--- a/src/http/ngx_http_request.h
+++ b/src/http/ngx_http_request.h
@@ -595,4 +595,8 @@ extern ngx_http_header_out_t ngx_http_
}


+#define ngx_http_set_log_request(log, r) \
+ ((ngx_http_log_ctx_t *) log->data)->current_request = r
+
+
#endif /* _NGX_HTTP_REQUEST_H_INCLUDED_ */
diff --git a/src/http/ngx_http_upstream.c b/src/http/ngx_http_upstream.c
--- a/src/http/ngx_http_upstream.c
+++ b/src/http/ngx_http_upstream.c
@@ -942,6 +942,11 @@ ngx_http_upstream_resolve_handler(ngx_re
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_http_upstream_handler(ngx_event_t *e
{
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 @@ ngx_http_upstream_handler(ngx_event_t *e
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 @@ ngx_http_upstream_ssl_handshake(ngx_conn
r = c->data;
u = r->upstream;

+ ngx_http_set_log_request(c->log, r);
+
if (c->ssl->handshaked) {

if (u->conf->ssl_verify) {

_______________________________________________
nginx-devel mailing list
nginx-devel@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-devel