Nginx stops sending file after ~1.5mb ?

[Yo'av Moshe]

Hey,
It's gets even weirder. I found out that if I limit the download speed, I
can get the whole file.

Could anyone confirm that this works:
wget --limit-rate=3500 http://www.noal.org.il/static/temp/barvazi2.pdf
while this doesn't:
wget http://www.noal.org.il/static/temp/barvazi2.pdf

Thank you.
Yo'av

On Tue, Jan 20, 2009 at 12:08 PM, Igor Sysoev <is at rambler-co.ru> wrote:

> On Tue, Jan 20, 2009 at 11:45:13AM +0200, Yo'av Moshe wrote:
>
> > Sorry, but it is still the same... server is now running the modified
> nginx,
> > but this file still can't be fetched:
> > http://www.noal.org.il/static/temp/barvazi2.pdf .
> > I just can't think what the problem might be.
> >
> > If it helps, my VPS is running CentOS 5.2 with kernel 2.6.18.
> >
> > Any more tests I can run?
>
> The patch tries to sendfile() until EAGAIN, even it already said
> that it sent smaller chunk than it was requested.
>
> Could you create a new strace and grep single pid to ensure that
> nginx calls sendfile() until EAGAIN ?
>
> If the patch does not help, I suspect a bug in kernel/VPS/etc, as kernel
> does not return event via epoll_wait().
>
> > Thanks again.
> > Yo'av.
> >
> >
> > 2009/1/20 Igor Sysoev <is at rambler-co.ru>
> >
> > > On Tue, Jan 20, 2009 at 02:59:34AM +0200, Yo'av Moshe wrote:
> > >
> > > > Thanks.
> > > > I'm not an strace guru but I don't think it shows anything unusual...
> > > >
> > > > http://paste-it.net/public/mffe731/
> > > >
> > > > You can see download starts right at the beginning, and at 02:25:25
> you
> > > can
> > > > see the last sendfile64 event. After that, no data was sent and I
> > > couldn't
> > > > find anything related to that in this strace log.
> > > >
> > > > The only thing this strace log is telling me is that nginx knows that
> > > there
> > > > is still more data to send, since it recognized the right size of the
> > > file
> > > > in the beginning (line 13: sendfile64(22, 23, [0], *1950230)*), and
> it
> > > knows
> > > > it has more to send by the last sendfile event (line 1173:
> sendfile64(22,
> > > > 23, [1618265], *331965*)).
> > > >
> > > > What stops the sending?
> > >
> > > Looking at these lines:
> > >
> > > 2140  02:25:24 epoll_wait(11,  <unfinished ...>
> > > 2140  02:25:24 <... epoll_wait resumed> {{EPOLLOUT, {u32=140043201,
> > > u64=13817743186826159041}}}, 512, 22224) = 1
> > > 2140  02:25:24 gettimeofday({1232411124, 913871}, NULL) = 0
> > > 2140  02:25:24 sendfile64(22, 23, [1559225], 391005) = 28800
> > >
> > > 2140  02:25:24 epoll_wait(11, {{EPOLLOUT, {u32=140043201,
> > > u64=13817743186826159041}}}, 512, 22077) = 1
> > > 2140  02:25:25 gettimeofday({1232411125, 66164}, NULL) = 0
> > > 2140  02:25:25 sendfile64(22, 23, [1588025], 362205) = 30240
> > >
> > > 2140  02:25:25 epoll_wait(11, {{EPOLLOUT, {u32=140043201,
> > > u64=13817743186826159041}}}, 512, 21924) = 1
> > > 2140  02:25:25 gettimeofday({1232411125, 211986}, NULL) = 0
> > > 2140  02:25:25 sendfile64(22, 23, [1618265], 331965) = 28800
> > >
> > > I see that client socket (22) is associated with
> u64=13817743186826159041
> > > in epoll. Also I see that the socket was added and modified in epoll
> > > in the start of the transfer:
> > >
> > > 2140  02:25:12 epoll_ctl(11, EPOLL_CTL_ADD, 22, {EPOLLIN|EPOLLET,
> > > {u32=140043201
> > > , u64=579069412499841985}}) = 0
> > >
> > > 2140  02:25:12 epoll_ctl(11, EPOLL_CTL_MOD, 22,
> {EPOLLIN|EPOLLOUT|EPOLLET,
> > > {u32=140043201, u64=13817743186826159041}}) = 0
> > >
> > > However, I do not see socket deletion from epoll or closing.
> > > I see only that after 02:25:25 epoll_wait(), i.e. kernel, never
> > > returned any events about 22 socket.
> > >
> > > You may try the attached patch.
> > >
> > >
> > > --
> > > Igor Sysoev
> > > http://sysoev.ru/en/
> > >
> >
> >
> >
> > --
> > Yo'av Moshe
>
> --
> Igor Sysoev
> http://sysoev.ru/en/
>
>


-- 
Yo'av Moshe
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://nginx.org/pipermail/nginx/attachments/20090120/4d2b00a7/attachment.html>