Welcome! Log In Create A New Profile

Advanced

Nginx holding subrequests when using thread pool

Jabasukuriputo Wang
August 12, 2022 11:10PM
Hi,

I’m trying to modify the ModSecurity NGINX connector to use the thread
pool feature offered by NGINX. However when running the test suites
involving auth_request, as long as I did a ngx_thread_task_post in
either the rewrite phase or preaccess phase, the auth subrequest
always seems to somehow block until the main request canceled. What
happened in between?

Cheers,
W.

NGINX version: 1.21.4

Code of rewrite handler:

ngx_int_t ngx_http_modsecurity_rewrite_handler(ngx_http_request_t *r)
{
ngx_http_modsecurity_rewrite_thread_ctx_t *ctx;
ngx_http_modsecurity_ctx_t *m_ctx;
ngx_thread_task_t *task;

m_ctx = ngx_http_get_module_ctx(r, ngx_http_modsecurity_module);

ngx_log_error(NGX_LOG_DEBUG, r->connection->log, 0, "recovering
ctx: %p", m_ctx);

task = ngx_thread_task_alloc(r->pool,
sizeof(ngx_http_modsecurity_rewrite_thread_ctx_t));

ctx = task->ctx;
ctx->r = r;
ctx->ctx = m_ctx;
ctx->return_code = NGX_DECLINED;

task->handler = ngx_http_modsecurity_rewrite_worker;
task->event.handler = ngx_http_modsecurity_rewrite_finalizer;
task->event.data = ctx;

ngx_log_error(NGX_LOG_DEBUG, r->connection->log, 0, "[ModSecurity]
Using Thread Pool: %p", mcf->thread_pool);

if (ngx_thread_task_post(mcf->thread_pool, task) != NGX_OK)
{
return NGX_ERROR;
}

return NGX_DONE;
}

The completion handler:

void ngx_http_modsecurity_rewrite_finalizer(ngx_event_t *ev)
{
ngx_http_modsecurity_rewrite_thread_ctx_t *ctx = ev->data;
ngx_http_core_main_conf_t *cmcf;

ngx_log_error(NGX_LOG_DEBUG, ctx->r->connection->log, 0,
"[ModSecurity] Rewrite Job Finalized");

cmcf = ngx_http_get_module_main_conf(ctx->r, ngx_http_core_module);

switch (ctx->return_code)
{
case NGX_OK:
ctx->r->phase_handler = cmcf->phase_engine.handlers->next;
ngx_http_core_run_phases(ctx->r);
break;
case NGX_DECLINED:
ctx->r->phase_handler++;
ngx_http_core_run_phases(ctx->r);
break;
case NGX_AGAIN:
case NGX_DONE:
// ngx_http_core_run_phases(ctx->r);
break;
default:
ngx_http_finalize_request(ctx->r, ctx->return_code);
}
}

Note that even if I don’t do anything in
ngx_http_modsecurity_rewrite_worker, it still seems to block.

Relevant Config:

location = /auth {
return 200;
}

location = /useauth {
modsecurity on;
modsecurity_rules '
SecRuleEngine On
SecRequestBodyAccess On
';
auth_request /auth;
proxy_pass http://127.0.0.1:8081;
}

Debug log (notice the gap, that’s when I Ctrl-C the curl):

2022/08/12 19:29:17 [debug] 17157#17160: Nothing to add on the body
inspection, reclaiming a NGX_DECLINED
2022/08/12 19:29:17 [debug] 17157#17160: complete task #2 in thread
pool "default"
2022/08/12 19:29:17 [debug] 17157#17157: epoll: fd:11 ev:0001 d:00005558A9EA4560
2022/08/12 19:29:17 [debug] 17157#17157: thread pool handler
2022/08/12 19:29:17 [debug] 17157#17157: run completion handler for task #2
2022/08/12 19:29:17 [debug] 17157#17157: *2 generic phase: 6
2022/08/12 19:29:17 [debug] 17157#17157: *2 generic phase: 7
2022/08/12 19:29:17 [debug] 17157#17157: *2 access phase: 8
2022/08/12 19:29:17 [debug] 17157#17157: *2 access phase: 9
2022/08/12 19:29:17 [debug] 17157#17157: *2 access phase: 10
2022/08/12 19:29:17 [debug] 17157#17157: *2 auth request handler
2022/08/12 19:29:17 [debug] 17157#17157: *2 http subrequest "/auth?"
2022/08/12 19:29:17 [debug] 17157#17157: timer delta: 0
2022/08/12 19:29:17 [debug] 17157#17157: worker cycle
2022/08/12 19:29:17 [debug] 17157#17157: epoll timer: -1
2022/08/12 19:29:23 [debug] 17157#17157: epoll: fd:3 ev:2001 d:00005558AB3ED909
2022/08/12 19:29:23 [debug] 17157#17157: *2 http run request: "/auth?"
2022/08/12 19:29:23 [debug] 17157#17157: *2 http request empty handler
2022/08/12 19:29:23 [debug] 17157#17157: *2 http posted request: "/auth?"
2022/08/12 19:29:23 [debug] 17157#17157: *2 rewrite phase: 0
2022/08/12 19:29:23 [debug] 17157#17157: *2 test location: "/bodylimitreject"
2022/08/12 19:29:23 [debug] 17157#17157: *2 test location: "/bodyaccess"
2022/08/12 19:29:23 [debug] 17157#17157: *2 test location: "/auth"
2022/08/12 19:29:23 [debug] 17157#17157: *2 using configuration "=/auth"
2022/08/12 19:29:23 [debug] 17157#17157: *2 http cl:-1 max:1048576
2022/08/12 19:29:23 [debug] 17157#17157: *2 rewrite phase: 2
2022/08/12 19:29:23 [debug] 17157#17157: *2 catching a new _rewrite_
phase handler

This is the log when I don’t bother with the thread pool:

2022/08/12 19:29:45 [debug] 18087#18087: *1 catching a new _rewrite_
phase handler
2022/08/12 19:29:45 [error] 18087#18087: *1 ModSecurity not enabled...
returning, client: 127.0.0.1, server: localhost, request: "GET
/useauth HTTP/1.1", host: "127.0.0.1:8080"
2022/08/12 19:29:45 [debug] 18087#18087: *1 rewrite phase: 3
2022/08/12 19:29:45 [debug] 18087#18087: *1 post rewrite phase: 4
2022/08/12 19:29:45 [debug] 18087#18087: *1 generic phase: 5
2022/08/12 19:29:45 [debug] 18087#18087: *1 catching a new _preaccess_
phase handler
2022/08/12 19:29:45 [error] 18087#18087: *1 ModSecurity not enabled...
returning, client: 127.0.0.1, server: localhost, request: "GET
/useauth HTTP/1.1", host: "127.0.0.1:8080"
2022/08/12 19:29:45 [debug] 18087#18087: *1 generic phase: 6
2022/08/12 19:29:45 [debug] 18087#18087: *1 generic phase: 7
2022/08/12 19:29:45 [debug] 18087#18087: *1 access phase: 8
2022/08/12 19:29:45 [debug] 18087#18087: *1 access phase: 9
2022/08/12 19:29:45 [debug] 18087#18087: *1 access phase: 10
2022/08/12 19:29:45 [debug] 18087#18087: *1 auth request handler
2022/08/12 19:29:45 [debug] 18087#18087: *1 http subrequest "/auth?"
2022/08/12 19:29:45 [debug] 18087#18087: *1 http posted request: "/auth?"
2022/08/12 19:29:45 [debug] 18087#18087: *1 rewrite phase: 0
2022/08/12 19:29:45 [debug] 18087#18087: *1 test location: "/bodylimitreject"
2022/08/12 19:29:45 [debug] 18087#18087: *1 test location: "/bodyaccess"
2022/08/12 19:29:45 [debug] 18087#18087: *1 test location: "/auth"
2022/08/12 19:29:45 [debug] 18087#18087: *1 using configuration "=/auth"
2022/08/12 19:29:45 [debug] 18087#18087: *1 http cl:-1 max:1048576
2022/08/12 19:29:45 [debug] 18087#18087: *1 rewrite phase: 2
2022/08/12 19:29:45 [debug] 18087#18087: *1 catching a new _rewrite_
phase handler
2022/08/12 19:29:45 [error] 18087#18087: *1 ModSecurity not enabled...
returning, client: 127.0.0.1, server: localhost, request: "GET
/useauth HTTP/1.1", subrequest: "/auth", host: "127.0.0.1:8080"
2022/08/12 19:29:45 [debug] 18087#18087: *1 rewrite phase: 3
2022/08/12 19:29:45 [debug] 18087#18087: *1 header filter, recovering
ctx: 0000000000000000
_______________________________________________
nginx-devel mailing list -- nginx-devel@nginx.org
To unsubscribe send an email to nginx-devel-leave@nginx.org
Subject Author Views Posted

Nginx holding subrequests when using thread pool

Jabasukuriputo Wang 283 August 12, 2022 11:10PM



Sorry, you do not have permission to post/reply in this forum.

Online Users

Guests: 79
Record Number of Users: 6 on February 13, 2018
Record Number of Guests: 421 on December 02, 2018
Powered by nginx      Powered by FreeBSD      PHP Powered      Powered by MariaDB      ipv6 ready