Daily Usenet report for news.niel.me: Feb 22 04:15:02

Unknown entries from news log file:

First 3 / 3 lines (100.0%)

Feb 22 20:51:21 rpi-studio innd: filter: Invalid Cancel-Key syntax 'sha1=YkoyMS0+mzpsgXWFBghpRpCu+FY='. target=<CVLqljL/0Bs@news.spitfire-nntp.fr>
Feb 22 20:51:21 rpi-studio innd: filter: Invalid Cancel-Key syntax 'sha256=0pzJAS6GSIRdZYo8rYuZsOxkW+Mr9y0XaVL0RZd6XYI='. target=<CVLqljL/0Bs@news.spitfire-nntp.fr>
Feb 22 20:51:21 rpi-studio innd: filter: No Cancel-Key[sha1=YkoyMS0+mzpsgXWFBghpRpCu+FY= #015#012 sha256=0pzJAS6GSIRdZYo8rYuZsOxkW+Mr9y0XaVL0RZd6XYI=] matches Cancel-Lock[sha1:0uItQnl0Eb2TM2hdp3luHzpM5tg=] target=<CVLqljL/0Bs@news.spitfire-nntp.fr>

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	3975	40.7%	787.6 KB	47.6%
innd	2248	23.0%	376.0 KB	22.7%
nnrpd	1780	18.2%	188.1 KB	11.4%
innfeed	1768	18.1%	301.3 KB	18.2%
controlchan	1	0.0%	0.2 KB	0.0%
nocem	1	0.0%	0.1 KB	0.0%
TOTAL: 6	9773	100.0%	1.6 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	21931	57.6%
Negative hits	12231	32.1%
Do not exist	3929	10.3%
Cache misses	7	0.0%
TOTAL: 4	38098	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
artcncl/perl	00:00:00.037	0.0%	18	1.000	2.056	7.000
article cancel	00:00:00.004	0.0%	18	0.000	0.222	1.000
article cleanup	00:00:00.078	0.0%	3942	0.000	0.020	0.154
article logging	00:00:00.302	0.0%	3947	0.000	0.077	0.222
article parse	00:00:00.681	0.0%	7626	0.000	0.089	0.233
article write	00:00:05.111	0.0%	3623	0.158	1.411	3.429
artlog/artcncl	00:00:00.001	0.0%	18	0.000	0.056	0.200
artlog/artcncl/perl	00:00:00.003	0.0%	18	0.000	0.167	1.000
data move	00:00:00.138	0.0%	40613	0.000	0.003	0.022
hisgrep/artcncl	00:00:00.001	0.0%	18	0.000	0.056	0.200
hisgrep/artcncl/perl	00:00:00.000	0.0%	18	0.000	0.000	0.000
hisgrep/perl	00:00:00.001	0.0%	19	0.000	0.053	0.500
hishave/artcncl	00:00:00.000	0.0%	18	0.000	0.000	0.000
hishave/artcncl/perl	00:00:00.000	0.0%	18	0.000	0.000	0.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:00.490	0.0%	38194	0.000	0.013	0.030
history sync	00:00:00.060	0.0%	407	0.000	0.147	1.000
history write	00:00:00.748	0.0%	3941	0.000	0.190	0.467
hiswrite/artcncl	00:00:00.000	0.0%	0	0.000	0.000	0.000
idle	24:00:31.795	100.0%	41767	666.756	2069.380	13638.932
nntp read	00:00:01.175	0.0%	41195	0.005	0.029	0.070
overview write	00:00:01.976	0.0%	3623	0.048	0.545	5.000
perl filter	00:00:16.781	0.0%	3941	2.265	4.258	8.457
python filter	00:00:00.010	0.0%	3941	0.000	0.003	0.050
site send	00:00:01.309	0.0%	7328	0.000	0.179	0.459
TOTAL: 24:01:12.405	24:01:00.701	100.0%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.014	0.0%	3617	0.000	0.004	0.062
article prepare	00:00:00.000	0.0%	308	0.000	0.000	0.000
article read	00:00:00.013	0.0%	71	0.000	0.183	8.000
backlog stats	00:00:00.104	0.0%	43478	0.000	0.002	0.018
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:00.619	0.0%	26818	0.000	0.023	0.097
data write	00:00:01.282	0.0%	23438	0.015	0.055	0.094
idle	23:57:40.691	100.0%	43478	1090.838	1984.008	6982.535
status file	00:00:00.504	0.0%	207	1.000	2.435	7.000
TOTAL: 23:57:46.264	23:57:43.227	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	00:00:30.347	25.7%	1446	12.200	20.987	1639.000
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.068	0.1%	3186	0.000	0.021	4.000
TOTAL: 00:01:58.275	00:00:30.415	25.7%	-	-	-	-

Control commands to INND:

Command	Number
flush	5
flushlogs	2
go	2
logmode	2
lowmark	1
mode	149
name	2
pause	2
paused	2
reload	2
reserve	2
TOTAL: 11	171

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	i2pn.org	2	3661	1050	2497	114	28%	24:56:43
2	feed-out.gegeweb.org	3	2022	979	1043	0	48%	23:18:49
3	gegeweb-out.news.tnetconsulting.net	2	5629	468	5148	13	8%	37:24:58
4	news.nntp4.net	1	5041	343	4535	163	6%	31:53:15
5	news.glou.org	1	3337	303	3003	31	9%	23:59:58
6	usenet.pasdenom.info	2	3025	218	2775	32	7%	30:48:53
7	nntp.terraraq.uk	1	494	38	451	5	7%	04:34:52
8	news.samoylyk.net	1	207	2	205	0	0%	01:52:38
9	localhost	25	0	0	0	0	0%	00:00:00
TOTAL: 9		38	23416	3401	19657	358	14%	178:50:06

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	i2pn.org	3.6 MB	0.0 KB	291.1 KB	3.9 MB	92%	3.4 KB
2	news.glou.org	3.0 MB	0.0 KB	91.8 KB	3.1 MB	97%	9.4 KB
3	feed-out.gegeweb.org	2.8 MB	0.0 KB	0.0 KB	2.8 MB	100%	2.9 KB
4	gegeweb-out.news.tnetconsulting.net	2.4 MB	2.8 KB	53.4 KB	2.4 MB	97%	5.2 KB
5	news.nntp4.net	1.6 MB	0.0 KB	543.7 KB	2.1 MB	74%	4.3 KB
6	usenet.pasdenom.info	507.8 KB	0.0 KB	67.2 KB	575.0 KB	88%	2.3 KB
7	nntp.terraraq.uk	189.1 KB	0.0 KB	23.3 KB	212.5 KB	89%	4.9 KB
8	news.samoylyk.net	172.2 KB	0.0 KB	0.0 KB	172.2 KB	100%	86.1 KB
9	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 9		14.2 MB	2.8 KB	1.0 MB	15.3 MB	93%	4.2 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Feb 22 04:15:02 - 04:59:59	82	2.3%	0.03	568.4 KB	3.7%	0.21
Feb 22 05:00:00 - 05:59:59	100	2.8%	0.03	540.0 KB	3.5%	0.15
Feb 22 06:00:00 - 06:59:59	102	2.8%	0.03	359.9 KB	2.3%	0.10
Feb 22 07:00:00 - 07:59:59	69	1.9%	0.02	251.7 KB	1.6%	0.07
Feb 22 08:00:00 - 08:59:59	96	2.7%	0.03	711.2 KB	4.6%	0.20
Feb 22 09:00:00 - 09:59:59	124	3.4%	0.03	464.2 KB	3.0%	0.13
Feb 22 10:00:00 - 10:59:59	102	2.8%	0.03	330.8 KB	2.1%	0.09
Feb 22 11:00:00 - 11:59:59	132	3.7%	0.04	594.6 KB	3.9%	0.17
Feb 22 12:00:00 - 12:59:59	103	2.9%	0.03	396.8 KB	2.6%	0.11
Feb 22 13:00:00 - 13:59:59	136	3.8%	0.04	354.5 KB	2.3%	0.10
Feb 22 14:00:00 - 14:59:59	162	4.5%	0.04	1.2 MB	8.1%	0.35
Feb 22 15:00:00 - 15:59:59	184	5.1%	0.05	1.1 MB	7.4%	0.32
Feb 22 16:00:00 - 16:59:59	209	5.8%	0.06	1.0 MB	6.8%	0.29
Feb 22 17:00:00 - 17:59:59	207	5.7%	0.06	750.9 KB	4.9%	0.21
Feb 22 18:00:00 - 18:59:59	208	5.8%	0.06	918.1 KB	6.0%	0.26
Feb 22 19:00:00 - 19:59:59	194	5.4%	0.05	545.7 KB	3.5%	0.15
Feb 22 20:00:00 - 20:59:59	186	5.1%	0.05	572.1 KB	3.7%	0.16
Feb 22 21:00:00 - 21:59:59	238	6.6%	0.07	823.8 KB	5.3%	0.23
Feb 22 22:00:00 - 22:59:59	177	4.9%	0.05	588.8 KB	3.8%	0.16
Feb 22 23:00:00 - 23:59:59	172	4.8%	0.05	646.4 KB	4.2%	0.18
Feb 23 00:00:00 - 00:59:59	182	5.0%	0.05	645.4 KB	4.2%	0.18
Feb 23 01:00:00 - 01:59:59	130	3.6%	0.04	476.7 KB	3.1%	0.13
Feb 23 02:00:00 - 02:59:59	141	3.9%	0.04	615.0 KB	4.0%	0.17
Feb 23 03:00:00 - 03:59:59	148	4.1%	0.04	673.0 KB	4.4%	0.19
Feb 23 04:00:00 - 04:15:01	30	0.8%	0.03	168.1 KB	1.1%	0.19
TOTAL: 23:59:59	3614	100.0%	0.04	15.1 MB	100.0%	0.18

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	news.nntp4.net	124	1	0	123
2	i2pn.org	104	0	0	104
3	news.glou.org	31	0	0	31
4	usenet.pasdenom.info	28	0	0	28
5	nntp.terraraq.uk	20	0	0	20
6	gegeweb-out.news.tnetconsulting.net	14	1	1	12
7	news.samoylyk.net	2	0	0	2
8	feed-out.gegeweb.org	2	0	0	2
TOTAL: 8		325	2	1	322

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fr.petites-annonces.informatique.materiel	2
TOTAL: 1	2

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	102
EMP (phn path)	65
Bad path (news.giganews.com.POSTED)	62
EMP (phl)	43
EMP (phn nph)	24
Too many newsgroups	18
Cancels abusifs	2
No Cancel-Key matches Cancel-Lock. target=<CVLqljL/0Bs@news.spitfire-nntp.fr>	1
TOTAL: 8	317

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Including strange strings
	feed-out.gegeweb.org	2
	usenet.pasdenom.info	1
	news.samoylyk.net	1
	news.nntp4.net	1
	TOTAL: 4	5
TOTAL: 1		5

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	i2pn.org	2424	29	1539	0	1016	1%	23:58:19
2	news.tnetconsulting.net	5101	21	3590	0	4	0%	23:59:40
3	news.gegeweb.org	2693	8	2614	5	0	0%	23:59:56
4	news.nntp4.net	3418	5	3283	0	0	0%	23:59:56
5	news.pasdenom.info	3218	3	3099	0	0	0%	23:58:51
6	nntp.terraraq.uk	2642	2	2461	2	0	0%	23:59:17
7	news.samoylyk.net	3912	2	3515	0	0	0%	23:59:56
8	news.aioe.org	0	0	0	0	2894	0%	23:59:56
TOTAL: 8		23408	70	20101	7	3914	0%	191:55:51

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	news.nntp4.net	106.7 KB	0.0 KB	106.7 KB	21.3 KB	23:59:56
2	nntp.terraraq.uk	102.2 KB	97.2 KB	199.4 KB	49.9 KB	23:59:17
3	news.tnetconsulting.net	78.0 KB	0.0 KB	78.0 KB	3.7 KB	23:59:40
4	i2pn.org	68.3 KB	0.0 KB	68.3 KB	2.4 KB	23:58:19
5	news.gegeweb.org	41.0 KB	26.7 KB	67.7 KB	5.2 KB	23:59:56
6	news.pasdenom.info	8.1 KB	0.0 KB	8.1 KB	2.7 KB	23:58:51
7	news.samoylyk.net	4.9 KB	0.0 KB	4.9 KB	2.4 KB	23:59:56
8	news.aioe.org	0.0 KB	0.0 KB	0.0 KB	0	23:59:56
TOTAL: 8		409.2 KB	123.9 KB	533.1 KB	6.9 KB	191:55:51

NNRP readership statistics:

System		Conn	Elapsed
1	198.199.97.62	1	00:00:00
2	172.104.238.162	1	00:00:03
3	hopeful.monitoring.internet-measurement.com	1	00:00:02
4	gracious.monitoring.internet-measurement.com	2	00:00:00
5	eloquent.monitoring.internet-measurement.com	1	00:00:00
6	185.73.124.50	1	00:00:00
7	awesome.monitoring.internet-measurement.com	1	00:00:02
8	mail.gegeweb.eu	288	00:01:43
9	fabulous.monitoring.internet-measurement.com	1	00:00:05
TOTAL: 9		297	00:01:57

NNRP readership statistics (by domain):

System		Conn	Elapsed
1	*.monitoring.internet-measurement.com	6	00:00:10
2	*.gegeweb.eu	288	00:01:43
3	unresolved	3	00:00:03
TOTAL: 3		297	00:01:57

NNRP auth users [Top 20]:

User	Conn
mailman	288
TOTAL: 1	288

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
mail.gegeweb.eu	4.643	4.636	1.960	00:01:43
fabulous.monitoring.internet-measurement.com	0.078	0.013	0.000	00:00:05
172.104.238.162	0.021	0.051	0.000	00:00:03
awesome.monitoring.internet-measurement.com	0.031	0.021	0.000	00:00:02
hopeful.monitoring.internet-measurement.com	0.036	0.009	0.000	00:00:02
198.199.97.62	0.019	0.029	0.000	00:00:00
185.73.124.50	0.030	0.020	0.000	00:00:00
gracious.monitoring.internet-measurement.com	0.040	0.041	0.000	00:00:00
eloquent.monitoring.internet-measurement.com	0.019	0.010	0.000	00:00:00
TOTAL: 9	4.917	4.830	1.960	00:01:57

NNRP gethostbyaddr failures [Top 20]:

System	Conn
? (can't getpeername)	7
TOTAL: 1	7

NNRP unrecognized commands (by host):

System	Conn
185.73.124.50	1
198.199.97.62	1
TOTAL: 2	2

NNRP unrecognized commands (by command):

Command	Count
MGLNDD_45.13.105.36_119	1
#003	1
TOTAL: 2	2

NNRP client timeouts [Top 20]:

System	Conn	Peer
185.73.124.50	1	1
TOTAL: 1	1	1

Daily Usenet report for news.niel.me

Feb 22 04:15:02 -- Feb 23 04:15:01