Nginx stops sending file after ~1.5mb?

Server NGINX
21

Thanks Igor.
I don’t want to be rude, but I find it hard to believe that it’s a
kernel
bug.

First, I’m using the default CentOS 5.2 kernel, it’s seems to me pretty
odd
that there’s such a bug in it. CentOS is being used on a lot of servers,
some of them must be running nginx.

Second, I tried serving the same file with thttpd, and it runs just
fine.
http://195.28.180.147:40/temp/hozer.pdf
Note it’s the exact same file which I cannot get from nginx:
http://www.noal.org.il/static/temp/hozer.pdf

How come thttpd can serve the file just fine? If it’s a kernel bug, I
thought it would happen with all of my servers.
If it’s using some different way of sending the files which does not
depend
on that epoll call - is there any way to configure nginx to use that as
well?

Can I do anything to confirm that it’s a kernel bug? If it is, I should
probably contact CentOS’s maintainers.

Thank you, again.
Yo’av.

22

On Fri, Jan 23, 2009 at 02:35:00PM +0200, Yo’av Moshe wrote:

Note it’s the exact same file which I cannot get from nginx:
http://www.noal.org.il/static/temp/hozer.pdf

How come thttpd can serve the file just fine? If it’s a kernel bug, I
thought it would happen with all of my servers.
If it’s using some different way of sending the files which does not depend
on that epoll call - is there any way to configure nginx to use that as
well?

I do not look modern thttpd, but according its change log, it has no
epoll support. You may try different ways in nginx: you need to build it

    --with-rtsig_module
    --with-select_module
    --with-poll_module

and then choose method:

events {
use select;
#use poll;
#use rtsig;
}

Also, epoll has two modes: level triggered (default) and edge
triggered (EPOLLET). nginx uses more effective edge triggered mode,
lighttpd uses level triggered one. The bug may be in ET mode only.

As to probabilty of kernel bugs: I saw them in FreeBSD (kqueue,
sendfile),
Linux (epoll), Solaris (event ports), and MacOSX (kqueue, sendfile).

Can I do anything to confirm that it’s a kernel bug? If it is, I should
probably contact CentOS’s maintainers.

Your straces confirms this: nginx added socket to epoll and did not
deleted it, nevertheless epoll does not send event.

23

Igor, I tried using select instead of poll, but I get the exact same
problem.

Check my strace:
http://pastebin.com/m65056ec0

I get the same thing with rtsig too.

Hints?
Again, file is at http://www.noal.org.il/static/temp/hozer.pdf. Server
is
using select now.

Thanks…
Yo’av.

24

On Sun, Jan 25, 2009 at 06:26:58PM +0200, Yo’av Moshe wrote:

using select now.
According strace select() does not return event for socket 19 after
sendfile64() sent 1651005 bytes:

25951 18:14:26 select(20, [7 8 16 19], [19], NULL, {60, 0} <unfinished
…>
25951 18:14:27 <… select resumed> ) = 1 (out [19], left {58,
790000})

25951 18:14:27 gettimeofday({1232900067, 890376}, NULL) = 0
25951 18:14:27 sendfile64(19, 20, [1509465], 440765 <unfinished …>
25951 18:14:27 <… sendfile64 resumed> ) = 141540
25951 18:14:27 sendfile64(19, 20, [1651005], 299225 <unfinished …>
25951 18:14:27 <… sendfile64 resumed> ) = -1 EAGAIN (Resource
temporarily unavailable)

25951 18:14:27 select(20, [16 19], [19], NULL, {0, 500000} <unfinished
…>
25951 18:14:28 <… select resumed> ) = 0 (Timeout)

As you have got the same issue with all methods (even with level
triggered
select()), I believe that the bug is in sendfile. You may try to turn
it off even for the single file:

location = /static/temp/hozer.pdf {
    sendfile off;
}

In Linux 2.6.23 sendfile() has been rewritten to use splice framework.
The bug may be introduced while rewriting.

BTW, it seems that thttpd does not use sendfile.

25

I have confirmed this below as well, and yes limiting rate to
3.5Kbit/sec (so SLOW) does work.

I just want to mention, that for the past 9 months I too have received
very random reports of clients having their files stop downloading
after 1.5MB from my server.

My server is running on Fedora 9 with 64GB of ram (yes GB) and dual
Intel 5430’s, so I would also say that the issue is not a VPS issue.

Confirmed:

wget -S http://www.noal.org.il/static/temp/barvazi2.pdf
–2009-01-20 19:02:06-- http://www.noal.org.il/static/temp/barvazi2.pdf
Resolving www.noal.org.il… 195.28.180.147
Connecting to www.noal.org.il|195.28.180.147|:80… connected.
HTTP request sent, awaiting response…
HTTP/1.1 200 OK
Server: nginx/0.7.30
Date: Wed, 21 Jan 2009 00:01:31 GMT
Content-Type: application/pdf
Content-Length: 1950230
Last-Modified: Thu, 15 Jan 2009 15:55:17 GMT
Connection: keep-alive
Expires: Wed, 21 Jan 2009 02:01:31 GMT
Cache-Control: max-age=7200
Accept-Ranges: bytes
Length: 1950230 (1.9M) [application/pdf]
Saving to: `barvazi2.pdf.1’

81% [================================================> ]
1,596,849 --.-K/s eta 5s

26

On Sun, Jan 25, 2009 at 09:04:54PM +0200, Yo’av Moshe wrote:

Sendfile is now off, using select, and still the same…
http://pastebin.com/m2c3ea25b

I have no idea, why it may be so.

I see that select() returned event (“out [19]”):

28215 20:50:18 select(20, [10 19], [19], NULL, {0, 500000} <unfinished
…>
28215 20:50:18 <… select resumed> ) = 1 (out [19], left {0, 380000})

However, at some stage select() did not return event, although the event
is still active (“select(20, [10 19], [19], NULL …”):

28215 20:50:18 gettimeofday({1232909418, 293895}, NULL) = 0
28215 20:50:18 writev(19,
[{“\227\1\2\1\3\1\4\1\5\0\373\0\374\1\230\1\231\1\232\1\233\0\375\0\376\1\6\1\7\1\10\0”…,
9676}], 1) = 9676
28215 20:50:18 pread64(20,
“\24\7\6#"'&\0214\22$63\1\6\25\24\26\27\02632654&#"\6\3\226\204”…,
32768, 1605632) = 32768
28215 20:50:18 writev(19,
[{“\24\7\6#"'&\0214\22$63\1\6\25\24\26\27\02632654&#"\6\3\226\204”…,
32768}], 1) = 32768
28215 20:50:18 pread64(20, “\0 \0M\0o\0r\0i\0s\0o\0n\0'\0s\0
\0d\0i\0r\0e\0c”…, 32768, 1638400) = 32768
28215 20:50:18 writev(19, [{“\0 \0M\0o\0r\0i\0s\0o\0n\0'\0s\0
\0d\0i\0r\0e\0c”…, 32768}], 1) = 1716
28215 20:50:18 select(20, [10 19], [19], NULL, {0, 500000} <unfinished
…>
28215 20:50:18 <… select resumed> ) = 0 (Timeout)

Could you run tcpdump of the session ?

27

Sendfile is now off, using select, and still the same…
http://pastebin.com/m2c3ea25b

Yo’av

28

Hey, attached is my tcpdump log.
I’ve never used tcpdump before, so I hope the log is fine.
I used grep to show only the connections from my computer while running
‘wget http://www.noal.org.il/static/temp/hozer.pdf’.

Hope this will lead us somewhere…

Yo’av.

29

Note I just compiled Cherokee 0.98. It is serving the file as it should
using sendfile and epoll.

30

On Tue, Jan 27, 2009 at 10:42:57AM +0200, Yo’av Moshe wrote:

Note I just compiled Cherokee 0.98. It is serving the file as it should
using sendfile and epoll.

Have you tried this on the same host ?
Could you post strace ?

31

Sure, here my Cherokee’s strace:
http://pastebin.com/m13cd213d

What you are saying about tcpdump’s logs is strange, but I have no idea
what’s causing it.

Yo’av.

32

On Mon, Jan 26, 2009 at 02:05:28PM +0200, Yo’av Moshe wrote:

Hey, attached is my tcpdump log.
I’ve never used tcpdump before, so I hope the log is fine.
I used grep to show only the connections from my computer while running
‘wget http://www.noal.org.il/static/temp/hozer.pdf’.

Hope this will lead us somewhere…

In this tcpdump I see the only strange thing: client acknowledged
data that was ~64K before (1534561), and this may be usual thing,
then server started to retransmit data and client never acknowledged
the data (1535941).

13:53:53.739626 49926 > http: . 125:125(0) ack 1534561 win 65535
13:53:53.739679 http > 49926: . 1596661:1598041(1380) ack 125 win 5840
13:53:53.739865 http > 49926: . 1598041:1599421(1380) ack 125 win 5840
13:53:54.577857 http > 49926: . 1534561:1535941(1380) ack 125 win 5840
13:53:56.256478 http > 49926: . 1534561:1535941(1380) ack 125 win 5840

However, when I have tried to look tcpdump on my side, I saw the my
client sent all acknowledges, but did not get a new data on some point.

33

Applied the patch, still the same.
The other only difference I can think about is that I’m running Cherokee
on
a different port. Maybe my VPS is handling them differently.
I’ll try testing it on the same port this evening and let you know.

Thank you.

Yo’av

34

On Tue, Jan 27, 2009 at 11:58:58AM +0200, Yo’av Moshe wrote:

Applied the patch, still the same.
The other only difference I can think about is that I’m running Cherokee on
a different port. Maybe my VPS is handling them differently.
I’ll try testing it on the same port this evening and let you know.

Could you run another nginx on this port ?
Or even the same nginx:

    server {
        listen  80;
        listen  PORT;

        ...
    }
35

On Tue, Jan 27, 2009 at 11:25:09AM +0200, Yo’av Moshe wrote:

Sure, here my Cherokee’s strace:
http://pastebin.com/m13cd213d

What you are saying about tcpdump’s logs is strange, but I have no idea
what’s causing it.

I see only two difference with nginx:

  1. it uses level triggered epoll (nginx uses edge triggered epoll),
  2. and it uses TCP_NODELAY for first request (nginx set TCP_NODELAY
    only just before going to keep-alive).

The attached patch sets TCP_NODELAY from very start.

36

Right, it’s working on the other port.
I’ll check it again with my VPS.

Sorry for all that.

Yo’av.

37

On Tue, Jan 27, 2009 at 12:24:50PM +0200, Yo’av Moshe wrote:

Right, it’s working on the other port.
I’ll check it again with my VPS.

Sorry for all that.

OK. Please, when issue will be resolved, post the cause in the list.

38

On Tue, 27 Jan 2009 22:03:43 +1100
Dave C. [email protected] wrote:

Hi Yo’av,

If you get an answer from your VPS host would you please post it too
the list. There were others who mentioned earlier on in the thread
that they had occasionally experienced your symptoms, your feedback
may help them.

What I’ve expirienced on Parallels Virtuozzo VPSes is that if tcp send
and/or receive buffer gets full, stuf like this happens. I was able to
workaround that issue by making those buffers larger.

I never investigated the issue in detail, but looking at Igor’s comment
on
the tcp dump, it makes sense that a missing ack for a packet makes the
whole tcp session stall.

If we get some more hard evidence, I can bring this issue to Parallels
support and see what they say.

–

Jure Pečar
http://jure.pecar.org
http://f5j.eu

39

Hi Yo’av,

If you get an answer from your VPS host would you please post it too
the list. There were others who mentioned earlier on in the thread
that they had occasionally experienced your symptoms, your feedback
may help them.

Cheers

Dave