> On 24 Nov 2021, at 22:06, Maxim Dounin <mdounin@mdounin.ru> wrote:
>
> Hello!
>
> On Wed, Nov 24, 2021 at 06:50:10PM +0300, Sergey Kandaurov wrote:
>
>>> On 24 Nov 2021, at 06:46, Maxim Dounin <mdounin@mdounin.ru> wrote:
>>>
>>> On Tue, Nov 23, 2021 at 10:44:00AM +0300, Sergey Kandaurov wrote:
>>>
>>>>> On 23 Nov 2021, at 06:12, Maxim Dounin <mdounin@mdounin.ru> wrote:
>>>>>
>>>>> On Thu, Nov 18, 2021 at 07:46:48PM +0300, Sergey Kandaurov wrote:
>>>>>
>>>>>>> On 16 Nov 2021, at 17:41, Maxim Dounin <mdounin@mdounin.ru> wrote:
>>>>>>>
>>>>>>> On Tue, Nov 16, 2021 at 02:59:46PM +0300, Sergey Kandaurov wrote:
>>>>>>>
>>>>>>>>> On 11 Nov 2021, at 06:10, Maxim Dounin <mdounin@mdounin.ru> wrote:
>>>>>>>>>
>>>>>>>>> # HG changeset patch
>>>>>>>>> # User Maxim Dounin <mdounin@mdounin.ru>
>>>>>>>>> # Date 1636599377 -10800
>>>>>>>>> # Thu Nov 11 05:56:17 2021 +0300
>>>>>>>>> # Node ID 76e072a6947a221868705c13973de15319c0d921
>>>>>>>>> # Parent 82b750b20c5205d685e59031247fe898f011394e
>>>>>>>>> HTTP/2: fixed sendfile() aio handling.
>>>>>>>>>
>>>>>>>>> With sendfile() in threads ("aio threads; sendfile on;"), client connection
>>>>>>>>> can block on writing, waiting for sendfile() to complete. In HTTP/2 this
>>>>>>>>> might result in the request hang, since an attempt to continue processig
>>>>>>>>
>>>>>>>> processing
>>>>>>>
>>>>>>> Fixed, thnx.
>>>>>>>
>>>>>>>>> in thread event handler will call request's write event handler, which
>>>>>>>>> is usually stopped by ngx_http_v2_send_chain(): it does nothing if there
>>>>>>>>> are no additional data and stream->queued is set. Further, HTTP/2 resets
>>>>>>>>> stream's c->write->ready to 0 if writing blocks, so just fixing
>>>>>>>>> ngx_http_v2_send_chain() is not enough.
>>>>>>>>>
>>>>>>>>> Can be reproduced with test suite on Linux with:
>>>>>>>>>
>>>>>>>>> TEST_NGINX_GLOBALS_HTTP="aio threads; sendfile on;" prove h2*.t
>>>>>>>>>
>>>>>>>>> The following tests currently fail: h2_keepalive.t, h2_priority.t,
>>>>>>>>> h2_proxy_max_temp_file_size.t, h2.t, h2_trailers.t.
>>>>>>>>>
>>>>>>>>> Similarly, sendfile() with AIO preloading on FreeBSD can block as well,
>>>>>>>>> with similar results. This is, however, harder to reproduce, especially
>>>>>>>>> on modern FreeBSD systems, since sendfile() usually do not return EBUSY.
>>>>>>>>
>>>>>>>> does not
>>>>>>>
>>>>>>> Fixed, thnx.
>>>>>>>
>>>>>>>>> Fix is to post a write event on HTTP/2 connection in the thread event
>>>>>>>>> handler (and aio preload handler). This ensures that sendfile() will be
>>>>>>>>> completed and stream processing will be resumed by HTTP/2 code.
>>>>>>>>>
>>>>>>>>> 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
>>>>>>>>> @@ -250,6 +250,21 @@ ngx_http_copy_aio_sendfile_event_handler
>>>>>>>>> r->aio = 0;
>>>>>>>>> ev->complete = 0;
>>>>>>>>>
>>>>>>>>> +#if (NGX_HTTP_V2)
>>>>>>>>> +
>>>>>>>>> + if (r->stream) {
>>>>>>>>> + /*
>>>>>>>>> + * for HTTP/2, trigger a write event on the main connection
>>>>>>>>> + * to handle sendfile() preload
>>>>>>>>> + */
>>>>>>>>> +
>>>>>>>>> + ngx_post_event(r->stream->connection->connection->write,
>>>>>>>>> + &ngx_posted_events);
>>>>>>>>> + return;
>>>>>>>>> + }
>>>>>>>>> +
>>>>>>>>> +#endif
>>>>>>>>> +
>>>>>>>>> r->connection->write->handler(r->connection->write);
>>>>>>>>> }
>>>>>>>>>
>>>>>>>>> @@ -323,6 +338,20 @@ ngx_http_copy_thread_event_handler(ngx_e
>>>>>>>>> r->main->blocked--;
>>>>>>>>> r->aio = 0;
>>>>>>>>>
>>>>>>>>> +#if (NGX_HTTP_V2)
>>>>>>>>> +
>>>>>>>>> + if (r->stream) {
>>>>>>>>> + /*
>>>>>>>>> + * for HTTP/2, trigger a write event on the main connection
>>>>>>>>> + * to handle sendfile() in threads
>>>>>>>>> + */
>>>>>>>>> +
>>>>>>>>> + ngx_post_event(r->stream->connection->connection->write,
>>>>>>>>> + &ngx_posted_events);
>>>>>>>>> + }
>>>>>>>>> +
>>>>>>>>> +#endif
>>>>>>>>> +
>>>>>
>>>>> [...]
>>>>>
>>>>> For the record, while testing this patch Sergey found another
>>>>> issue with sendfile() in threads and HTTP/2: since HTTP/2 might
>>>>> call sendfile() within the main connection, bypassing request
>>>>> filter chain, normal r->aio flag checking to prevent multiple
>>>>> operations do not work, and this eventually results in "task
>>>>> already active" alerts due to duplicate operations being posted.
>>>>> With the above patch this issue is much more likely to happen,
>>>>> since it intentionally triggers write events on the main HTTP/2
>>>>> connection.
>>>>>
>>>>> Below are two patches: the first one addresses the issue with
>>>>> duplicate operations by additionally checking file->thread_task
>>>>> before sendfile(), and the second one is a better alternative to
>>>>> the above patch which doesn't post additional events on the main
>>>>> connection.
>>>>>
>>>>> # HG changeset patch
>>>>> # User Maxim Dounin <mdounin@mdounin.ru>
>>>>> # Date 1637635671 -10800
>>>>> # Tue Nov 23 05:47:51 2021 +0300
>>>>> # Node ID 8a18b0bff1266db221fe35dc08f4483044ea0f86
>>>>> # Parent 82b750b20c5205d685e59031247fe898f011394e
>>>>> HTTP/2: fixed "task already active" with sendfile in threads.
>>>>>
>>>>> With sendfile in threads, "task already active" alerts might appear in logs
>>>>> if a write event happens on the main HTTP/2 connection, triggering a sendfile
>>>>> in threads while another thread operation is already running. Observed
>>>>> with "aio threads; aio_write on; sendfile on;" and with thread event handlers
>>>>> modified to post a write event to the main HTTP/2 connection (though can
>>>>> happen without any modifications).
>>>>>
>>>>> Fix is to avoid starting a sendfile operation if file->thread_task indicates
>>>>> that another thread operation is active.
>>>>>
>>>>> 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
>>>>> @@ -324,6 +324,18 @@ ngx_linux_sendfile_thread(ngx_connection
>>>>> "linux sendfile thread: %d, %uz, %O",
>>>>> file->file->fd, size, file->file_pos);
>>>>>
>>>>> + task = file->file->thread_task;
>>>>> +
>>>>> + if (task && task->event.active) {
>>>>> + /*
>>>>> + * with HTTP/2, another thread operation might be already running
>>>>> + * if sendfile() is called as a result of a write event on the main
>>>>> + * connection
>>>>> + */
>>>>> +
>>>>> + return NGX_DONE;
>>>>> + }
>>>>> +
>>>>> task = c->sendfile_task;
>>>>>
>>>>> if (task == NULL) {
>>>
>>> After looking once again into it, I tend to think this patch is
>>> incomplete. In particular, the particular check won't stop
>>> additional sendfile() if there are multiple files and different
>>> files use different thread tasks. While this is not something
>>> possible with standard modules, but nevertheless.
>>
>> Could you please clarify?
>> Is it something rather theoretical (and irrelevant to subrequests)?
>> Because there is a room for only one task in c->sendfile_task.
>
> The code above checks file->file->thread_task, not
> c->sendfile_task, so there can be many different tasks.
>

Got it.

> This is not something about subrequests: multiple thread/aio
> operations are allowed with subrequests as long as they are within
> different subrequests (the r->aio flag is within a particular
> subrequest).
>
> The case I'm talking about can happen if a module returns multiple
> buffers with different files, and these files use different
> thread tasks (for non-sendfile thread operations). This is not
> something which can happen with the standard modules, but might
> happen in theory.

Agreed.

>
>>> Further, the same problem seems to apply to aio preloading (though
>>> unlikely to happen in practice).
>>>
>>> The following patch checks r->aio in relevant handlers to prevent
>>> sendfile() when another operation is running:
>>
>> As a positive effect, moving the check down to thread handlers allows
>> to complete a sendfile operation, within http2 write handler, after
>> thread task completion, since now the check is performed after the
>> "if (task->event.complete) {" logic in ngx_linux_sendfile_thread().
>> E.g.:
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 http2 write handler
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 http2 frame out: 000055BA978A5E28 sid:1 bl:0 len:8192
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 http2 frame out: 000055BA978A5D20 sid:1 bl:1 len:8192
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 linux sendfile thread: 15, 8192, 8794
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 linux sendfile thread: complete:1 err:0 sent:8192
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 no tcp_nodelay
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 tcp_nopush
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 writev: 9 of 9
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 linux sendfile thread: 15, 8192, 16986
>> 2021/11/24 15:16:43 [debug] 474666#474666: *1 linux sendfile thread: complete:0
>
> While the side effect is expected, I don't think this is not
> something important. As far as I understand, you are looking at
> what happens with the previous version of the initial patch with
> ngx_post_event(), but in real world such a write event is
> unlikely. (Not to mention that this won't happen with HTTP/1.x,
> and only applies to HTTP/2 without SSL.)

Correct.
I was not able to see any difference with the current series.

>
>>> # HG changeset patch
>>> # User Maxim Dounin <mdounin@mdounin.ru>
>>> # Date 1637723745 -10800
>>> # Wed Nov 24 06:15:45 2021 +0300
>>> # Node ID 3450841798597536d17ced29b35d1d90ce06ce0d
>>> # Parent 3443c02ca1d183fe52bf8af66627c94be2b2f785
>>> HTTP/2: fixed "task already active" with sendfile in threads.
>>>
>>> With sendfile in threads, "task already active" alerts might appear in logs
>>> if a write event happens on the main HTTP/2 connection, triggering a sendfile
>>> in threads while another thread operation is already running. Observed
>>> with "aio threads; aio_write on; sendfile on;" and with thread event handlers
>>> modified to post a write event to the main HTTP/2 connection (though can
>>> happen without any modifications).
>>>
>>> Similarly, sendfile() with AIO preloading on FreeBSD can trigger duplicate
>>> aio operation, resulting in "second aio post" alerts. This is, however,
>>> harder to reproduce, especially on modern FreeBSD systems, since sendfile()
>>> usually does not return EBUSY.
>>>
>>> Fix is to avoid starting a sendfile operation if other thread operation
>>> is active by checking r->aio in the thread handler (and, similarly, in
>>> aio preload handler).
>>>
>>> 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
>>> @@ -219,6 +219,22 @@ ngx_http_copy_aio_sendfile_preload(ngx_b
>>> ngx_http_request_t *r;
>>> ngx_output_chain_ctx_t *ctx;
>>>
>>> +#if (NGX_HTTP_V2)
>>> +
>>> + r = file->file->aio->data;
>>> +
>>> + if (r->aio) {
>>> + /*
>>> + * with HTTP/2, another thread operation might be already running
>>> + * if sendfile() is called as a result of a write event on the main
>>> + * connection
>>> + */
>>> +
>>> + return NGX_OK;
>>> + }
>>> +
>>> +#endif
>>> +
>>
>> Shouldn't this also check for r->stream to narrow it down to HTTP/2 ?
>> At least, it looks inconsistent taking the code is under NGX_HTTP_V2.
>> On the contrary, shouldn't this expand to non-HTTP/2 protocols as well?
>
> I tend to think that correct approach would be to expand this to
> non-HTTP/2 as well. Without the HTTP/2 check, it will also catch
> duplicate sendfile calls due to subrequests (currently not handled
> by the aio preloading, and handled separately in sendfile in
> threads).
>
> Updated patch below.
>
>>> n = ngx_file_aio_read(file->file, buf, 1, file->file_pos, NULL);
>>>
>>> if (n == NGX_AGAIN) {
>>> @@ -270,6 +286,23 @@ ngx_http_copy_thread_handler(ngx_thread_
>>>
>>> r = file->thread_ctx;
>>>
>>> +#if (NGX_HTTP_V2)
>>> +
>>> + if (r->aio
>>> + && r->stream
>>> + && r->stream->connection->connection->sendfile_task == task)
>>> + {
>>
>> I'm not quite sure how the last part of condition is related (if at all)
>> to stop additional sendfile() for different files using different tasks,
>> as outlined above.
>>
>> Also, looking at ngx_linux_sendfile_thread(), where c->sendfile_task is
>> initially allocated, I cannot imagine how the tasks won't match there.
>> I guess it is enough to check for a non-NULL sendfile_task.
>
> The same thread handler can be used for different thread
> operations, notably sendfile(), read(), or write(). The idea is
> to check if the operation we are called for is actually sendfile()
> in threads, and not thread read or write (which will use different
> task). With sendfile(), calls with r->aio set are expected, and
> we can simply return NGX_OK to properly handle them. With thread
> read or write, simply returning NGX_OK likely will silently broke
> things, so it's better to let it instead fail in
> ngx_thread_task_post().

Ok.

>
>>> + /*
>>> + * with HTTP/2, another thread operation might be already running
>>> + * if sendfile() is called as a result of a write event on the main
>>> + * connection
>>> + */
>>> +
>>> + return NGX_OK;
>>> + }
>>> +
>>> +#endif
>>> +
>>> clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
>>> tp = clcf->thread_pool;
>>>
>>> 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
>>> @@ -3854,6 +3854,23 @@ ngx_http_upstream_thread_handler(ngx_thr
>>> r = file->thread_ctx;
>>> p = r->upstream->pipe;
>>>
>>> +#if (NGX_HTTP_V2)
>>> +
>>> + if (r->aio
>>> + && r->stream
>>> + && r->stream->connection->connection->sendfile_task == task)
>>> + {
>>> + /*
>>> + * with HTTP/2, another thread operation might be already running
>>> + * if sendfile() is called as a result of a write event on the main
>>> + * connection
>>> + */
>>> +
>>> + return NGX_OK;
>>> + }
>>> +
>>> +#endif
>>> +
>>> clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
>>> tp = clcf->thread_pool;
>>>
>
> Updated patch:
>
> # HG changeset patch
> # User Maxim Dounin <mdounin@mdounin.ru>
> # Date 1637774456 -10800
> # Wed Nov 24 20:20:56 2021 +0300
> # Node ID 80c8892153bef7edec591cd1af37237b22d6d0c5
> # Parent 3443c02ca1d183fe52bf8af66627c94be2b2f785
> HTTP/2: fixed "task already active" with sendfile in threads.
>
> With sendfile in threads, "task already active" alerts might appear in logs
> if a write event happens on the main HTTP/2 connection, triggering a sendfile
> in threads while another thread operation is already running. Observed
> with "aio threads; aio_write on; sendfile on;" and with thread event handlers
> modified to post a write event to the main HTTP/2 connection (though can
> happen without any modifications).
>
> Similarly, sendfile() with AIO preloading on FreeBSD can trigger duplicate
> aio operation, resulting in "second aio post" alerts. This is, however,
> harder to reproduce, especially on modern FreeBSD systems, since sendfile()
> usually does not return EBUSY.
>
> Fix is to avoid starting a sendfile operation if other thread operation
> is active by checking r->aio in the thread handler (and, similarly, in
> aio preload handler).
>
> The added check also makes duplicate calls protection in sendfile() in
> threads redundant, so it is removed. Further, now there is a corresponding
> duplicate calls protection in AIO preloading.
>
> 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
> @@ -219,13 +219,25 @@ ngx_http_copy_aio_sendfile_preload(ngx_b
> ngx_http_request_t *r;
> ngx_output_chain_ctx_t *ctx;
>
> + aio = file->file->aio;
> + r = aio->data;
> +
> + if (r->aio) {
> + /*
> + * tolerate sendfile() calls if another operation is already
> + * running; this can happen due to subrequests, multiple calls
> + * of the next body filter from a filter, or in HTTP/2 due to
> + * a write event on the main connection
> + */
> +
> + return NGX_OK;
> + }
> +
> n = ngx_file_aio_read(file->file, buf, 1, file->file_pos, NULL);
>
> if (n == NGX_AGAIN) {
> - aio = file->file->aio;
> aio->handler = ngx_http_copy_aio_sendfile_event_handler;
>
> - r = aio->data;
> r->main->blocked++;
> r->aio = 1;
>
> @@ -263,6 +275,7 @@ static ngx_int_t
> ngx_http_copy_thread_handler(ngx_thread_task_t *task, ngx_file_t *file)
> {
> ngx_str_t name;
> + ngx_connection_t *c;
> ngx_thread_pool_t *tp;
> ngx_http_request_t *r;
> ngx_output_chain_ctx_t *ctx;
> @@ -270,6 +283,27 @@ ngx_http_copy_thread_handler(ngx_thread_
>
> r = file->thread_ctx;
>
> + if (r->aio) {
> + /*
> + * tolerate sendfile() calls if another operation is already
> + * running; this can happen due to subrequests, multiple calls
> + * of the next body filter from a filter, or in HTTP/2 due to
> + * a write event on the main connection
> + */
> +
> + c = r->connection;
> +
> +#if (NGX_HTTP_V2)
> + if (r->stream) {
> + c = r->stream->connection->connection;
> + }
> +#endif
> +
> + if (task == c->sendfile_task) {
> + return NGX_OK;
> + }
> + }
> +
> clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
> tp = clcf->thread_pool;
>
> 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
> @@ -3847,6 +3847,7 @@ ngx_http_upstream_thread_handler(ngx_thr
> {
> ngx_str_t name;
> ngx_event_pipe_t *p;
> + ngx_connection_t *c;
> ngx_thread_pool_t *tp;
> ngx_http_request_t *r;
> ngx_http_core_loc_conf_t *clcf;
> @@ -3854,6 +3855,27 @@ ngx_http_upstream_thread_handler(ngx_thr
> r = file->thread_ctx;
> p = r->upstream->pipe;
>
> + if (r->aio) {
> + /*
> + * tolerate sendfile() calls if another operation is already
> + * running; this can happen due to subrequests, multiple calls
> + * of the next body filter from a filter, or in HTTP/2 due to
> + * a write event on the main connection
> + */
> +
> + c = r->connection;
> +
> +#if (NGX_HTTP_V2)
> + if (r->stream) {
> + c = r->stream->connection->connection;
> + }
> +#endif
> +
> + if (task == c->sendfile_task) {
> + return NGX_OK;
> + }
> + }
> +
> clcf = ngx_http_get_module_loc_conf(r, ngx_http_core_module);
> tp = clcf->thread_pool;
>
> 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
> @@ -379,15 +379,6 @@ ngx_linux_sendfile_thread(ngx_connection
> return ctx->sent;
> }
>
> - if (task->event.active && ctx->file == file) {
> - /*
> - * tolerate duplicate calls; they can happen due to subrequests
> - * or multiple calls of the next body filter from a filter
> - */
> -
> - return NGX_DONE;
> - }
> -
> ctx->file = file;
> ctx->socket = c->fd;
> ctx->size = size;
>

It's hard to say about preload handler, generally it looks good.
Also, I can confirm that the check in ngx_linux_sendfile_thread() is now
redundant and can be removed, a test case for 6422:768e287a6f36 shows
that duplicate calls in subrequests are now handled in thread handlers
(both in HTTP/1.x and HTTP/2), also can be tested with proxy_store.t.
BTW, what about a similar check in ngx_freebsd_sendfile_chain()
used to catch duplicate calls? Both were added in 6422:768e287a6f36.
Anyway, it is removed in the sendfile(SF_NODISKIO) rework.

--
Sergey Kandaurov

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