Daily Usenet Report: Aug 22 00:01:02

Unknown entries from news log file:

First 3 / 3 lines (100.0%)

Aug 22 08:17:31 newsfeed innd: message repeated 2 times: [ ctlinnd command s]
Aug 22 10:52:12 newsfeed nnrpd[2934114]: localhost auth: program exited with status 8
Aug 23 00:00:01 newsfeed nnrpd[3285955]: localhost auth: program exited with status 8

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	8848	29.5%	3.6 MB	55.5%
nnrpd	8617	28.7%	890.6 KB	13.4%
innd	7965	26.5%	1.1 MB	17.2%
innfeed	4081	13.6%	828.5 KB	12.5%
cnfsstat	432	1.4%	64.2 KB	1.0%
nocem	96	0.3%	26.2 KB	0.4%
controlchan	1	0.0%	0.1 KB	0.0%
TOTAL: 7	30040	100.0%	6.5 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	112793	60.0%
Negative hits	66802	35.6%
Do not exist	8250	4.4%
Cache misses	38	0.0%
TOTAL: 4	187883	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.494	0.0%	486	0.000	1.016	11.000
article cleanup	00:00:00.442	0.0%	8346	0.000	0.053	3.591
article logging	00:00:00.392	0.0%	8430	0.000	0.047	0.639
article parse	00:00:00.238	0.0%	12992	0.000	0.018	0.161
article write	00:00:02.190	0.0%	7305	0.000	0.300	2.831
artlog/artcncl	00:00:00.008	0.0%	420	0.000	0.019	0.125
artlog/artparse	00:00:00.000	0.0%	0	0.000	0.000	0.000
data move	00:00:00.518	0.0%	191610	0.000	0.003	0.078
hisgrep/artcncl	00:00:00.323	0.0%	485	0.000	0.666	11.000
hishave/artcncl	00:00:00.047	0.0%	423	0.000	0.111	1.556
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:02:46.206	0.2%	189150	0.072	0.879	6.385
history sync	00:00:00.089	0.0%	403	0.000	0.221	2.333
history write	00:01:57.884	0.1%	8333	3.230	14.147	124.934
hiswrite/artcncl	00:00:00.008	0.0%	3	2.667	2.667	2.667
idle	23:46:07.178	99.0%	190227	91.981	449.816	1327.150
nntp read	00:00:04.589	0.0%	191944	0.001	0.024	0.811
overview write	00:08:16.890	0.6%	7305	0.326	68.021	4367.729
perl filter	00:00:47.556	0.1%	8333	1.493	5.707	163.700
python filter	00:00:02.878	0.0%	8333	0.000	0.345	5.857
site send	00:00:00.987	0.0%	14660	0.000	0.067	0.266
TOTAL: 24:01:09.400	24:00:08.917	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:04.268	0.0%	4760938	0.000	0.001	0.002
article prepare	00:00:00.010	0.0%	50324	0.000	0.000	0.004
article read	00:00:01.056	0.0%	4103	0.000	0.257	35.643
backlog stats	00:00:01.901	0.0%	1998982	0.000	0.001	0.004
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:12.364	0.0%	1181630	0.004	0.010	0.038
data write	00:00:12.874	0.0%	1177145	0.007	0.011	0.041
idle	23:47:48.973	99.8%	1998982	35.393	42.856	52.608
status file	00:00:00.312	0.0%	247	0.667	1.263	9.000
TOTAL: 23:50:08.242	23:48:21.758	99.9%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	27:50:12.464	99.0%	10247	0.000	9779.688	53047.453
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:02.501	0.0%	99498	0.000	0.025	1.000
readart	00:00:00.080	0.0%	152	0.526	0.526	0.526
TOTAL: 28:07:54.656	27:50:15.045	99.0%	-	-	-	-

Control commands to INND:

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

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	endofthelinebbs-out.news.weretis.net	4	13746	1976	11477	293	14%	50:16:13
2	outgoing.news.lysator.liu.se	2	6168	1592	4517	59	25%	23:59:53
3	usenet.blueworldhosting.com	722	8157	914	6870	373	11%	23:52:45
4	news.corradoroberto.it	7	1430	474	956	0	33%	22:24:43
5	news.hispagatos.org	6	7207	439	6747	21	6%	24:25:01
6	nntp.comgw.net	1	7578	412	7034	132	5%	23:59:57
7	usenet.network	1	5791	394	5394	3	6%	23:59:57
8	endoftheline-out.news.chmurka.net	1	3969	216	3753	0	5%	23:59:56
9	i2pn.org	1	7191	187	6995	9	2%	23:59:56
10	newsfeed.xs3.de	1	6076	167	5877	32	2%	23:59:54
11	endofthelinebbs.peers.news.panix.com	25	7755	139	7600	16	1%	23:54:56
12	newsfeed.bofh.team	2	8158	118	8033	7	1%	23:59:53
13	usenet.goja.nl.eu.org	10	7562	108	7430	24	1%	23:58:22
14	news.samoylyk.net	2	6618	104	6508	6	1%	23:59:36
15	news.netfront.net	1	5003	25	4857	121	0%	21:53:57
16	glockenspiel.complete.org	2	5788	20	5767	1	0%	23:56:00
17	news.furie.org.uk	2	4614	9	4603	2	0%	23:59:44
18	news.bbs.nz	1	6693	8	6684	1	0%	23:59:25
19	photonic.trudheim.com	1	1757	0	1757	0	0%	21:16:08
20	eotl-out.news.tnetconsulting.net	1	0	0	0	0	0%	00:10:04
21	localhost	26	0	0	0	0	0%	00:00:00
22	news.nk.ca	2	0	0	0	0	0%	00:20:12
23	news.nntp4.net	1	0	0	0	0	0%	00:10:00
TOTAL: 23		822	121261	7302	112859	1100	6%	476:36:32

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	endofthelinebbs-out.news.weretis.net	6.4 MB	10.6 KB	537.5 KB	6.9 MB	92%	3.1 KB
2	outgoing.news.lysator.liu.se	5.6 MB	5.3 KB	103.8 KB	5.7 MB	98%	3.5 KB
3	usenet.network	4.0 MB	5.3 KB	1.5 KB	4.0 MB	99%	10.3 KB
4	news.corradoroberto.it	3.0 MB	0.0 KB	0.0 KB	3.0 MB	100%	6.5 KB
5	usenet.blueworldhosting.com	2.7 MB	0.0 KB	1.1 MB	3.8 MB	69%	3.0 KB
6	nntp.comgw.net	1.4 MB	0.0 KB	276.4 KB	1.7 MB	83%	3.2 KB
7	news.hispagatos.org	1.3 MB	5.3 KB	79.6 KB	1.4 MB	94%	3.1 KB
8	i2pn.org	732.9 KB	0.0 KB	13.3 KB	746.2 KB	98%	3.8 KB
9	endoftheline-out.news.chmurka.net	636.9 KB	0.0 KB	0.0 KB	636.9 KB	100%	2.9 KB
10	newsfeed.xs3.de	568.3 KB	0.0 KB	137.8 KB	706.2 KB	80%	3.5 KB
11	news.samoylyk.net	546.2 KB	5.3 KB	9.3 KB	560.8 KB	97%	5.1 KB
12	endofthelinebbs.peers.news.panix.com	460.4 KB	5.3 KB	32.6 KB	498.3 KB	92%	3.2 KB
13	usenet.goja.nl.eu.org	370.1 KB	5.3 KB	23.0 KB	398.4 KB	92%	3.0 KB
14	newsfeed.bofh.team	276.6 KB	5.3 KB	19.7 KB	301.7 KB	91%	2.4 KB
15	glockenspiel.complete.org	143.0 KB	5.3 KB	0.0 KB	148.3 KB	96%	7.1 KB
16	news.netfront.net	69.0 KB	5.4 KB	1.1 MB	1.2 MB	5%	8.3 KB
17	news.furie.org.uk	32.4 KB	5.4 KB	0.7 KB	38.4 KB	84%	3.5 KB
18	news.bbs.nz	21.1 KB	5.3 KB	0.0 KB	26.4 KB	79%	2.9 KB
19	eotl-out.news.tnetconsulting.net	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
20	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
21	news.nk.ca	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
22	news.nntp4.net	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
23	photonic.trudheim.com	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 23		28.1 MB	69.2 KB	3.5 MB	31.7 MB	88%	3.9 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Aug 22 00:01:02 - 00:59:59	186	2.5%	0.05	923.1 KB	3.2%	0.26
Aug 22 01:00:00 - 01:59:59	213	2.9%	0.06	789.2 KB	2.7%	0.22
Aug 22 02:00:00 - 02:59:59	295	4.0%	0.08	990.2 KB	3.4%	0.28
Aug 22 03:00:00 - 03:59:59	321	4.4%	0.09	1.1 MB	3.9%	0.31
Aug 22 04:00:00 - 04:59:59	367	5.0%	0.10	1.3 MB	4.4%	0.36
Aug 22 05:00:00 - 05:59:59	335	4.6%	0.09	1.0 MB	3.6%	0.29
Aug 22 06:00:00 - 06:59:59	409	5.6%	0.11	1.5 MB	5.3%	0.42
Aug 22 07:00:00 - 07:59:59	366	5.0%	0.10	1.6 MB	5.7%	0.46
Aug 22 08:00:00 - 08:59:59	452	6.2%	0.13	1.9 MB	6.6%	0.53
Aug 22 09:00:00 - 09:59:59	397	5.4%	0.11	1.5 MB	5.4%	0.44
Aug 22 10:00:00 - 10:59:59	438	6.0%	0.12	1.8 MB	6.3%	0.51
Aug 22 11:00:00 - 11:59:59	376	5.1%	0.10	1.6 MB	5.8%	0.46
Aug 22 12:00:00 - 12:59:59	521	7.1%	0.14	1.6 MB	5.8%	0.47
Aug 22 13:00:00 - 13:59:59	417	5.7%	0.12	1.7 MB	5.9%	0.48
Aug 22 14:00:00 - 14:59:59	321	4.4%	0.09	989.5 KB	3.4%	0.27
Aug 22 15:00:00 - 15:59:59	364	5.0%	0.10	1.2 MB	4.3%	0.35
Aug 22 16:00:00 - 16:59:59	260	3.6%	0.07	1019.9 KB	3.5%	0.28
Aug 22 17:00:00 - 17:59:59	235	3.2%	0.07	1.3 MB	4.6%	0.37
Aug 22 18:00:00 - 18:59:59	215	2.9%	0.06	1.1 MB	4.0%	0.32
Aug 22 19:00:00 - 19:59:59	158	2.2%	0.04	664.5 KB	2.3%	0.18
Aug 22 20:00:00 - 20:59:59	150	2.1%	0.04	784.2 KB	2.7%	0.22
Aug 22 21:00:00 - 21:59:59	167	2.3%	0.05	765.2 KB	2.6%	0.21
Aug 22 22:00:00 - 22:59:59	128	1.8%	0.04	598.2 KB	2.1%	0.17
Aug 22 23:00:00 - 23:59:59	206	2.8%	0.06	670.4 KB	2.3%	0.19
Aug 23 00:00:00 - 00:01:02	6	0.1%	0.10	12.4 KB	0.0%	0.20
TOTAL: 24:00:00	7303	100.0%	0.08	28.3 MB	100.0%	0.34

CNFS buffer status:

Buffer	Class	Size	Used	%Used	Cycles	KB/sec	Days
CYCNGS1	NGS	1536.0 GB	48.0 MB	0.0%	1	0.00	0.00
CYCNGS2	NGS	1536.0 GB	96.5 GB	6.3%	0	0.50	37112.84
CYCTXT1	TEXT	5.0 GB	3.8 GB	76.4%	0	0.02	2492.94
TOTAL: 3	-	3077.0 GB	100.4 GB	3.3%	1	0.35	-

Sites sending bad articles:

Server		Total	Duplic	Other
1	usenet.blueworldhosting.com	416	0	416
2	endofthelinebbs-out.news.weretis.net	320	2	318
3	nntp.comgw.net	131	0	131
4	news.netfront.net	68	1	67
5	outgoing.news.lysator.liu.se	61	1	60
6	newsfeed.xs3.de	32	0	32
7	usenet.goja.nl.eu.org	24	1	23
8	endofthelinebbs.peers.news.panix.com	22	1	21
9	news.hispagatos.org	22	1	21
10	i2pn.org	9	0	9
11	newsfeed.bofh.team	7	1	6
12	news.samoylyk.net	5	1	4
13	usenet.network	3	1	2
14	news.furie.org.uk	2	1	1
15	glockenspiel.complete.org	1	1	0
16	news.bbs.nz	1	1	0
17	photonic.trudheim.com	1	0	1
TOTAL: 17		1125	13	1112

INND Perl filter [Top 20]:

Reason	Count
EMP (phn path)	406
EMP (phr path)	347
EMP (md5)	165
Too many newsgroups	62
EMP (phn nph)	29
HTML Multipart	7
Too many newsgroups (meow)	4
User-issued cancel	4
Binary: misplaced binary	2
Too many newsgroups (low_xpost)	2
TOTAL: 10	1028

NoCeM on Spool:

Issuer (type)	Notices	Cancel	Skip	Total
i2pn2-nocem@i2pn2.org (spam)	45	421	0	421
robot@pasdenom.info (spam3)	4	0	5	5
robot@pasdenom.info (spam2)	1	0	1	1
TOTAL: 3	50	421	6	427

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Including strange strings
	usenet.blueworldhosting.com	42
	endofthelinebbs-out.news.weretis.net	28
	endofthelinebbs.peers.news.panix.com	5
	nntp.comgw.net	3
	news.hispagatos.org	2
	outgoing.news.lysator.liu.se	2
	usenet.goja.nl.eu.org	1
	newsfeed.xs3.de	1
	TOTAL: 8	84
TOTAL: 1		84

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	news.netfront.net	11206	2734	4544	0	9	24%	23:59:54
2	nyheter.lysator.liu.se	5866	1471	3791	449	0	25%	23:59:54
3	news.furie.org.uk	5432	774	3549	11	5	14%	23:59:54
4	photonic.trudheim.com	7735	762	5649	869	0	9%	23:59:40
5	news.hispagatos.org	8053	517	6107	201	3	6%	23:58:39
6	endofthelinebbs.peers.news.panix.com	7586	429	6865	6	0	5%	23:59:35
7	usenet.network	7282	409	5842	43	0	5%	23:56:39
8	news.bbs.nz	13408	250	6665	375	61	1%	23:59:54
9	news.nk.ca	11062	201	6434	580	14	1%	23:59:54
10	newsfeed.bofh.team	8424	201	6934	0	1	2%	23:59:54
11	usenet.goja.nl.eu.org	8544	187	6797	192	0	2%	23:59:54
12	i2pn.org	8063	169	6907	25	34	2%	23:59:54
13	news.corradoroberto.it	1108	131	780	2	0	11%	23:01:34
14	news.tnetconsulting.net	8121	127	6947	225	7	1%	23:59:22
15	news.weretis.net	7602	99	7038	165	1	1%	23:59:29
16	news.quux.org	7826	94	6770	423	5	1%	23:59:24
17	nntp.comgw.net	8049	83	6672	128	0	1%	23:59:54
18	newsfeed.xs3.de	8681	52	6942	153	1	0%	23:59:43
19	news.chmurka.net	4611	47	3619	0	0	1%	23:59:54
20	news.samoylyk.net	8819	22	7115	27	19	0%	23:59:34
21	news.nntp4.net	4792400	0	0	0	4792375	0%	23:59:54
22	usenet.blueworldhosting.com	6341	0	6103	0	0	0%	23:59:54
23	feed.opticnetworks.net	0	0	0	0	7303	0%	23:59:54
TOTAL: 23		4956219	8759	122070	3874	4799838	0%	550:52:21

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.netfront.net	12.3 MB	0.0 KB	12.3 MB	0.1 KB/s	4.6 KB	23:59:54
2	nyheter.lysator.liu.se	5.6 MB	4.4 MB	9.9 MB	0.1 KB/s	5.3 KB	23:59:54
3	news.furie.org.uk	4.7 MB	109.5 KB	4.8 MB	0.1 KB/s	6.2 KB	23:59:54
4	photonic.trudheim.com	4.6 MB	3.1 MB	7.7 MB	0.1 KB/s	4.8 KB	23:59:40
5	endofthelinebbs.peers.news.panix.com	2.7 MB	7.2 KB	2.7 MB	0.0 KB/s	6.4 KB	23:59:35
6	news.hispagatos.org	1.8 MB	2.0 MB	3.9 MB	0.0 KB/s	5.5 KB	23:58:39
7	newsfeed.bofh.team	1.7 MB	0.0 KB	1.7 MB	0.0 KB/s	8.8 KB	23:59:54
8	usenet.network	1.5 MB	133.8 KB	1.6 MB	0.0 KB/s	3.6 KB	23:56:39
9	news.bbs.nz	887.4 KB	3.2 MB	4.0 MB	0.0 KB/s	6.6 KB	23:59:54
10	i2pn.org	723.9 KB	250.7 KB	974.6 KB	0.0 KB/s	5.0 KB	23:59:54
11	news.quux.org	680.7 KB	3.4 MB	4.1 MB	0.0 KB/s	8.1 KB	23:59:24
12	usenet.goja.nl.eu.org	600.7 KB	2.0 MB	2.5 MB	0.0 KB/s	6.9 KB	23:59:54
13	news.tnetconsulting.net	594.9 KB	1.9 MB	2.5 MB	0.0 KB/s	7.2 KB	23:59:22
14	news.weretis.net	512.6 KB	1.8 MB	2.3 MB	0.0 KB/s	9.0 KB	23:59:29
15	news.corradoroberto.it	459.9 KB	24.9 KB	484.8 KB	0.0 KB/s	3.6 KB	23:01:34
16	news.nk.ca	457.8 KB	4.0 MB	4.4 MB	0.1 KB/s	5.8 KB	23:59:54
17	nntp.comgw.net	329.7 KB	1.4 MB	1.8 MB	0.0 KB/s	8.6 KB	23:59:54
18	newsfeed.xs3.de	274.5 KB	1.6 MB	1.9 MB	0.0 KB/s	9.3 KB	23:59:43
19	news.samoylyk.net	201.5 KB	80.5 KB	282.0 KB	0.0 KB/s	5.8 KB	23:59:34
20	news.chmurka.net	157.7 KB	0.0 KB	157.7 KB	0.0 KB/s	3.4 KB	23:59:54
21	feed.opticnetworks.net	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:59:54
22	news.nntp4.net	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:59:54
23	usenet.blueworldhosting.com	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:59:54
TOTAL: 23		40.6 MB	29.4 MB	70.0 MB	0.0 KB/s	5.7 KB	550:52:21

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	unresolved	7	11	87.1 KB	1	27:26:39
2	*.demos.su	2773	0	0.0 KB	0	00:29:52
3	*.ip.linodeusercontent.com	58	0	0.0 KB	0	00:01:27
4	?	2	0	0.0 KB	0	00:09:41
5	*.internet-census.org	1	0	0.0 KB	0	00:00:10
6	*.monitoring.internet-measurement.com	1	0	0.0 KB	0	00:00:01
TOTAL: 6		2842	11	87.1 KB	1	28:07:53

NNRP auth users [Top 20]:

User	Conn
getlist	2
TOTAL: 1	2

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
47.189.156.68	0.057	0.233	0.075	27:26:14
ddt.demos.su	9.841	37.054	0.000	00:29:52
localhost	178.764	361.626	0.070	00:09:41
172-104-4-17.ip.linodeusercontent.com	0.813	0.820	0.000	00:01:08
172-232-203-93.ip.linodeusercontent.com	0.008	0.024	0.000	00:00:18
sh-chi-us-gp1-wk103b.internet-census.org	0.004	0.012	0.000	00:00:10
198.235.24.213	0.005	0.011	0.000	00:00:10
205.210.31.2	0.004	0.012	0.000	00:00:10
167.94.145.103	0.017	0.045	0.000	00:00:03
congratulated.monitoring.internet-measurement.com	0.004	0.012	0.000	00:00:01
45.227.254.8	0.000	0.016	0.000	00:00:00
91.238.181.23	0.004	0.013	0.000	00:00:00
?	0.000	0.015	0.000	00:00:00
TOTAL: 13	189.521	399.893	0.145	28:07:53

Curious NNRP server explorers [Top 20]:

System	Conn
ddt.demos.su	2773
172-104-4-17.ip.linodeusercontent.com	56
167.94.145.103	3
172-232-203-93.ip.linodeusercontent.com	2
localhost	2
198.235.24.213	1
205.210.31.2	1
45.227.254.8	1
91.238.181.23	1
congratulated.monitoring.internet-measurement.com	1
sh-chi-us-gp1-wk103b.internet-census.org	1
TOTAL: 11	2842

NNRP gethostbyaddr failures [Top 20]:

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

NNRP unrecognized commands (by host) [Top 20]:

System	Conn
167.94.145.103	1
45.227.254.8	1
TOTAL: 2	2

NNRP unrecognized commands (by command) [Top 20]:

Command	Count
#003	1
EHLO www.censys.io	1
TOTAL: 2	2

NNRP client timeouts [Top 20]:

System	Conn	Peer
167.94.145.103	1	2
172-104-4-17.ip.linodeusercontent.com	1	1
45.227.254.8	1	1
TOTAL: 3	3	4

Newsgroup request counts (by hierarchy):

Hierarchy		Count	Pct
1	news	8	100.0%
TOTAL: 1		8	100.0%

Newsgroup request counts (by newsgroup) [Top 100]:

Newsgroup		Count
1	news.software.nntp	8
TOTAL: 1		8

Daily Usenet Report

Aug 22 00:01:02 -- Aug 23 00:01:02