Bug #2114

lighty fds pile up using kqueue, select.

Added by jbj almost 5 years ago. Updated over 3 years ago.

Status:FixedStart date:2009-12-04
Priority:NormalDue date:
Assignee:-% Done:

100%

Category:mod_proxy
Target version:1.4.27
Missing in 1.5.x:No

Description

i tested with a setup like client->lighty (mod_proxy)->server. Client uploads a file and server will exit as soon as it accepts the connection. lighty works fine with epoll where it closes the connection properly (EPOLLHUP). But for kqueue and select, sendfile() throws 'Socket is not connected' and returns -2. The fds are not removed and sits in handle-req state.

if (-2 == ret) { /* remote close */
log_error_write(srv, FILE, LINE, "ssd", "write failed, remote connection close:", strerror(errno), errno);
return HANDLER_WAIT_FOR_EVENT;
}

Below is truss output taken in FreeBSD 7.0. I can reproduce it and give you further details if needed.

Truss Output:
............
............
5.761943487 0.000028216 write(5,"2009-12-02 20:20:10: (mod_proxy."...,78) = 78 (0x4e)
5.762071436 0.000043581 socket(PF_INET,SOCK_STREAM,0) = 9 (0x9)
5.762358903 0.000024584 fcntl(9,F_SETFD,FD_CLOEXEC) = 0 (0x0)
5.762460033 0.000023746 fcntl(9,F_SETFL,O_NONBLOCK|0x2) = 0 (0x0)
5.762650280 0.000084088 connect(9,{ AF_INET 172.16.0.230:85 },16) ERR#36 'Operation now in progress'
5.762806725 0.000035200 write(5,"2009-12-02 20:20:10: (mod_proxy."...,59) = 59 (0x3b)
5.763022674 0.000033803 kevent(7,{0x9,EVFILT_WRITE,EV_ADD|EV_CLEAR,0,0x0,0x0},1,0x0,0,{0.000000000}) = 0 (0x0)
5.763169900 0.000029054 kevent(7,{0x8,EVFILT_READ,EV_DELETE,0,0x0,0x0},1,0x0,0,{0.000000000}) = 0 (0x0)
5.763276617 0.000021790 gettimeofday({1259765410.396380},0x0) = 0 (0x0)
5.763395068 0.000029333 kevent(7,0x0,0,{0x9,EVFILT_WRITE,EV_CLEAR,0,0x8218,0x0},7208,{1.000000000}) = 1 (0x1)
5.763539500 0.000032127 write(5,"2009-12-02 20:20:10: (mod_proxy."...,62) = 62 (0x3e)
5.763663258 0.000027657 kevent(7,{0x9,EVFILT_WRITE,EV_DELETE,0,0x0,0x0},1,0x0,0,{0.000000000}) = 0 (0x0)
5.763794001 0.000023187 getsockopt(0x9,0xffff,0x1007,0xbfbfe8d4,0xbfbfe8d0,0xbfbfe888) = 0 (0x0)
5.763915246 0.000029613 write(5,"2009-12-02 20:20:10: (mod_proxy."...,74) = 74 (0x4a)
5.764110522 0.000070121 writev(0x9,0xbfbfc7f8,0x1,0x0,0x0,0x0) = 227 (0xe3)
5.764356642 0.000126552 stat("/var/tmp/lighttpd-upload-bqDHIm",{mode=-rw------- ,inode=898063,size=300000,blksize=
4096}) = 0 (0x0)
5.764534878 0.000052242 open("/var/tmp/lighttpd-upload-bqDHIm",O_RDONLY,027757743344) = 10 (0xa)
5.764636846 0.000030451 close(10) = 0 (0x0)
5.764815081 0.000052241 open("/var/tmp/lighttpd-upload-bqDHIm",O_RDONLY,05023107000) = 10 (0xa)
5.764912579 0.000021511 fcntl(10,F_SETFD,FD_CLOEXEC) = 0 (0x0)
5.765151157 0.000151975 sendfile(0xa,0x9,0x0,0x0,0x493e0,0x0) ERR#35 'Resource temporarily unavailable'
5.765324922 0.000033244 kevent(7,{0x9,EVFILT_WRITE,EV_ADD|EV_CLEAR,0,0x0,0x0},1,0x0,0,{0.000000000}) = 0 (0x0)
5.765436948 0.000021791 gettimeofday({1259765410.398541},0x0) = 0 (0x0)
5.766587653 0.001062147 kevent(7,0x0,0,{0x9,EVFILT_WRITE,EV_CLEAR|EV_EOF,54,0x8218,0x0},7208,{1.000000000}) = 1 (0x1)
5.766791589 0.000034921 write(5,"2009-12-02 20:20:10: (mod_proxy."...,62) = 62 (0x3e)
5.767008935 0.000054756 sendfile(0xa,0x9,0x8000,0x0,0x413e0,0x0) ERR#57 'Socket is not connected'
5.767181303 0.000034082 write(5,"2009-12-02 20:20:10: (mod_proxy."...,106) = 106 (0x6a)
5.767273773 0.000021790 gettimeofday({1259765410.400378},0x0) = 0 (0x0)
6.767701481 1.000335238 kevent(7,0x0,0,{},7208,{1.000000000}) = 0 (0x0)
............
............
............

changeset_r2719.diff Magnifier (747 Bytes) tinus, 2011-02-14 12:48


Related issues

Related to Bug #2181: Connections pile up and waits in handle request Duplicate 2010-04-01

Associated revisions

Revision 2719
Added by stbuehler over 4 years ago

mod_proxy: close connection on write error (fixes #2114)

History

#1 Updated by jbj over 4 years ago

  • Target version set to 1.4.27

it is in version 1.4.26 too.

#2 Updated by stbuehler over 4 years ago

  • Status changed from New to Fixed
  • % Done changed from 0 to 100

Applied in changeset r2719.

#3 Updated by tinus over 3 years ago

Using the original patch, I get the following flow of events:

- Client sends PUT request headers and a file upload body
- Lighttpd sends the headers and a small part of the body to the server
- While lighttpd is sending the body, the server responds with a failure message (401 unauthorized) and closes the connection
- Lighttpd cannot send the body as the connection is closed, so it logs an error and responds to the client with a 500 internal server error

The attached patch makes lighttpd skip sending the rest of the file when it cannot send due to the connection being closed, but continue handling the request. This way it can return the original server response to the client.

Also available in: Atom