From mboxrd@z Thu Jan 1 00:00:00 1970 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on dcvr.yhbt.net X-Spam-Level: X-Spam-ASN: AS14383 205.234.109.0/24 X-Spam-Status: No, score=0.0 required=3.0 tests=none shortcircuit=no autolearn=unavailable version=3.3.2 Path: news.gmane.org!not-for-mail From: chris mckenzie Newsgroups: gmane.comp.lang.ruby.rainbows.general Subject: Page request roundtrip time increases substantially after a bit of use Date: Mon, 24 Jan 2011 13:03:25 -0800 (PST) Message-ID: <571697.98064.qm@web63303.mail.re1.yahoo.com> NNTP-Posting-Host: lo.gmane.org Mime-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit X-Trace: dough.gmane.org 1295903924 23726 80.91.229.12 (24 Jan 2011 21:18:44 GMT) X-Complaints-To: usenet@dough.gmane.org NNTP-Posting-Date: Mon, 24 Jan 2011 21:18:44 +0000 (UTC) To: rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org Original-X-From: rainbows-talk-bounces-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org Mon Jan 24 22:18:40 2011 Return-path: Envelope-to: gclrrg-rainbows-talk@m.gmane.org X-Original-To: rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org Delivered-To: rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s1024; t=1295903005; bh=tJY/gnNj4Rrr+gVwJApNruAepvqqO/pE37PVP/lw3n8=; h=Message-ID:X-YMail-OSG:Received:X-Mailer:Date:From:Subject:To:MIME-Version:Content-Type; b=x3hGX9fjYUJfbfKcFnoe3sXYpBCGHba7yr3QEailJnhx/HJVE/2/3gRW/VaEPAjELJmlR4Z3feCA5PdZbsjH1sq7Vk80FNIR4fNsNrSeD/taLmMUmfXxHK5Tpo0oM2n9kKEWmRv55MXH3GQNjP+NTszWFHMjn2Wf55Lj9iYAQAA= DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; h=Message-ID:X-YMail-OSG:Received:X-Mailer:Date:From:Subject:To:MIME-Version:Content-Type; b=k8naD47X566+aLZ+Li4uwnYMmCenrl/sPx4VwOODy4rQCX5Mjz/mEKu19xl2/VTTPr8w337vszyqDW9zZHsdi0iTlaIY009h7x2g2/PIYM+2yU9hXzo2v9fX7ByHlOZxklNr/IkycYSGbHaT3nAA3sFass0XbEEj5OWJIFT6Fck=; X-YMail-OSG: xgAUW2MVM1lRoOVdQjCYGyUfkh1EyTNpF4MXa.vnRMYJ1RP p4wr30qBHlkk9ViQQkrGLOchJ2btc9yAAcITxYM5bugc3jo.z0w.uGSdPzip stZJjKN_WjE.ap_hc_Qz1Ml5ZgBChMDEoK8wvLj9bN9Z02__z2pDTPxXMByx Bd6sB22zjRHePsszx.qNKkWAwwOqa7zJw455n7tMqpsgckgfU0FevzxXW0J2 K1xz1NsMsRSVxSE3K81KkiCGLOscVzVJhVLI4zM_bGIXMLTAMDQDzFoSSTrW 6QI2DNaONEjHLK._MfyMgalaGPPTIWGcx.KI8CeF9qAoB_.3a.TE.Ozh.IjP SkpM6azoGvjlKFfnIUBXtF083 X-Mailer: YahooMailRC/555 YahooMailWebService/0.8.107.285259 X-BeenThere: rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org X-Mailman-Version: 2.1.12 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Original-Sender: rainbows-talk-bounces-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org Errors-To: rainbows-talk-bounces-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org Xref: news.gmane.org gmane.comp.lang.ruby.rainbows.general:196 Archived-At: Received: from rubyforge.org ([205.234.109.19]) by lo.gmane.org with esmtp (Exim 4.69) (envelope-from ) id 1PhTo6-0001M8-Up for gclrrg-rainbows-talk@m.gmane.org; Mon, 24 Jan 2011 22:18:39 +0100 Received: from rubyforge.org (rubyforge.org [127.0.0.1]) by rubyforge.org (Postfix) with ESMTP id AC0161858363; Mon, 24 Jan 2011 16:18:35 -0500 (EST) Received: from web63303.mail.re1.yahoo.com (web63303.mail.re1.yahoo.com [69.147.97.28]) by rubyforge.org (Postfix) with SMTP id D5319185834E for ; Mon, 24 Jan 2011 16:03:25 -0500 (EST) Received: (qmail 98988 invoked by uid 60001); 24 Jan 2011 21:03:25 -0000 Received: from [173.243.145.79] by web63303.mail.re1.yahoo.com via HTTP; Mon, 24 Jan 2011 13:03:25 PST --- Note --- I'm sorry if you get this twice. I was sending this email from Yahoo, and I guess they defaulted to HTML for the mail. My apologies if this was the case. If not, please ignore this message. Thank you for your time. --- Note --- Hi, First of all, let me thank all of you for creating such a wonderful product. Rainbows is a unique solution and is the perfect candidate to solve our complex problems. I don't know where this current project could possibly be without your fine work. :-) Now about the problem. First a little background on the architecture, so you can get the context: I'm dealing with some code that I can't just legally paste for example (although I can probably make a simple proof of concept if needed) ... Here's the design: I have a cascading long-poll connection, which listens for various JSON messages. The throughput is quite low (a few a second) and I have a policy of falling over based on either a large amount of traffic, or a predefined amount of time (30 seconds) lapsing. Essentially I have a 30 second connection and at second 25, a new one opens up ... the first one closes, and that one lasts for 30 seconds, etc. This is designed for web browsers and it's implemented through hidden iframes. This is a problem that has persisted across Firefox 3.6/OS X and Firefox 3.6/XP and Firefox 4.0b6/XP along with IE8/XP and Chrome/OS X and FF 3.6/Ubuntu so I don't think that any nuance of a browser or OS could be considered culpable. I'm also not using any middle webserver like nginx and am connecting directly to rainbows! *** The Problem *** When serving static files along with my long polled connections, I will get a round trip time of ten millisecond or so, usually. This is perfectly acceptable. Every now and then, however, it will be about 2.5 seconds. This will then be followed by a bunch of the snappy millisecond level transaction times. This is one browser with 1 persistent connection against rainbows configured with 10 worker_processes and 100 worker_connections. Everything changes about 5-10 minutes into things. Then every transaction takes about 2-4 seconds. Static files that are 10 bytes in size, 2-4 seconds. Ruby code to emit "Hello World"? 2-4 seconds. Every request. Still using just 1 browser. After I exit all browsers and then do a netstat on the client machine to see that the connections have closed, I can then do a curl command for a static file; again 2-4 seconds. On the machine running rainbows if I do a netstat, I get this: tcp 1 0 10.10.192.12:7788 10.10.131.165:17443 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17352 CLOSE_WAIT tcp 1 196 10.10.192.12:7788 10.10.131.165:17317 CLOSE_WAIT tcp 1 196 10.10.192.12:7788 10.10.131.165:17310 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17437 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17366 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17410 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17447 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17357 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17449 CLOSE_WAIT tcp 1 0 10.10.192.12:7788 10.10.131.165:17347 CLOSE_WAIT ^^^ rainbows is running on 7788 on this machine ^^^. The reference machine, in this case, windows, claims that all the connections are closed: Proto Local Address Foreign Address State TCP 0.0.0.0:80 0.0.0.0:0 LISTENING TCP 0.0.0.0:135 0.0.0.0:0 LISTENING TCP 0.0.0.0:443 0.0.0.0:0 LISTENING TCP 0.0.0.0:445 0.0.0.0:0 LISTENING TCP 0.0.0.0:6060 0.0.0.0:0 LISTENING TCP 0.0.0.0:63508 0.0.0.0:0 LISTENING TCP 10.10.131.165:139 0.0.0.0:0 LISTENING TCP 10.10.131.165:16841 187.39.33.180:11827 ESTABLISHED TCP 10.10.131.165:16844 69.63.181.105:5222 ESTABLISHED TCP 10.10.131.165:16849 10.10.10.71:5222 ESTABLISHED TCP 10.10.131.165:16883 64.12.29.50:443 ESTABLISHED TCP 10.10.131.165:16904 64.12.28.222:443 ESTABLISHED TCP 10.10.131.165:16915 64.12.165.99:443 ESTABLISHED TCP 10.10.131.165:16918 64.12.202.37:443 ESTABLISHED TCP 10.10.131.165:16958 205.188.248.151:443 ESTABLISHED TCP 10.10.131.165:16961 205.188.254.83:443 ESTABLISHED TCP 10.10.131.165:17102 10.10.131.136:22 ESTABLISHED TCP 10.10.131.165:17466 10.10.192.12:22 ESTABLISHED TCP 10.10.131.165:17470 10.0.0.29:515 SYN_SENT TCP 127.0.0.1:1030 0.0.0.0:0 LISTENING TCP 192.168.56.1:139 0.0.0.0:0 LISTENING TCP [::]:135 [::]:0 LISTENING 0 I can disconnect the windows client machine; turn it off even, and this problem persists. I think that somewhere in the ruby stack, the connections are not closing. If I increase my worker_process count and prolong the long poll, then yes, I'll survive for 15 minutes instead of 5; but the problem will still eventually occur and I will hit the wall. I have yet to try to test unicorn or zbatery for this style of solution because I need the keep-alive; and although I know that unicorn put in the keep-alive support for rainbows, I haven't really taken the time necessary to know how to invoke it. If you think this would be instructive, I'd be happy to do so. As far as my ruby set-up, I'm using ruby1.8 and I have the ThreadSpawn model. We are running on a modern version of Ubuntu without any serious customization. If you think that another configuration would do the trick or if you know how to squash this bug, it would be very helpful. This problem has become of great concern for us. We love rainbows and all that it is. Thanks for the project and keep up the good work. Cheers, ~chris. _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying