From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on dcvr.yhbt.net X-Spam-Level: X-Spam-ASN: AS3215 2.6.0.0/16 X-Spam-Status: No, score=-3.2 required=3.0 tests=AWL,BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_NONE, SPF_HELO_NONE,SPF_PASS shortcircuit=no autolearn=ham autolearn_force=no version=3.4.2 Received: from mail-io1-xd42.google.com (mail-io1-xd42.google.com [IPv6:2607:f8b0:4864:20::d42]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by dcvr.yhbt.net (Postfix) with ESMTPS id 6840B1F463 for ; Tue, 10 Sep 2019 08:38:25 +0000 (UTC) Received: by mail-io1-xd42.google.com with SMTP id f4so34922892ion.2 for ; Tue, 10 Sep 2019 01:38:25 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linuxfoundation.org; s=google; h=date:from:to:cc:subject:message-id:mail-followup-to:references :mime-version:content-disposition:in-reply-to:user-agent; bh=glSUWilXFeKKafoXIW3zbGojUwRJ0jlgZ1RoN8tbhNM=; b=Gv1V1BXSrzGTyAIUEfZCFuKwfZVhhZo9LasOjOXQnJSgtVcYDqcgz3oG4o5oyd3r3B 6VPRwfgmetMVX3MR2AzcOMSL1eRaXdLXNaEuqlYKzuL9j2OzaShop1q5B0KIZVrY7/M/ esfRJUGRhc0bkpU+uQn7Jao8W6HR9jhmCTIZs= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:subject:message-id :mail-followup-to:references:mime-version:content-disposition :in-reply-to:user-agent; bh=glSUWilXFeKKafoXIW3zbGojUwRJ0jlgZ1RoN8tbhNM=; b=dGfb6qsJYnTywppFZ84pV4/dgI6/KX9TKXrkN9fRfqUX9CzgApM2LgOJTBz2e7YSFW kFePjtTZbsiMVuOyagE55QxP7bmdxZ151sYA+gEBS0HVNNUsmsXII68pCkOAUtaalG1y ZN43APciJ1HB/NrP+Sj8fTCzJ7bILRnLthshibTCi5kJiu3TbZ6mFK1cyBs66EgFv5WF Zzwl6ZufXG8XKBSptqv3T7A1Rn7wRjuEuhvYMYrJDUFIuhNSlR/+uQbgsUpRSNaSbakY +nvksRRvqXa6Ws4LUctrhMChVo5hcO/Ye9PGHtxv82/EKl2SuWh10vMV+bI+j/s75Pjf KS4w== X-Gm-Message-State: APjAAAULEYIaSV8hkZ3+h432i3jx+yAHCOtHGo9uj3IYkscdLCHVLe5L +DySAPMVana/Tg4pWQLX47P5xQ== X-Google-Smtp-Source: APXvYqyBVwdaMU+3lsZeGAeUOS+oijT06W22eyXuvtt3cO2/LXt4PgUitxbgaRQ2LAsb5yRXGqbj/g== X-Received: by 2002:a6b:b792:: with SMTP id h140mr3173009iof.225.1568104704660; Tue, 10 Sep 2019 01:38:24 -0700 (PDT) Received: from pure.paranoia.local ([87.101.92.157]) by smtp.gmail.com with ESMTPSA id g4sm12177975ion.26.2019.09.10.01.38.23 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Tue, 10 Sep 2019 01:38:23 -0700 (PDT) Date: Tue, 10 Sep 2019 04:38:20 -0400 From: Konstantin Ryabitsev To: Eric Wong Cc: meta@public-inbox.org Subject: Re: trying to figure out 100% CPU usage in nntpd... Message-ID: <20190910083820.GA8018@pure.paranoia.local> Mail-Followup-To: Eric Wong , meta@public-inbox.org References: <20190908104518.11919-1-e@80x24.org> <20190908105243.GA15983@dcvr> <20190909100500.GA9452@pure.paranoia.local> <20190909175340.u5aq4ztfzukko7zb@dcvr> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline In-Reply-To: <20190909175340.u5aq4ztfzukko7zb@dcvr> User-Agent: Mutt/1.12.1 (2019-06-15) List-Id: On Mon, Sep 09, 2019 at 05:53:41PM +0000, Eric Wong wrote: > Konstantin Ryabitsev wrote: > > There also was a weird problem a couple of days ago where one of the > > httpd daemons started returning "Internal Server Error" to all requests. > > Restarting public-inbox-httpd fixed the problem, but I am not sure how I > > would troubleshoot the causes if it happens next time -- is there a way > > to enable error logging for the httpd daemon? > > That's a new one... I haven't seen any problems from -httpd myself > in ages. So -httpd could not handle requests at all? > > The daemons already spits errors to stderr which typically ends up > in syslog via systemd. So, that's the first place to look > (also "systemctl status $SERVICE"); anything in there? Bah, I hadn't even considered looking in syslog. I blame jet lag. Well, the explanation is simple, then: Sep 7 22:22:35 lore.kernel.org public-inbox-httpd: pipe failed: Too many open files at /usr/local/share/perl5/PublicInbox/Git.pm line 210. Sep 7 22:22:36 lore.kernel.org public-inbox-httpd: pipe: Too many open files Sep 7 22:23:01 lore.kernel.org public-inbox-httpd: pipe: Too many open files Sep 7 22:23:02 lore.kernel.org public-inbox-httpd: pipe: Too many open files Sep 7 22:23:02 lore.kernel.org public-inbox-httpd: pipe: Too many open files I see that there's already a LimitNOFILE=30000 -- is exhausting 30,000 open files a reasonable sort of thing for a system as busy as lore.kernel.org, or should we look for a leak. Currently: publici+ 13125 1 0 52297 25096 0 Sep09 ? 00:00:00 /usr/bin/perl -w /usr/local/bin/public-inbox-httpd -W4 -1 /var/log/public-inbox/httpd.out.log publici+ 13128 13125 1 200056 591376 4 Sep09 ? 00:21:06 /usr/bin/perl -w /usr/local/bin/public-inbox-httpd -W4 -1 /var/log/public-inbox/httpd.out.log publici+ 13129 13125 1 117789 262000 2 Sep09 ? 00:16:09 /usr/bin/perl -w /usr/local/bin/public-inbox-httpd -W4 -1 /var/log/public-inbox/httpd.out.log publici+ 13130 13125 0 103569 204772 9 Sep09 ? 00:08:06 /usr/bin/perl -w /usr/local/bin/public-inbox-httpd -W4 -1 /var/log/public-inbox/httpd.out.log publici+ 13131 13125 0 101510 199268 1 Sep09 ? 00:03:33 /usr/bin/perl -w /usr/local/bin/public-inbox-httpd -W4 -1 /var/log/public-inbox/httpd.out.log # ls /proc/13125/fd/ | wc -l 9 # ls /proc/13128/fd/ | wc -l 17776 # ls /proc/13129/fd/ | wc -l 3937 # ls /proc/13130/fd/ | wc -l 648 # ls /proc/13131/fd/ | wc -l 68 17776 since Sep 09 seems... fairly excessive. Most of them are pipes: # lsof -p 13128 | grep pipe | wc -l 14741 a bunch of them are to (deleted) entries in /tmp: # lsof -p 13128 | grep deleted | wc -l 3015 (e.g.): public-in 13128 publicinbox 45u REG 259,4 984 4200094 /tmp/PerlIO_yd43mN (deleted) public-in 13128 publicinbox 46r FIFO 0,9 0t0 21818751 pipe public-in 13128 publicinbox 47u REG 259,4 984 4200096 /tmp/PerlIO_siY3Pb (deleted) public-in 13128 publicinbox 48r FIFO 0,9 0t0 21818758 pipe public-in 13128 publicinbox 49u REG 259,4 984 4200100 /tmp/PerlIO_WyIaaC (deleted) It does seem like there's perhaps a leak somewhere? -K