Hi all,

Jan 31 15:56:12 www innd: rejecting[perl] <T5gCL.2931033$miq3.1112593@usenetxs.com> 439 Binary: misplaced binary
Jan 31 15:56:14 www innd: rejecting[perl] <U5gCL.2931041$miq3.2915980@usenetxs.com> 439 Binary: misplaced binary

I'm getting hundreds, if not thousands of these.

It doesn't really tell me which news server is sending out misplaced
binaries or which newsgroup is the culprit.

Open to suggestions on figuring this one out. I'd really like it to
stop. I don't accept binaries for a reason. I don't have unlimited
bandwidth so I'd like to nip this junk in the bud.

Thanks,

--
End Of The Line BBS - Plano, TX
telnet endofthelinebbs.com 23

> Jan 31 15:56:12 www innd: rejecting[perl] <T5gCL.2931033$miq3.1112593@usenetxs.com> 439 Binary: misplaced binary

> It doesn't really tell me which news server is sending out misplaced
> binaries

The news log (/var/log/news/news) should tell you which peer caused the message.

> or which newsgroup is the culprit.

You could try and connect to the peer, then issue a "head <msgid>" command.

Or edit the filter and make it output the Newsgroups, too. cleanfeed sets
@groups and $sortgrps.

On Jan 31, 2023 at 3:59:25 PM CST, "Nigel Reed" <sysop@endofthelinebbs.com>
wrote:

> Hi all,
>
>
> Jan 31 15:56:12 www innd: rejecting[perl]
> <T5gCL.2931033$miq3.1112593@usenetxs.com> 439 Binary: misplaced binary
> Jan 31 15:56:14 www innd: rejecting[perl]
> <U5gCL.2931041$miq3.2915980@usenetxs.com> 439 Binary: misplaced binary
>
>
> I'm getting hundreds, if not thousands of these.
>
> It doesn't really tell me which news server is sending out misplaced
> binaries or which newsgroup is the culprit.
>
> Open to suggestions on figuring this one out. I'd really like it to
> stop. I don't accept binaries for a reason. I don't have unlimited
> bandwidth so I'd like to nip this junk in the bud.
>
> Thanks,

It is probably coming from HighWinds. They recently started leaking "alt.b" to
me as well, which looks like test traffic between two commercial providers.
I'm not propgating the articles, and have asked them to filter them out, but
no response yet.

Cheers,
Jesse

Hi,
Nigel Reed a écrit :

> Jan 31 15:56:12 www innd: rejecting[perl] <T5gCL.2931033$miq3.1112593@usenetxs.com> 439 Binary: misplaced binary
> Jan 31 15:56:14 www innd: rejecting[perl] <U5gCL.2931041$miq3.2915980@usenetxs.com> 439 Binary: misplaced binary

> I'm getting hundreds, if not thousands of these.

> It doesn't really tell me which news server is sending out misplaced
> binaries or which newsgroup is the culprit.

You can see which feed is sending that posts in /var/log/news/news but the
first server is not in the log files.

--
Stéphane
Sorry for my bad English...

yamo ' <News@pasdenom.info > writes:

> You can see which feed is sending that posts in /var/log/news/news but
> the first server is not in the log files.

The first server is to some extent fundamentally unknowable since the Path
header can be manipulated, but you could make the Perl filter log the Path
header as well if you wanted to try to track things down to that extent.

--
Russ Allbery (eagle@eyrie.org) <https://www.eyrie.org/~eagle/>

Please post questions rather than mailing me directly.
<https://www.eyrie.org/~eagle/faqs/questions.html> explains why.

Hi,
Russ Allbery a tapoté le 01/02/2023 17:01:
> The first server is to some extent fundamentally unknowable since the Path
> header can be manipulated, but you could make the Perl filter log the Path
> header as well if you wanted to try to track things down to that extent.

Yes but it may not be useful.

--
Stéphane

Hi,
Jesse Rehmer a tapoté le 01/02/2023 04:13:
> I'm not propgating the articles, and have asked them to filter them out, but
> no response yet.

There may be something wrong in your configuration.

You send me some of this :
<https://pasdenom.info/usenet/news-notice.2023.02.02-06.15.04.html#inn_unwanted>

I think there should be an entry "Binary" in this table.

Example (today) : <48a6d37ee00645eaa197950f15bd9c66@ngPost>

--
Stéphane

On Feb 3, 2023 at 3:07:10 AM CST, "yamo'" <yamo@beurdin.invalid> wrote:

> Hi,
> Jesse Rehmer a tapoté le 01/02/2023 04:13:
>> I'm not propgating the articles, and have asked them to filter them out, but
>> no response yet.
>
> There may be something wrong in your configuration.
>
> You send me some of this :
> <https://pasdenom.info/usenet/news-notice.2023.02.02-06.15.04.html#inn_unwanted>
>
> I think there should be an entry "Binary" in this table.
>
> Example (today) : <48a6d37ee00645eaa197950f15bd9c66@ngPost>

The original post was referencing "alt.b", which I was getting a ton of for
months and filtering. Your example is from a.b.erotica, and should have been
rejected by pyClean. I'm investigating, but have added more specific group
filters to your feed in the meantime.

Please reach out to me with more examples if it is still an issue.

Hi,
Jesse Rehmer a tapoté le 03/02/2023 11:23:

> The original post was referencing "alt.b", which I was getting a ton of for
> months and filtering. Your example is from a.b.erotica, and should have been
> rejected by pyClean. I'm investigating, but have added more specific group
> filters to your feed in the meantime.
>
> Please reach out to me with more examples if it is still an issue.
>

You may have found the bug, the last one filtered by cleanfeed is :

Feb 3 11:05:55.650 - usenet.blueworldhosting.com
<HX4DL.844661$US27.24444@usenetxs.com> 439 Binary: misplaced binary

Thanks!

pyClean didn't work on my server...

--
Stéphane

On Feb 3, 2023 at 4:41:53 AM CST, "yamo'" <yamo@beurdin.invalid> wrote:

> Hi,
> Jesse Rehmer a tapoté le 03/02/2023 11:23:
>
>> The original post was referencing "alt.b", which I was getting a ton of for
>> months and filtering. Your example is from a.b.erotica, and should have been
>> rejected by pyClean. I'm investigating, but have added more specific group
>> filters to your feed in the meantime.
>>
>> Please reach out to me with more examples if it is still an issue.
>>
>
> You may have found the bug, the last one filtered by cleanfeed is :
>
> Feb 3 11:05:55.650 - usenet.blueworldhosting.com
> <HX4DL.844661$US27.24444@usenetxs.com> 439 Binary: misplaced binary
>
> Thanks!
>
> pyClean didn't work on my server...

I think I figured it out, or at least I am seeing it reject misplaced binaries
now. There were no error messages to be found, but on a hunch I removed
pyclean/lib/* and restarted INN.

2023-02-03 04:45:09 INFO reject:
mid=<5b323cbb146d4e14a9ec0afabb7d3660@ngPost>, reason=Binary (yEnc)
2023-02-03 04:45:11 INFO reject: mid=<63800.TQ.20230203.114510@teamquest.pl>,
reason=EMP Body Reject

On Feb 3, 2023 at 4:47:22 AM CST, "Jesse Rehmer"
<jesse.rehmer@blueworldhosting.com> wrote:

> On Feb 3, 2023 at 4:41:53 AM CST, "yamo'" <yamo@beurdin.invalid> wrote:
>
>> Hi,
>> Jesse Rehmer a tapoté le 03/02/2023 11:23:
>>
>>> The original post was referencing "alt.b", which I was getting a ton of for
>>> months and filtering. Your example is from a.b.erotica, and should have been
>>> rejected by pyClean. I'm investigating, but have added more specific group
>>> filters to your feed in the meantime.
>>>
>>> Please reach out to me with more examples if it is still an issue.
>>>
>>
>> You may have found the bug, the last one filtered by cleanfeed is :
>>
>> Feb 3 11:05:55.650 - usenet.blueworldhosting.com
>> <HX4DL.844661$US27.24444@usenetxs.com> 439 Binary: misplaced binary
>>
>> Thanks!
>>
>> pyClean didn't work on my server...
>
> I think I figured it out, or at least I am seeing it reject misplaced binaries
> now. There were no error messages to be found, but on a hunch I removed
> pyclean/lib/* and restarted INN.
>
> 2023-02-03 04:45:09 INFO reject:
> mid=<5b323cbb146d4e14a9ec0afabb7d3660@ngPost>, reason=Binary (yEnc)
> 2023-02-03 04:45:11 INFO reject: mid=<63800.TQ.20230203.114510@teamquest.pl>,
> reason=EMP Body Reject

Cleanfeed isn't much better in this regard, but been running the latest
pyClean from https://github.com/crooks/PyClean, and the CPU consumption is
execessive for a small stream of binaries:

PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
33293 news 1 98 0 212M 152M CPU6 6 8:46 91.04%
/usr/local/news/bin/innd -u

When receiving ~10Mbps I'm highly CPU bound on a big server. Another driver
for me to keep going down the Diablo path, even though there is plenty of pain
involved. Diablo's "feeder" design is more scalable, even with Cleanfeed in
the mix, but will admit INN works best for a backend spool for me. I like
having working control message processing, Cancel-Lock support, native TLS,
etc.

Hi Jesse,

> Diablo's "feeder" design is more scalable, even with Cleanfeed in
> the mix, but will admit INN works best for a backend spool for me. I like
> having working control message processing, Cancel-Lock support, native TLS,
> etc.

FWIW, Miquel van Smoorenburg added support in INN for Diablo's hashfeed.
It's the Q flag value in newsfeeds. It permits scaling feeders like
Diablo does with backend-servers.

You may then have the following architecture:

- a front innd transit server without overview/reader/filtering, just
feeding to N internal innd feeders (using Q to split the feed in N parts
in newsfeeds; or binaries to some feeders, text to others);
- N internal innd feeders doing filtering, without overview and reader;
- a final innd/nnrpd serving server, without filtering, but numbering
and storing articles, generating overview data and handling readers.

I don't know whether it could be of help for your usage, notably for the
reduced CPU amount needed for filtering across several intermediate feeders.

--
Julien ÉLIE

« Le bonheur, c'est de continuer à désirer ce que l'on possède. »
(Saint-Augustin)

Julien ÉLIE <iulius@nom-de-mon-site.com.invalid> writes:

> I don't know whether it could be of help for your usage, notably for the
> reduced CPU amount needed for filtering across several intermediate
> feeders.

I suspect the available filtering software is fairly inefficient on CPU
cycles, although that's a much harder problem to solve. Last time I
looked at it, it was tons of regex matches written in languages that
aren't the fastest. I know Jeremy Nixon did a lot of benchmarking and
optimization of the regexes back in the day, but I'm not sure if those
optimizations still work with the latest Perl or have been carried
forward, and I suspect Python will be even slower. (The Perl regex engine
is terrifying, but it's absurdly optimized.)

For something like binary detection, there are probably optimization gains
to be had, but it would be a lot of development work. (Spam detection is
a lot harder and inherently seems to involve a lot of complex pattern
matching.)

--
Russ Allbery (eagle@eyrie.org) <https://www.eyrie.org/~eagle/>

Please post questions rather than mailing me directly.
<https://www.eyrie.org/~eagle/faqs/questions.html> explains why.

On Feb 3, 2023 at 1:10:17 PM CST, "Julien ÉLIE"
<iulius@nom-de-mon-site.com.invalid> wrote:

> Hi Jesse,
>
>> Diablo's "feeder" design is more scalable, even with Cleanfeed in
>> the mix, but will admit INN works best for a backend spool for me. I like
>> having working control message processing, Cancel-Lock support, native TLS,
>> etc.
>
> FWIW, Miquel van Smoorenburg added support in INN for Diablo's hashfeed.
> It's the Q flag value in newsfeeds. It permits scaling feeders like
> Diablo does with backend-servers.
>
> You may then have the following architecture:
>
> - a front innd transit server without overview/reader/filtering, just
> feeding to N internal innd feeders (using Q to split the feed in N parts
> in newsfeeds; or binaries to some feeders, text to others);
> - N internal innd feeders doing filtering, without overview and reader;
> - a final innd/nnrpd serving server, without filtering, but numbering
> and storing articles, generating overview data and handling readers.
>
> I don't know whether it could be of help for your usage, notably for the
> reduced CPU amount needed for filtering across several intermediate feeders.

This is similar to my current setup, but I don't have the middle "internal"
feeder layer doing filtering, it's being done by the transit server to protect
text-only peers.

As Russ stated, it's the filtering that's eating up CPU cycles. I can handle
> 50Mbps of incoming and >80Mbps outgoing traffic using ~20% of the CPU without
filtering, but when I turn on Cleanfeed or PyClean innd maxes out its core and
upstream peers start to spool.

I will admit, I'm likely an outlier in that I absolutely want to be a good
Usenet citizen to all of Usenet. while also participating (partially) in all
of it.

Hi Jesse,
> As Russ stated, it's the filtering that's eating up CPU cycles. I can handle
> >50Mbps of incoming and >80Mbps outgoing traffic using ~20% of the CPU without
> filtering, but when I turn on Cleanfeed or PyClean innd maxes out its core and
> upstream peers start to spool.

Do you think reordering the checks Cleanfeed does would be of help?
For instance having the is_binary() check as soon as possible instead of
always having body parsing like:

$body = lc substr($hdr{__BODY__}, 0, 4000);

$state{badlines}++ while $hdr{__BODY__} =~ /[^\r]\n/g;

$hdr{__BODY__} =~ /
^[Bb][Ee][Gg][Ii][Nn]$hws+[0-7]{3,4}$hws+ # begin 666
(...long regexp for UUencoded...)
/mx;

--
Julien ÉLIE

« Les grands artistes n'ont pas de patrie. » (Alfred de Musset)

On Feb 3, 2023 at 2:47:01 PM CST, "Julien ÉLIE"
<iulius@nom-de-mon-site.com.invalid> wrote:

> Hi Jesse,
>> As Russ stated, it's the filtering that's eating up CPU cycles. I can handle
>>> 50Mbps of incoming and >80Mbps outgoing traffic using ~20% of the CPU without
>> filtering, but when I turn on Cleanfeed or PyClean innd maxes out its core and
>> upstream peers start to spool.
>
> Do you think reordering the checks Cleanfeed does would be of help?
> For instance having the is_binary() check as soon as possible instead of
> always having body parsing like:
>
> $body = lc substr($hdr{__BODY__}, 0, 4000);
>
> $state{badlines}++ while $hdr{__BODY__} =~ /[^\r]\n/g;
>
> $hdr{__BODY__} =~ /
> ^[Bb][Ee][Gg][Ii][Nn]$hws+[0-7]{3,4}$hws+ # begin 666
> (...long regexp for UUencoded...)
> /mx;

I'm sure it would help. If the binary detection were performed first, and an
article is iidentified as a binary then passed through without further checks
would eliminate a lot of unncessary cycles.

I've been able to strip out most of the checks from Cleanfeed to one that is
only checking for misplaced binaries and CPU impact is negligable compared to
before. Beyond ripping everything out, I'm not a developer but sometimes
manage to modify things to suit my needs. Likely not efficiently. :)

The one thing I noticed early on with PyClean was the binary articles pass
through all the other checks, or at least the EMP check and every so often one
would be rejected from that part of the filter. That always seemed inefficient
and I experiemented with the variable it uses to exclude groups but that
didn't seem to work to exclude them from the EMP filter.

If anyone has modified versions/patches they'd be interested in having me test
for performance I'm capable of tossing a steady stream of mixed article flow
at it.

Hi Jesse,

> I'm sure it would help. If the binary detection were performed first, and an
> article is identified as a binary then passed through without further checks
> would eliminate a lot of unncessary cycles.

Does it mean that if you turn off binary detection in Cleanfeed or
PyClean, there's no longer any huge CPU load?

Something like "block_binaries => 0" for Cleanfeed and "bin_allowed =
['\.']" (any newsgroup containing a dot will match) for PyClean.

It would be interesting to know, if CPU load is still high, which checks
cause that. For instance by disabling in Cleanfeed things like:

do_md5 => 0
do_scoring_filter => 0
fuzzy_md5 => 0
block_mime_html => 0 (and other block_html_* stuff)

and telling PyClean (in pyclean.py) that all groups are test groups, so
as to disable many checks:

test = ['\.']

Does the load become acceptable?

If that's not the case, there's a more fundamental problem that cannot
be fixed by just optimizing Cleanfeed and PyClean regexps.

> I've been able to strip out most of the checks from Cleanfeed to one that is
> only checking for misplaced binaries and CPU impact is negligable compared to
> before. Beyond ripping everything out, I'm not a developer but sometimes
> manage to modify things to suit my needs. Likely not efficiently. :)

Did you also try to directly disable the checks with do_xxx => 0?

> The one thing I noticed early on with PyClean was the binary articles pass
> through all the other checks, or at least the EMP check and every so often one
> would be rejected from that part of the filter. That always seemed inefficient
> and I experiemented with the variable it uses to exclude groups but that
> didn't seem to work to exclude them from the EMP filter.

Even with:

emp_exclude = ['\.']

in pyclean.py?

> If anyone has modified versions/patches they'd be interested in having me test
> for performance I'm capable of tossing a steady stream of mixed article flow
> at it.

Looking at Diablo's code to detect binaries... well, it's pretty
straight-forward. There aren't many checks done:
https://github.com/jpmens/diablo/blob/master/lib/arttype.c

/*
*
* Try and categorise an article into a range of types
*
* We keep state info as the article is passed to us line by line
*
* Once we have found an article type, we keep to that type unless
* we find a different type. We never reset.
*
* Once we have found a binary, we stop scanning the article - save CPU
*
*/

"save CPU" :-)

It could maybe be useful to do something similar in INN, and make the
function available to embedded Perl and Python filters (like
INN::havehist() and like). They may run faster.
If of course Perl and Python filters without binary checking on already
run fast enough.

--
Julien ÉLIE

« Passion is inversely proportional to the amount of real information
available. » (Benford's law)

On Feb 4, 2023 at 5:50:34 AM CST, "Julien ÉLIE"
<iulius@nom-de-mon-site.com.invalid> wrote:

> Hi Jesse,
>
>> I'm sure it would help. If the binary detection were performed first, and an
>> article is identified as a binary then passed through without further checks
>> would eliminate a lot of unncessary cycles.
>
> Does it mean that if you turn off binary detection in Cleanfeed or
> PyClean, there's no longer any huge CPU load?

These are good questions, and I will take some time to do testing of various
scenarios and report back with findings.

When I brought my systems back online last year I started with pyClean, no
modifications or configuration. I began backfilling my spool from commercial
entities using 10-20 instances of pullnews running at the same time. This
resulted in a very mixed article stream (lots of misplaced binaries on
commercial spools!), and is when I first noticed the filtering bottleneck.

In my observation, the more binaries going through, the worse things got.
This is when I noticed that binaries were also going through the EMP filter as
occasionally one would be rejected by the EMP filter. That got me thinking I
just needed to add the binary patterns to emp_exclude, so I used this:

emp_exclude = ['^alt\.anonymous\.messages',
'^free\.', '^local\.', '\.answers',
'^news\.answers', '^comp\.answers',
'^relcom\.', '^mailing\.', '^fa\.', '\.cvs\.',
'^gnu\.', 'lists\.freebsd\.ports\.bugs',
'^bin[a.]', '\.bin[aei.]', '\.bin$']

But that didn't help with CPU load, and binaries were still passing through
the EMP filter and sometimes rejected there.

pyClean was harder for me to understand how to turn off some filters (can you
even fully disable the EMP filter in pyClean?), so I switched to Cleanfeed
because the configuration made it obvious how to enable/disable all of the
filters.

Your suggestion of:

emp_exclude = ['\.']

Is a good one that I didn't think to try, but will!

I didn't understand what the test groups definition in pyClean was for, so I
didn't experiment with that either.

Hi Jesse,

> This resulted in a very mixed article stream (lots of misplaced
> binaries on commercial spools!), and is when I first noticed the
> filtering bottleneck.

Seems like they're using light heuristics to detect binaries, which
generate false negative (and probably also false positive). But these
heuristics are less CPU intensive!

> can you even fully disable the EMP filter in pyClean? >
> Your suggestion of:
>
> emp_exclude = ['\.']
>
> Is a good one that I didn't think to try, but will!

:)

> I didn't understand what the test groups definition in pyClean was for, so I
> didn't experiment with that either.

In the current version, test groups are treated like groups to exclude
from the EMP filter. The check for test_bool is only at one place:

# Start of EMP checks.
if (not self.groups['emp_exclude_bool'] and
not self.groups['test_bool']):

The intent is probably to also exclude them from other checks in future
versions.

--
Julien ÉLIE

« Le rire est une chose sérieuse avec laquelle il ne faut pas
plaisanter. » (Raymond Devos)