From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on dcvr.yhbt.net X-Spam-Level: X-Spam-ASN: AS3561 63.128.0.0/15 X-Spam-Status: No, score=-0.5 required=3.0 tests=AWL,BAYES_00,URIBL_BLOCKED, URIBL_DBL_ABUSE_REDIR shortcircuit=no autolearn=ham version=3.3.2 X-Original-To: unicorn-public@bogomips.org Received: from us-smtp-delivery-110.mimecast.com (us-smtp-delivery-110.mimecast.com [63.128.21.110]) by dcvr.yhbt.net (Postfix) with ESMTP id BC1C41F49F for ; Wed, 4 Mar 2015 20:27:42 +0000 (UTC) Subject: Re: Request Queueing after deploy + USR2 restart Received: from mail-qc0-f180.google.com (mail-qc0-f180.google.com [209.85.216.180]) (Using TLS) by us-mta-18.us.mimecast.lan; Wed, 04 Mar 2015 15:27:40 -0500 Received: by qcvx3 with SMTP id x3so11377818qcv.8 for ; Wed, 04 Mar 2015 12:27:40 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:date :message-id:subject:from:to:cc:content-type; bh=w9jKiHzKUNn5ZzAzJuRiSvYZ/7qAHClrxmO6UVN/+Mg=; b=Kpz1HQrkbrK9dnuuK0VSJu0ma9XJc8tE08XX7EQ76NSBZJK+yQ1sIXMFln2WvjqlKy 3TVfH97p2ozkid6s1Ti7qIYSlR3+tv7gvBPl3FX3ENom7MoScWFz5Yyvq7Up7wJscXJL xkb/OUeeySMZeN34os+RIzhyvg1C4DvWmOEJCP3Pxt4FcOFre0lrIZD8dmwjxRhA2iA4 U5xtlL4McEelxqCXlcKjfWyo7uxWsbeYhn+7BVkfTLLWSVxhvUe2BH6b1LJck7Ze2McV D3J46MoY1+xd3zz1CHAsJRio3gyPWnrN2MFgKD3yczjvq08yH1Lsk5e+0lrBMIfKc1sy 4m/A== X-Gm-Message-State: ALoCoQmj+dy4ODp3nOfQZsBbXEnizKdX+ZlUsMFXsxs1jrV4FrinjpYdUWTaLZTI2T6NUqeVx5RiEXm3+BhfIMNfzgWdJfNjxO4I1Gd0kY4Km5w2n2LA+MYB9pEc3QuYlNPAK9l4JXfWJYa/nBmbufA78bM31GHu9baUxi7y9/+iddnQvvsJybw= X-Received: by 10.55.18.14 with SMTP id c14mr10829415qkh.25.1425500860038; Wed, 04 Mar 2015 12:27:40 -0800 (PST) MIME-Version: 1.0 X-Received: by 10.55.18.14 with SMTP id c14mr10829399qkh.25.1425500859920; Wed, 04 Mar 2015 12:27:39 -0800 (PST) Received: by 10.140.48.97 with HTTP; Wed, 4 Mar 2015 12:27:39 -0800 (PST) In-Reply-To: References: Date: Wed, 4 Mar 2015 12:27:39 -0800 Message-ID: From: Michael Fischer To: Sarkis Varozian Cc: unicorn-public X-MC-Unique: JNvR0VhPSFyRt5F5zQ1ynA-1 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable X-Content-Filtered-By: PublicInbox::Filter 0.0.1 List-Id: before_fork should work fine. The children which will actually handle the requests will inherit everything from the parent, including any libraries that were loaded by the master process as a result of handling the mock requests. It'll also conserve memory, which is a nice benefit. On Wed, Mar 4, 2015 at 12:24 PM, Sarkis Varozian wrote: > That does make sense - I was looking at another suggestion from a user > here (Braulio) of running a "warmup" using rack MockRequest: > https://gist.github.com/brauliobo/11298486#file-unicorn-conf-rb-L77 > > The only issue I am having with the above solution is it is happening in > the before_fork block - shouldn't I warmup the connection in after_fork? = If > I follow the above gist properly it warms up the server with the old > activerecord base connection and then its turned off, then turned back on > in after_fork. I think I am not understanding the sequence of events > there... If this is the case, I should warmup and also check/kill the old > master in the after_fork block after the new db, redis, neo4j connections > are all created. Thoughts? > > On Wed, Mar 4, 2015 at 12:17 PM, Michael Fischer > wrote: > >> I'm not exactly sure how preload_app works, but I suspect your app is >> lazy-loading a number of Ruby libraries while handling the first few >> requests that weren't automatically loaded during the preload process. >> >> Eric, your thoughts? >> >> --Michael >> >> On Wed, Mar 4, 2015 at 11:58 AM, Sarkis Varozian >> wrote: >> >>> Yes, preload_app is set to true, I have not made any changes to the >>> unicorn.rb from OP: http://goo.gl/qZ5NLn >>> >>> Hmmmm, you may be onto something - Here is the i/o metrics from the >>> server with the highest response times: http://goo.gl/0HyUYt (in this >>> graph: http://goo.gl/x7KcKq) >>> >>> Looks like it may be i/o related as you suspect - is there much I can d= o >>> to alleviate that? >>> >>> On Wed, Mar 4, 2015 at 11:51 AM, Michael Fischer >>> wrote: >>> >>>> What does your I/O latency look like during this interval? (iostat -x= k >>>> 10, look at the busy %). I'm willing to bet the request queueing is >>>> strongly correlated with I/O load. >>>> >>>> Also is preload_app set to true? This should help. >>>> >>>> --Michael >>>> >>>> On Wed, Mar 4, 2015 at 11:48 AM, Sarkis Varozian >>>> wrote: >>>> >>>>> Michael, >>>>> >>>>> Thanks for this - I have since changed the way we are restarting the >>>>> unicorn servers after a deploy by changing capistrano task to do: >>>>> >>>>> in :sequence, wait: 30 >>>>> >>>>> We have 4 backends and the above will restart them sequentially, >>>>> waiting 30s (which I think should be more than enough time), however,= I >>>>> still get the following latency spikes after a deploy: >>>>> http://goo.gl/tYnLUJ >>>>> >>>>> This is what the individual servers look like for the same time >>>>> interval: http://goo.gl/x7KcKq >>>>> >>>>> >>>>> >>>>> On Tue, Mar 3, 2015 at 2:32 PM, Michael Fischer >>>>> wrote: >>>>> >>>>>> If the response times are falling a minute or so after the reload, >>>>>> I'd chalk it up to a cold CPU cache. You will probably want to stag= ger >>>>>> your reloads across backends to minimize the impact. >>>>>> >>>>>> --Michael >>>>>> >>>>>> On Tue, Mar 3, 2015 at 2:24 PM, Sarkis Varozian >>>>>> wrote: >>>>>> >>>>>>> We have a rails application with the following unicorn.rb: >>>>>>> http://goo.gl/qZ5NLn >>>>>>> >>>>>>> When we deploy to the application, a USR2 signal is sent to the >>>>>>> unicorn >>>>>>> master which spins up a new master and we use the before_fork in th= e >>>>>>> unicorn.rb config above to send signals to the old master as the ne= w >>>>>>> workers come online. >>>>>>> >>>>>>> I've been trying to debug a weird issue that manifests as "Request >>>>>>> Queueing" in our Newrelic APM. The graph shows what happens after a >>>>>>> deployment (represented by the vertical lines). Here is the graph: >>>>>>> http://goo.gl/iFZPMv . As you see from the graph, it is >>>>>>> inconsistent - >>>>>>> there is always a latency spike - however, at times Request Queuein= g >>>>>>> is >>>>>>> higher than previous deploys. >>>>>>> >>>>>>> Any ideas on what exactly is going on here? Any suggestions on >>>>>>> tools/profilers to use to get to the bottom of this? Should we >>>>>>> expect this >>>>>>> to happen on each deploy? >>>>>>> >>>>>>> Thanks, >>>>>>> >>>>>>> -- >>>>>>> *Sarkis Varozian* >>>>>>> svarozian@gmail.com >>>>>>> >>>>>>> >>>>>>> >>>>>> >>>>> >>>>> >>>>> -- >>>>> *Sarkis Varozian* >>>>> svarozian@gmail.com >>>>> >>>> >>>> >>> >>> >>> -- >>> *Sarkis Varozian* >>> svarozian@gmail.com >>> >> >> > > > -- > *Sarkis Varozian* > svarozian@gmail.com >