cant store article: bogus Xref: header in INN 2.5 ?

Fri Sep 2 19:14:59 UTC 2011

Hi Matija,

>> So, hmm...  Maybe you could upgrade your newsfeed server to 2.5.2-2~squeeze1;
>> I bet it will directly solve the issue for your slave server :-)
> 
> I do understand that would be easier way out -- if your bet is correct, but as
> I only have redundancy for xrefslave servers and not for the feeder, I'd very
> much first like to test and then let users hammer those for at least a month
> or two before trying to upgrade newsfeed (so I can fallback to 2.4.6 server if
> anything go wrong -- as I'm doing just now).
> 
> I guess I'm just not much of a betting man :-)

Well, I perfectly understand your point.
Besides, my yesterday's mistake does not work in my favour...

Anyway, in case it could be of help to decide between an upgrade of newsfeed
to 2.5.2-2~squeeze1 and a patch added to your 2.5.2-2~squeeze1 slave, here are
the results of a few tests.

2.4.6 -> leading spaces in Xref: header field are kept.
2.5.0 -> leading spaces in Xref: header field are removed.
2.5.3 -> leading spaces in Xref: header field are removed.

It confirms the change of behaviour in the 2.5 branch, since 2.5.0.
2.5.2-2~squeeze1 will also remove leading spaces in Xref: header.

200 denver.dinauz.org InterNetNews server INN 2.4.6 ready
IHAVE <ITv0a$3test at news.trigofacile.com4>
335
Path: pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      plop.plop.test    trigofacile.test:510

plop
.
235
HEAD <ITv0a$3test at news.trigofacile.com4>
221 0 <ITv0a$3test at news.trigofacile.com4>
Path: denver.dinauz.org!pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      denver.dinauz.org trigofacile.test:1

.
QUIT
205 .

-----------------------------------------------------------------------------------

200 denver.dinauz.org InterNetNews server INN 2.5.0 ready
IHAVE <ITv0a$3test at news.trigofacile.com4>
335
Path: pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      plop.plop.test    trigofacile.test:510

plop
.
235
HEAD <ITv0a$3test at news.trigofacile.com4>
221 0 <ITv0a$3test at news.trigofacile.com4>
Path: denver.dinauz.org!pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref: denver.dinauz.org trigofacile.test:1
.
QUIT
205 .

-----------------------------------------------------------------------------------

200 news.trigofacile.com InterNetNews server INN 2.5.3 (rc1 version) ready (transit mode)
IHAVE <ITv0a$3test at news.trigofacile.com4>
335 Send it
Path: pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      plop.plop.test    trigofacile.test:510

plop
.
235 Article transferred OK
HEAD <ITv0a$3test at news.trigofacile.com4>
221 0 <ITv0a$3test at news.trigofacile.com4> head
Path: news.trigofacile.com!pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref: news.trigofacile.com trigofacile.test:515
.
QUIT
205 Bye!

-----------------------------------------------------------------------------------

And another point...
With an unpatched INN 2.5.3 *running in slave mode*:

200 news.trigofacile.com2 InterNetNews server INN 2.5.3 (rc1 version) ready (transit mode)
IHAVE <ITv0a$3test at news.trigofacile.com4>
335 Send it
Path: pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      plop.plop.test    trigofacile.test:510

plop
.
436 cant store article
QUIT
205 Bye!

Error is:

Sep  2 20:44:01 news innd: SERVER bad_format plop.plop.test
Sep  2 20:44:01 news innd: SERVER cant store article: bogus Xref: header

With a new patch (not yet posted here), I have in slave mode

200 news.trigofacile.com2 InterNetNews server INN 2.5.3 (rc1 version) ready (transit mode)
IHAVE <ITv0a$3test at news.trigofacile.com4>
335 Send it
Path: pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com4>
Xref:      plop.plop.test    trigofacile.test:510

plop
.
235 Article transferred OK
head <ITv0a$3test at news.trigofacile.com4>
221 0 <ITv0a$3test at news.trigofacile.com4> head
Path: news.trigofacile.com2!pouet!test
From: =?ISO-8859-15?Q?Julien_=C9LIE?= <iulius at nom-de-mon-site.com.invalid>
Newsgroups: trigofacile.test
Subject: test
Date: Wed, 30 Aug 2011 16:19:01 +0200 (CEST)
Message-ID: <ITv0a$3test at news.trigofacile.com10>
Xref:      plop.plop.test    trigofacile.test:510
.
QUIT
205 Bye!

Seems pretty good.

> With the "bogus Xref: header" problem found, what still worries me is why
> the server sometimes (but not always) decided to throttle with the
> "Interrupted system call writing SMstore file -- throttling" in the same
> second as "bogus Xref: header" hit?
> 
> More precisely, would fixing the "bogus Xref: header" also fix all cases
> leading to server auto-throttling, or may there be there some other possibile
> vectors for server to auto-throttle when receiving just one invalid article?

I think you will be reassured by knowing that innd throttles itself
if it has already been through 50 errors.

storage/tradspool/tradspool.c:

    if ((xrefs = CrackXref(xrefhdr, &numxrefs)) == NULL || numxrefs == 0) {
[...]
        token.type = TOKEN_EMPTY;
        SMseterror(SMERR_UNDEFINED, "bogus Xref: header");

innd/art.c:

  if (result.type == TOKEN_EMPTY) {
    if (SMerrno == SMERR_NOMATCH)
      ThrottleNoMatchError();
    else if (SMerrno != SMERR_NOERROR)
      IOError("SMstore", SMerrno);

innd/innd.h:

/*
**  Mark that an I/O error occurred, and block if we got too many.
*/
#define IOError(WHEN, e)                    \
  do {                                      \
    if (--ErrorCount <= 0 || (e) == ENOSPC) \
      ThrottleIOError(WHEN);                \
  } while (0)

And finally in inn/options.h:

#define IO_ERROR_COUNT          50

Have a nice week-end,

-- 
Julien ÉLIE

« Encore un peu, et cette histoire finira en queue de poisson ! »
  (Astérix)