How to really do non-blocking http requests in log_by_lua (or help me understand what i'm doing wrong ;-)

[ThomasLohner]

My Usecase

I'm building a proxy server that stores optimized versions of response bodies for the next request to be served from cache. This means writing the response body of a proxied request to a temporary file and sending it to a optimizing process (minify, compress images etc.) via a rest api after the proxy request is done. This first / uncached request should not suffer from any overhead so log_by_lua* seemed like a good choice to me.

What i tried

Since ngx.location.capture and ngx.socket.tcp are disabled in log_by_lua* i went with ngx.timer.at

log_by_lua_block {
    -- simulate 1 second http call
    local function sleep(premature)
        local socket = require("socket")
        socket.sleep(1)
    end
    local ok, err = ngx.timer.at(0, sleep)
}

Although running in a "light thread" this will block workers and connections start piling up very quickly. After just a couple of seconds proxy will stop working and nginx throws the slightly misleading error message:

upstream timed out (110: Connection timed out) while connecting to upstream

At this point response time i super slow because nginx seems to be queuing new connections. It can take several seconds just to get server stats:

# time curl localhost/server-status

Active connections: 160
server accepts handled requests
 165403 165403 164827
Reading: 0 Writing: 44 Waiting: 116

real	0m14.835s
user	0m0.000s
sys	0m0.007s

What would work

I can confirm that it's possible to run non-blocking code in log_by_lua* like this:

log_by_lua_block {
    ngx.sleep(2)
}

Help!

I'm wondering if i am missing something here and i don't quite understand why the client connection is not simply closed before running NGX_HTTP_LOG_PHASE. Any hint on how to solve this problem would be highly appreciated.

I'm running nginx/1.17.3 from https://launchpad.net/~nginx/+archive/ubuntu/stable

Thank you.

[dams-dev]

I have the same problem.

ngx.timer.at(0) is blocking wall process.

Could you give feedback please?

Tkank you.