[PATCH 4 of 4] AIO operations now add timers (ticket #2162)

[Sergey Kandaurov]

> On 27 Nov 2023, at 06:50, Maxim Dounin <mdounin at mdounin.ru> wrote:
> 
> # HG changeset patch
> # User Maxim Dounin <mdounin at mdounin.ru>
> # Date 1701050170 -10800
> #      Mon Nov 27 04:56:10 2023 +0300
> # Node ID 00c3e7333145ddb5ea0eeaaa66b3d9c26973c9c2
> # Parent  61d08e4cf97cc073200ec32fc6ada9a2d48ffe51
> 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.
> 
> diff --git a/src/http/ngx_http_copy_filter_module.c b/src/http/ngx_http_copy_filter_module.c
> --- 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_cha
>     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_even
>     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;
> 
> @@ -273,6 +286,8 @@ ngx_http_copy_thread_handler(ngx_thread_
>         return NGX_ERROR;
>     }
> 
> +    ngx_add_timer(&task->event, 60000);
> +
>     r->main->blocked++;
>     r->aio = 1;
> 
> @@ -297,6 +312,17 @@ ngx_http_copy_thread_event_handler(ngx_e
>     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
> --- a/src/http/ngx_http_file_cache.c
> +++ b/src/http/ngx_http_file_cache.c
> @@ -705,6 +705,8 @@ ngx_http_file_cache_aio_read(ngx_http_re
>         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;
> 
> @@ -752,6 +754,17 @@ ngx_http_cache_aio_event_handler(ngx_eve
>     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;
> 
> @@ -810,6 +823,8 @@ ngx_http_cache_thread_handler(ngx_thread
>         return NGX_ERROR;
>     }
> 
> +    ngx_add_timer(&task->event, 60000);
> +
>     r->main->blocked++;
>     r->aio = 1;
> 
> @@ -831,6 +846,17 @@ ngx_http_cache_thread_event_handler(ngx_
>     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
> --- a/src/http/ngx_http_upstream.c
> +++ b/src/http/ngx_http_upstream.c
> @@ -3949,6 +3949,8 @@ ngx_http_upstream_thread_handler(ngx_thr
>     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(n
>     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
> --- 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
>             return NGX_ERROR;
>         }
> 
> +        task->event.log = file->log;
> +
>         file->thread_task = task;
>     }
> 
> @@ -493,6 +495,8 @@ ngx_thread_write_chain_to_file(ngx_file_
>             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
> --- 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
>             return NGX_ERROR;
>         }
> 
> +        task->event.log = c->log;
>         task->handler = ngx_linux_sendfile_thread_handler;
> 
>         c->sendfile_task = task;

Looks good to me.

-- 
Sergey Kandaurov