changeset 9202:e88cdaa0f1ff

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.
author Maxim Dounin <mdounin@mdounin.ru>
date Mon, 29 Jan 2024 10:31:37 +0300
parents 791ead216b03
children 0de20f43db25
files src/http/ngx_http_copy_filter_module.c src/http/ngx_http_file_cache.c src/http/ngx_http_upstream.c src/os/unix/ngx_files.c src/os/unix/ngx_linux_sendfile_chain.c
diffstat 5 files changed, 70 insertions(+), 0 deletions(-) [+]
line wrap: on
line diff
--- a/src/http/ngx_http_copy_filter_module.c	Mon Jan 29 10:29:39 2024 +0300
+++ b/src/http/ngx_http_copy_filter_module.c	Mon Jan 29 10:31:37 2024 +0300
@@ -170,6 +170,8 @@
     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_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 @@
         return NGX_ERROR;
     }
 
+    ngx_add_timer(&task->event, 60000);
+
     r->main->blocked++;
     r->aio = 1;
 
@@ -288,6 +303,17 @@
     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;
 
--- a/src/http/ngx_http_file_cache.c	Mon Jan 29 10:29:39 2024 +0300
+++ b/src/http/ngx_http_file_cache.c	Mon Jan 29 10:31:37 2024 +0300
@@ -690,6 +690,8 @@
         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_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 @@
         return NGX_ERROR;
     }
 
+    ngx_add_timer(&task->event, 60000);
+
     r->main->blocked++;
     r->aio = 1;
 
@@ -807,6 +822,17 @@
     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;
 
--- a/src/http/ngx_http_upstream.c	Mon Jan 29 10:29:39 2024 +0300
+++ b/src/http/ngx_http_upstream.c	Mon Jan 29 10:31:37 2024 +0300
@@ -3949,6 +3949,8 @@
     r->aio = 1;
     p->aio = 1;
 
+    ngx_add_timer(&task->event, 60000);
+
     return NGX_OK;
 }
 
@@ -3967,6 +3969,17 @@
     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;
 
--- a/src/os/unix/ngx_files.c	Mon Jan 29 10:29:39 2024 +0300
+++ b/src/os/unix/ngx_files.c	Mon Jan 29 10:31:37 2024 +0300
@@ -110,6 +110,8 @@
             return NGX_ERROR;
         }
 
+        task->event.log = file->log;
+
         file->thread_task = task;
     }
 
@@ -493,6 +495,8 @@
             return NGX_ERROR;
         }
 
+        task->event.log = file->log;
+
         file->thread_task = task;
     }
 
--- a/src/os/unix/ngx_linux_sendfile_chain.c	Mon Jan 29 10:29:39 2024 +0300
+++ b/src/os/unix/ngx_linux_sendfile_chain.c	Mon Jan 29 10:31:37 2024 +0300
@@ -332,6 +332,7 @@
             return NGX_ERROR;
         }
 
+        task->event.log = c->log;
         task->handler = ngx_linux_sendfile_thread_handler;
 
         c->sendfile_task = task;