RE: nginx+lua reverse proxy empty body (weird repeatable behavior)

Hi all

It seems the body_filter_by_lua section is bypassed somehow, it just
doesn’t receive the proxied data. I have this simplified testcase which
at least for my setup is completely repeatable. See below.

In short, I do a curl call to localhost:9001, which gets the proxied
server www.spelletjes.nl, and I correctly receive the index file
including the “Speel” string that I’m trying to replace. But the lua
section only says: “empty string”. Once! So how did the server data get
through to my curl call? Using openresty 1.2.4.7 (nginx 1.2.4 +
ngx_lua-0.7.4 and more). The nginx.conf shown below is all there is, I
am not using anything else.

I could really use some help here.

Thanks

Bart van Deenen

nginx.conf:

worker_processes 1;
error_log logs/error.log debug;
events {
worker_connections 1024;
}
http {
server {
client_body_in_single_buffer on;
listen 9001;
location / {
proxy_pass http://www.spelletjes.nl:80;
proxy_set_header X-Real-IP $remote_addr;
body_filter_by_lua ’

if ngx.arg[1] ~= “” then
print ( “The body is " … ngx.arg[1])
ngx.arg[1] = string.gsub(ngx.arg[1], “Speel”, “NGINX”)
else
print(ngx.var.uri … " has empty body” … ngx.arg[1])
end
';

    }
}

}

curl call:

curl -v -o spelletjes.html http://localhost:9001/

  • About to connect() to localhost port 9001 (#0)
  • Trying 127.0.0.1…
    % Total % Received % Xferd Average Speed Time Time Time
    Current
    Dload Upload Total Spent Left
    Speed
    0 0 0 0 0 0 0 0 --:–:-- --:–:-- --:–:–
    0* connected
  • Connected to localhost (127.0.0.1) port 9001 (#0)

GET / HTTP/1.1
User-Agent: curl/7.27.0
Host: localhost:9001
Accept: /

  • additional stuff not fine transfer.c:1037: 0 0
  • HTTP 1.1 or later with persistent connection, pipelining supported
    < HTTP/1.1 200 OK
    < Server: ngx_openresty/1.2.4.9
    < Date: Thu, 29 Nov 2012 09:37:35 GMT
    < Content-Type: text/html; charset=UTF-8
    < Content-Length: 149577
    < Connection: keep-alive
    < RTSS: 1-1297-2
    < Vary: Accept-Encoding
    < Cache-Control: max-age=3600
    < P3P: CP=“IDC DSP COR CURa ADMa OUR IND PHY ONL COM STA”
    < P3P: policyref=“http://www.spelletjes.nl/w3c/p3p.xml”, CP="DSP IDC CUR
    ADM PSA PSDi OTPi DELi STP NAV COM UNI INT PHY DEM "
    < X-Id: 066
    < Expires: Thu, 29 Nov 2012 10:29:59 GMT
    < Last-Modified: Thu, 29 Nov 2012 09:29:59 GMT
    <
    { [data not shown]
    100 146k 100 146k 0 0 3163k 0 --:–:-- --:–:-- --:–:–
    3246k
  • Connection #0 to host localhost left intact
  • Closing connection #0

error.log:
1 2012/11/29 10:37:29 [notice] 4013#0: using the “epoll” event method
2 2012/11/29 10:37:29 [notice] 4013#0: start worker processes
3 2012/11/29 10:37:29 [notice] 4013#0: start worker process 4218
4 2012/11/29 10:37:29 [notice] 4013#0: signal 17 (SIGCHLD) received
5 2012/11/29 10:37:29 [notice] 4013#0: worker process 4215 exited with
code 0
6 2012/11/29 10:37:29 [notice] 4013#0: signal 29 (SIGIO) received
7 2012/11/29 10:37:35 [notice] 4218#0: *65 [lua] variations.lua:67: /
has empty body while sending to client, client: 127.0.0.1,
server: , request: “GET / HTTP/1.1”, upstream:
http://212.72.60.182:80/”, host: “localhost: 9001”
8 2012/11/29 10:37:35 [info] 4218#0: *65 client 127.0.0.1 closed
keepalive connection (104: Connection reset by peer)

And the output of the curl call (the local file spelletjes.html) does
contain the correct html (from the proxied server, including the string
‘Speel’ that I’m trying to match on).

Hello!

On Thu, Nov 29, 2012 at 1:51 AM, Bart van Deenen wrote:

It seems the body_filter_by_lua section is bypassed somehow, it just doesn’t
receive the proxied data. I have this simplified testcase which at least for my
setup is completely repeatable. See below.

With your (exact) code sample, I cannot see any issues with
ngx_openresty 1.2.4.9 on Linux x86_64.

For a single request to location / (note: not multiple!), I’m
getting 26 non-empty data chunks:

$ grep 'The body is' logs/error.log | wc -l
26

and also one empty data chunk (which is generated by ngx_proxy to
solely signal the end of the body):

$ grep 'has empty body' logs/error.log | wc -l
1

You can try to scan your error.log on your side.

For big enough response bodies, it’s common to see multiple data
chunks emitted by ngx_proxy to the output body filter chain. And your
body_filter_by_lua handler will be called multiple times, one time for
one data chunk, for a single response.

BTW, please post such questions to the openresty-en mailing list
(https://groups.google.com/group/openresty-en ) instead so that I can
see your mails sooner rather than later :slight_smile:

Best regards,
-agentzh