From b794465178ecf48f13b37e4397145b05fd3fe6df Mon Sep 17 00:00:00 2001 From: Maxim Dounin Date: Mon, 29 Jan 2024 10:31:37 +0300 Subject: [PATCH] AIO operations now add timers (ticket #2162). Each AIO (thread IO) operation being run is now accompanied with 1-minute timer. This timer prevents unexpected shutdown of the worker process while an AIO operation is running, and logs an alert if the operation is running for too long. This fixes "open socket left" alerts during worker processes shutdown due to pending AIO (or thread IO) operations while corresponding requests have no timers. In particular, such errors were observed while reading cache headers (ticket #2162), and with worker_shutdown_timeout. --- src/http/ngx_http_copy_filter_module.c | 26 ++++++++++++++++++++++++++ src/http/ngx_http_file_cache.c | 26 ++++++++++++++++++++++++++ src/http/ngx_http_upstream.c | 13 +++++++++++++ src/os/unix/ngx_files.c | 4 ++++ src/os/unix/ngx_linux_sendfile_chain.c | 1 + 5 files changed, 70 insertions(+) diff --git a/src/http/ngx_http_copy_filter_module.c b/src/http/ngx_http_copy_filter_module.c index bd3028bc7..6a96e003f 100644 --- a/src/http/ngx_http_copy_filter_module.c +++ b/src/http/ngx_http_copy_filter_module.c @@ -170,6 +170,8 @@ ngx_http_copy_aio_handler(ngx_output_chain_ctx_t *ctx, ngx_file_t *file) file->aio->data = r; file->aio->handler = ngx_http_copy_aio_event_handler; + ngx_add_timer(&file->aio->event, 60000); + r->main->blocked++; r->aio = 1; ctx->aio = 1; @@ -192,6 +194,17 @@ ngx_http_copy_aio_event_handler(ngx_event_t *ev) ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http aio: \"%V?%V\"", &r->uri, &r->args); + if (ev->timedout) { + ngx_log_error(NGX_LOG_ALERT, c->log, 0, + "aio operation took too long"); + ev->timedout = 0; + return; + } + + if (ev->timer_set) { + ngx_del_timer(ev); + } + r->main->blocked--; r->aio = 0; @@ -264,6 +277,8 @@ ngx_http_copy_thread_handler(ngx_thread_task_t *task, ngx_file_t *file) return NGX_ERROR; } + ngx_add_timer(&task->event, 60000); + r->main->blocked++; r->aio = 1; @@ -288,6 +303,17 @@ ngx_http_copy_thread_event_handler(ngx_event_t *ev) ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http thread: \"%V?%V\"", &r->uri, &r->args); + if (ev->timedout) { + ngx_log_error(NGX_LOG_ALERT, c->log, 0, + "thread operation took too long"); + ev->timedout = 0; + return; + } + + if (ev->timer_set) { + ngx_del_timer(ev); + } + r->main->blocked--; r->aio = 0; diff --git a/src/http/ngx_http_file_cache.c b/src/http/ngx_http_file_cache.c index aa5fd1917..6c49dd42d 100644 --- a/src/http/ngx_http_file_cache.c +++ b/src/http/ngx_http_file_cache.c @@ -690,6 +690,8 @@ ngx_http_file_cache_aio_read(ngx_http_request_t *r, ngx_http_cache_t *c) c->file.aio->data = r; c->file.aio->handler = ngx_http_cache_aio_event_handler; + ngx_add_timer(&c->file.aio->event, 60000); + r->main->blocked++; r->aio = 1; @@ -737,6 +739,17 @@ ngx_http_cache_aio_event_handler(ngx_event_t *ev) ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http file cache aio: \"%V?%V\"", &r->uri, &r->args); + if (ev->timedout) { + ngx_log_error(NGX_LOG_ALERT, c->log, 0, + "aio operation took too long"); + ev->timedout = 0; + return; + } + + if (ev->timer_set) { + ngx_del_timer(ev); + } + r->main->blocked--; r->aio = 0; @@ -786,6 +799,8 @@ ngx_http_cache_thread_handler(ngx_thread_task_t *task, ngx_file_t *file) return NGX_ERROR; } + ngx_add_timer(&task->event, 60000); + r->main->blocked++; r->aio = 1; @@ -807,6 +822,17 @@ ngx_http_cache_thread_event_handler(ngx_event_t *ev) ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http file cache thread: \"%V?%V\"", &r->uri, &r->args); + if (ev->timedout) { + ngx_log_error(NGX_LOG_ALERT, c->log, 0, + "thread operation took too long"); + ev->timedout = 0; + return; + } + + if (ev->timer_set) { + ngx_del_timer(ev); + } + r->main->blocked--; r->aio = 0; diff --git a/src/http/ngx_http_upstream.c b/src/http/ngx_http_upstream.c index f5db65338..99215ad82 100644 --- a/src/http/ngx_http_upstream.c +++ b/src/http/ngx_http_upstream.c @@ -3949,6 +3949,8 @@ ngx_http_upstream_thread_handler(ngx_thread_task_t *task, ngx_file_t *file) r->aio = 1; p->aio = 1; + ngx_add_timer(&task->event, 60000); + return NGX_OK; } @@ -3967,6 +3969,17 @@ ngx_http_upstream_thread_event_handler(ngx_event_t *ev) ngx_log_debug2(NGX_LOG_DEBUG_HTTP, c->log, 0, "http upstream thread: \"%V?%V\"", &r->uri, &r->args); + if (ev->timedout) { + ngx_log_error(NGX_LOG_ALERT, c->log, 0, + "thread operation took too long"); + ev->timedout = 0; + return; + } + + if (ev->timer_set) { + ngx_del_timer(ev); + } + r->main->blocked--; r->aio = 0; diff --git a/src/os/unix/ngx_files.c b/src/os/unix/ngx_files.c index 1c82a8ead..2fec1ece1 100644 --- a/src/os/unix/ngx_files.c +++ b/src/os/unix/ngx_files.c @@ -110,6 +110,8 @@ ngx_thread_read(ngx_file_t *file, u_char *buf, size_t size, off_t offset, return NGX_ERROR; } + task->event.log = file->log; + file->thread_task = task; } @@ -493,6 +495,8 @@ ngx_thread_write_chain_to_file(ngx_file_t *file, ngx_chain_t *cl, off_t offset, return NGX_ERROR; } + task->event.log = file->log; + file->thread_task = task; } diff --git a/src/os/unix/ngx_linux_sendfile_chain.c b/src/os/unix/ngx_linux_sendfile_chain.c index 101d91a9a..603f91722 100644 --- a/src/os/unix/ngx_linux_sendfile_chain.c +++ b/src/os/unix/ngx_linux_sendfile_chain.c @@ -332,6 +332,7 @@ ngx_linux_sendfile_thread(ngx_connection_t *c, ngx_buf_t *file, size_t size) return NGX_ERROR; } + task->event.log = c->log; task->handler = ngx_linux_sendfile_thread_handler; c->sendfile_task = task;