From: Jonathan Corbet <corbet@lwn.net>
To: Eric Wong <e@80x24.org>
Cc: meta@public-inbox.org
Subject: Re: Race condition in public-inbox-nntpd?
Date: Tue, 16 Oct 2018 08:04:27 -0600 [thread overview]
Message-ID: <20181016080427.6cce2765@lwn.net> (raw)
In-Reply-To: <20181016063620.bm34ts45yp5irqmh@untitled>
On Tue, 16 Oct 2018 06:36:20 +0000
Eric Wong <e@80x24.org> wrote:
> Jonathan Corbet <corbet@lwn.net> wrote:
> > So for a little while, I've been seeing occasional NNTP weirdness,
> > associated with log lines like:
> >
> > Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: error from:
> > XOVER 196731-196731 (BUG: nested long response at /usr/local/share/perl5/PublicInbox/NNTP.pm line 588.
> >
> > Such complaints tend to be immediately followed by significant
> > disgruntlement on the client side.
>
> Do you have any logs of client commands which hit this?
I'll attach a snippet. The pattern always looks about the same - a lot of
XOVER commands; at some point they start failing.
> Any relation to group size in reproducing this?
It tends to happen on big groups, but the real common factor seems to be a
lot of saved messages, resulting in a lot of single-article XOVER commands
in rapid sequence.
> I stared at it some, too; but I'm not seeing it right now, either;
> but it's been a tiring few weeks for me so I'm not at my sharpest.
I can relate to that!
Thanks,
jon
Oct 13 18:01:04 archive.lwn.net public-inbox-nntpd[12352]: [6] 1 GROUP lwn.kernel.lkml - 0.001696
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 153433-153447 - 0.087349 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 158027-158032 - 0.009294 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 181909-181914 - 0.009046 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 182996-183003 - 0.010729 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 187687-187687 - 0.001941 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188205-188205 - 0.003165 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188351-188351 - 0.002194 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188571-188573 - 0.005668 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188580-188580 - 0.001533 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188680-188684 - 0.005570 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188691-188697 - 0.008083 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188792-188792 - 0.003481 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188798-188798 - 0.001609 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188808-188808 - 0.001487 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188818-188818 - 0.002147 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 188841-188841 - 0.001679 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189272-189272 - 0.001514 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189524-189528 - 0.008616 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189547-189547 - 0.001627 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189736-189736 - 0.002618 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189868-189877 - 0.012032 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 189950-189952 - 0.004263 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190022-190022 - 0.001705 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190123-190123 - 0.001533 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190207-190207 - 0.001467 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190224-190224 - 0.002197 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190452-190452 - 0.001644 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190603-190603 - 0.001524 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 190771-190773 - 0.003532 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 191276-191276 - 0.001874 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 191290-191290 - 0.001543 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 191448-191448 - 0.001545 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 191519-191519 - 0.001578 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 192078-192078 - 0.001462 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 192278-192278 - 0.001610 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 192385-192385 - 0.001401 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 192458-192458 - 0.001678 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 192534-192534 - 0.001726 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 193216-193224 - 0.009579 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 193719-193719 - 0.001444 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 193736-193743 - 0.008615 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194152-194152 - 0.001519 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194261-194264 - 0.004747 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194371-194371 - 0.001522 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194390-194390 - 0.001397 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194840-194856 - 0.017661 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 194991-195022 - 0.031130 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 0 XOVER 196023-196023 - 0.001578 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: error from: XOVER 196034-196034 (BUG: nested long response at /usr/local/share/perl5/PublicInbox/NNTP.pm line 588.
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: )
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 1 XOVER 196034-196034 - 0.000694 deferred[6]
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: error from: XOVER 196073-196073 (BUG: nested long response at /usr/local/share/perl5/PublicInbox/NNTP.pm line 588.
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: )
Oct 13 18:01:06 archive.lwn.net public-inbox-nntpd[12352]: [6] 1 XOVER 196073-196073 - 0.000563 deferred[6]
next prev parent reply other threads:[~2018-10-16 14:04 UTC|newest]
Thread overview: 4+ messages / expand[flat|nested] mbox.gz Atom feed top
2018-10-13 18:46 Race condition in public-inbox-nntpd? Jonathan Corbet
2018-10-16 6:36 ` Eric Wong
2018-10-16 14:04 ` Jonathan Corbet [this message]
2018-12-06 3:59 ` [PATCH] nntp: prevent event_read from firing twice in a row Eric Wong
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
List information: https://public-inbox.org/README
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20181016080427.6cce2765@lwn.net \
--to=corbet@lwn.net \
--cc=e@80x24.org \
--cc=meta@public-inbox.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
Code repositories for project(s) associated with this public inbox
https://80x24.org/public-inbox.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).