From owner-freebsd-hackers@FreeBSD.ORG Fri Aug 19 18:43:56 2011 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 4A9821065674; Fri, 19 Aug 2011 18:43:56 +0000 (UTC) (envelope-from aboutbus@gmail.com) Received: from mail-yx0-f182.google.com (mail-yx0-f182.google.com [209.85.213.182]) by mx1.freebsd.org (Postfix) with ESMTP id E9FC88FC13; Fri, 19 Aug 2011 18:43:55 +0000 (UTC) Received: by yxn22 with SMTP id 22so1695352yxn.13 for ; Fri, 19 Aug 2011 11:43:55 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=E0fcTRmii/3+bnjkHOM6rK8xlYkxKk5SkKGs+TzFe3k=; b=wuAVrrwOIBK3jeQ1jnm39VRdKCqUAHlg69JKIcNFYvDcrJ1Dv1ADfWYXdnjkRD7u3b VdpwjaqYaxjM0jzy2PpB3rtjsHXjOZ3OFDYnH0fiV2H0NM+wVjqVAP9m6yhQH7Z0do/i dNXmV4RVw/rtDS2+SHLk/Q3E+mtyhCgR5iIu8= MIME-Version: 1.0 Received: by 10.236.195.73 with SMTP id o49mr621147yhn.23.1313779435156; Fri, 19 Aug 2011 11:43:55 -0700 (PDT) Received: by 10.236.110.9 with HTTP; Fri, 19 Aug 2011 11:43:55 -0700 (PDT) In-Reply-To: References: Date: Fri, 19 Aug 2011 21:43:55 +0300 Message-ID: From: about bus To: Adrian Chadd Content-Type: text/plain; charset=ISO-8859-1 X-Content-Filtered-By: Mailman/MimeDel 2.1.5 Cc: freebsd-hackers@freebsd.org Subject: Re: Kqueue + Libevent X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 19 Aug 2011 18:43:56 -0000 I've added some debug output in libevent, before and after kevent function call. ### good one request 21:30:05 evhttp_get_request_connection: fd: 196 new request from 127.0.0.1:60010 21:30:05 kq_dispatch: fd: 196 set kevent filter: EVFILT_READ flags: EV_ADD 21:30:05 kq_dispatch: fd: 196 return kevent filter: EVFILT_READ flags: 0 data: 729 21:30:05 kq_dispatch: fd: 196 set kevent filter: EVFILT_READ flags: EV_DELETE 21:30:05 kq_dispatch: fd: 196 set kevent filter: EVFILT_WRITE flags: EV_ADD 21:30:05 kq_dispatch: fd: 196 return kevent filter: EVFILT_WRITE flags: 0 data: 28672 21:30:05 kq_dispatch: fd: 196 set kevent filter: EVFILT_WRITE flags: EV_DELETE 21:30:05 kq_dispatch: fd: 196 return kevent filter: EVFILT_WRITE flags: EV_ERROR data: 9 (EBADF) ### timeouted request 21:30:06 evhttp_get_request_connection: fd: 196 new request from 127.0.0.1:64308 21:30:06 kq_dispatch: fd: 196 set kevent filter: EVFILT_READ flags: EV_ADD 21:30:36 kq_dispatch: fd: 196 return kevent filter: EVFILT_READ flags: EV_EOF data: 450 21:30:36 kq_dispatch: fd: 196 set kevent filter: EVFILT_READ flags: EV_DELETE 21:30:36 kq_dispatch: fd: 196 set kevent filter: EVFILT_WRITE flags: EV_ADD 21:30:36 kq_dispatch: fd: 196 return kevent filter: EVFILT_WRITE flags: 0 data: 28672 21:30:36 kq_dispatch: fd: 196 set kevent filter: EVFILT_WRITE flags: EV_DELETE 21:30:36 kq_dispatch: fd: 196 return kevent filter: EVFILT_WRITE flags: EV_ERROR data: 9 (EBADF) There is problem between 21:30:06 and 21:30:36 timestamps. Libevent received socket from Kqueue with EV_EOF flag when nginx has closed connection. There is 30 seconds timeout value in nginx config file. On Fri, Aug 19, 2011 at 2:10 PM, Adrian Chadd wrote: > I've not seen this happen before, are you sure that libevent's kqueue > code is properly removing all the pending events for a given FD when > it's closed? > > > On 19 August 2011 18:33, about bus wrote: > > Hello! > > > > I've got some interesting problem with my own server which use Libevent > and > > Kqueue. > > Kqueue holds some sockets for a long time (while reading data) and gives > it > > back to application when another side closes connection. > > > > I have server with FreeBSD 7.2 which serves several thousands requests > per > > second. > > Nginx -> statical requests, images > > -> backend for dynamical requests: Libevent based http server > > written on C > > > > Sometimes, about 0.1% of request, Nginx displays error: "Operation timed > out > > while reading response from upstream." > > Switching Libevent from Kqueue to Poll in my http server fixes the > problem. > > Poll works fine without errors in Nginx log file. > > > > Debug output for timeouted requests from Libevent: > > 1) Libevent accepts incoming connection from Nginx. > > 2) Libevent adds socket to Kqueue for waiting incoming data with HTTP > > request. > > 3) No events on socket for 60 seconds, no received data. (60 - timeout > value > > in Nginx config) > > 4) On the another side Nginx closes connection and displays timeout > error. > > 5) At the same time Kqueue reports about incoming data and returns socket > to > > Libevent. > > 6) Libevent reads correct HTTP request from socket and passes it to my > > handler. > > > > Why Kqueue does not reports about read event for so long time? > > Why Kqueue do it only when another side closes connection? > > It is strange, because Poll does not have such problems. > > _______________________________________________ > > freebsd-hackers@freebsd.org mailing list > > http://lists.freebsd.org/mailman/listinfo/freebsd-hackers > > To unsubscribe, send any mail to " > freebsd-hackers-unsubscribe@freebsd.org" > > >