Daily Usenet report for csiph.com: Oct 9 04:15:00

Unknown entries from news log file:

First 2 / 2 lines (100.0%)

Oct 9 18:16:50 csiph pgpverify[18850]: pgpverify: verification failed
Oct 9 19:38:31 csiph pgpverify[21941]: pgpverify: verification failed

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	38822	60.5%	7.3 MB	71.4%
innd	21633	33.7%	2.4 MB	23.2%
innfeed	3213	5.0%	509.9 KB	4.9%
nnrpd	428	0.7%	47.6 KB	0.5%
nocem	50	0.1%	5.6 KB	0.1%
controlchan	7	0.0%	0.9 KB	0.0%
pgpverify	2	0.0%	0.2 KB	0.0%
TOTAL: 7	64155	100.0%	10.2 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	406090	56.6%
Negative hits	273084	38.1%
Do not exist	37924	5.3%
Cache misses	536	0.1%
TOTAL: 4	717634	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:01.186	0.0%	165	0.000	7.188	67.000
article cleanup	00:00:00.238	0.0%	37703	0.000	0.006	0.023
article logging	00:00:00.720	0.0%	38269	0.000	0.019	0.811
article parse	00:00:01.483	0.0%	134181	0.004	0.011	0.060
article write	00:05:50.679	0.4%	21427	0.463	16.366	70.949
artlog/artcncl	00:00:00.001	0.0%	160	0.000	0.006	0.077
artlog/artparse	00:00:00.004	0.0%	363	0.000	0.011	1.000
data move	00:00:00.256	0.0%	685421	0.000	0.000	0.001
hisgrep/artcncl	00:00:00.245	0.0%	163	0.000	1.503	11.182
hishave/artcncl	00:00:00.014	0.0%	165	0.000	0.085	1.273
hishave/artparse	00:00:00.000	0.0%	363	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:07.498	0.0%	719679	0.000	0.010	0.170
history sync	00:00:01.621	0.0%	355	0.000	4.566	95.333
history write	00:00:29.956	0.0%	37675	0.060	0.795	10.110
hiswrite/artcncl	00:00:00.000	0.0%	2	0.000	0.000	0.000
hiswrite/artparse	00:00:00.239	0.0%	363	0.000	0.658	10.500
idle	23:50:25.835	99.3%	692374	67.127	123.959	335.348
nntp read	00:00:02.505	0.0%	708326	0.002	0.004	0.006
overview write	00:01:29.475	0.1%	21427	0.186	4.176	102.145
perl filter	00:01:36.161	0.1%	37588	1.564	2.558	4.548
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.388	0.0%	42896	0.000	0.009	0.028
TOTAL: 24:00:53.842	24:00:08.504	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.054	0.0%	21518	0.000	0.003	0.026
article prepare	00:00:00.002	0.0%	30296	0.000	0.000	0.013
article read	00:00:04.612	0.0%	4271	0.000	1.080	15.273
backlog stats	00:00:00.221	0.0%	409072	0.000	0.001	0.002
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:01.628	0.0%	309876	0.000	0.005	0.012
data write	00:00:02.188	0.0%	291793	0.004	0.007	0.013
idle	23:53:16.901	100.0%	409072	128.836	210.224	572.044
status file	00:00:00.517	0.0%	295	0.000	1.753	9.400
TOTAL: 23:53:33.593	23:53:26.123	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:00.000	0.0%	13	0.000	0.000	0.000
idle	15:59:16.115	99.9%	277	360.000	207783.809	900054.000
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.008	0.0%	706	0.000	0.011	0.500
readart	00:00:00.483	0.0%	56	0.000	8.625	71.000
TOTAL: 16:00:39.552	15:59:16.606	99.9%	-	-	-	-

Control commands to INND:

Command	Number
L	1
flush	5
flushlogs	2
go	2
logmode	2
mode	137
pause	2
paused	2
reload	2
reserve	2
TOTAL: 10	157

Control Channel:

Sender	newgroup	rmgroup	Other	Bad PGP	DoIt	OK
grisbi-control@grisbi.org	0	0	0	2	0	0
TOTAL	0	0	0	2	0	0

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	csiph-out.news.weretis.net	3	46226	5200	39842	1184	11%	48:08:07
2	csiph-out.feeder.erje.net	1152	117558	5117	103864	8577	4%	94:57:48
3	feeder.eternal-september.org	4	33294	3011	29573	710	9%	23:59:21
4	news-out.aioe.org	3	20454	1710	18717	27	8%	24:09:40
5	news-out.mixmin.net	2	24694	1609	22391	694	6%	24:08:57
6	newsfeed.neva.ru	141	49574	1278	43604	4692	2%	72:20:00
7	newsfeed.fu-berlin.de	25	23545	1166	21910	469	4%	29:10:41
8	newsfeeds.xmission.com	1	20903	1021	19841	41	4%	24:26:56
9	news.redatomik.org	2	15608	509	15089	10	3%	19:09:21
10	news.fcku.it	2	8733	419	8211	103	4%	23:59:22
11	xanadu-bbs.net	22	580	105	468	7	18%	22:36:06
12	news.swapon.de	6	1872	36	1836	0	1%	24:14:22
13	news.freedyn.net	3	24075	36	24001	38	0%	24:09:05
14	nntp.pasdenom.info	4	34257	19	34208	30	0%	24:07:03
15	news.bbs.geek.nz	1	16710	6	16704	0	0%	23:59:52
16	localhost	36	1	1	0	0	100%	00:00:00
TOTAL: 16		1407	438084	21243	400259	16582	4%	503:36:41

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	csiph-out.feeder.erje.net	16.9 MB	117.7 KB	42.8 MB	59.9 MB	28%	4.5 KB
2	csiph-out.news.weretis.net	14.8 MB	2.6 KB	15.9 MB	30.7 MB	48%	4.9 KB
3	feeder.eternal-september.org	7.6 MB	3.9 KB	13.2 MB	20.8 MB	36%	5.7 KB
4	news-out.mixmin.net	5.2 MB	0.0 KB	1.7 MB	6.9 MB	75%	3.1 KB
5	news-out.aioe.org	4.2 MB	0.0 KB	42.6 KB	4.3 MB	99%	2.5 KB
6	newsfeed.neva.ru	3.6 MB	44.1 KB	41.8 MB	45.5 MB	7%	7.8 KB
7	newsfeeds.xmission.com	2.9 MB	0.0 KB	2.5 MB	5.4 MB	53%	5.2 KB
8	newsfeed.fu-berlin.de	2.6 MB	0.0 KB	7.3 MB	9.9 MB	25%	6.2 KB
9	news.redatomik.org	1.2 MB	0.0 KB	146.6 KB	1.3 MB	88%	2.6 KB
10	news.fcku.it	857.7 KB	2.9 KB	6.7 MB	7.5 MB	11%	14.8 KB
11	xanadu-bbs.net	302.7 KB	0.0 KB	59.4 KB	362.1 KB	83%	3.2 KB
12	news.freedyn.net	141.9 KB	0.0 KB	2.7 MB	2.9 MB	4%	39.5 KB
13	news.swapon.de	84.5 KB	0.0 KB	0.0 KB	84.5 KB	100%	2.3 KB
14	nntp.pasdenom.info	33.2 KB	5.7 KB	458.4 KB	497.2 KB	6%	10.1 KB
15	news.bbs.geek.nz	8.5 KB	0.0 KB	0.0 KB	8.5 KB	100%	1.4 KB
16	localhost	1.6 KB	0.0 KB	0.0 KB	1.6 KB	100%	1.6 KB
TOTAL: 16		60.4 MB	176.9 KB	135.3 MB	195.9 MB	30%	5.3 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Oct 9 04:15:00 - 04:59:59	302	1.4%	0.11	1010.6 KB	1.6%	0.37
Oct 9 05:00:00 - 05:59:59	393	1.8%	0.11	1.1 MB	1.9%	0.32
Oct 9 06:00:00 - 06:59:59	585	2.7%	0.16	1.8 MB	3.0%	0.52
Oct 9 07:00:00 - 07:59:59	746	3.5%	0.21	2.4 MB	3.9%	0.67
Oct 9 08:00:00 - 08:59:59	826	3.9%	0.23	2.3 MB	3.8%	0.66
Oct 9 09:00:00 - 09:59:59	919	4.3%	0.26	2.6 MB	4.3%	0.75
Oct 9 10:00:00 - 10:59:59	934	4.4%	0.26	2.5 MB	4.2%	0.72
Oct 9 11:00:00 - 11:59:59	949	4.4%	0.26	2.4 MB	3.9%	0.68
Oct 9 12:00:00 - 12:59:59	1096	5.1%	0.30	3.0 MB	4.8%	0.84
Oct 9 13:00:00 - 13:59:59	1061	5.0%	0.29	2.7 MB	4.5%	0.78
Oct 9 14:00:00 - 14:59:59	1115	5.2%	0.31	3.4 MB	5.5%	0.96
Oct 9 15:00:00 - 15:59:59	1307	6.1%	0.36	3.5 MB	5.7%	1.00
Oct 9 16:00:00 - 16:59:59	1316	6.1%	0.37	3.6 MB	6.0%	1.03
Oct 9 17:00:00 - 17:59:59	1284	6.0%	0.36	4.2 MB	6.8%	1.18
Oct 9 18:00:00 - 18:59:59	1272	5.9%	0.35	3.5 MB	5.8%	1.01
Oct 9 19:00:00 - 19:59:59	1271	5.9%	0.35	3.4 MB	5.6%	0.96
Oct 9 20:00:00 - 20:59:59	1137	5.3%	0.32	2.9 MB	4.7%	0.82
Oct 9 21:00:00 - 21:59:59	1028	4.8%	0.29	2.7 MB	4.5%	0.77
Oct 9 22:00:00 - 22:59:59	884	4.1%	0.25	2.8 MB	4.5%	0.79
Oct 9 23:00:00 - 23:59:59	652	3.0%	0.18	1.9 MB	3.1%	0.53
Oct 10 00:00:00 - 00:59:59	632	3.0%	0.18	2.0 MB	3.3%	0.57
Oct 10 01:00:00 - 01:59:59	548	2.6%	0.15	1.7 MB	2.8%	0.48
Oct 10 02:00:00 - 02:59:59	450	2.1%	0.12	1.3 MB	2.2%	0.37
Oct 10 03:00:00 - 03:59:59	542	2.5%	0.15	1.6 MB	2.7%	0.46
Oct 10 04:00:00 - 04:15:00	170	0.8%	0.19	588.7 KB	0.9%	0.65
TOTAL: 24:00:00	21419	100.0%	0.25	60.9 MB	100.0%	0.72

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	csiph-out.feeder.erje.net	8612	324	17	8271
2	newsfeed.neva.ru	4732	458	6	4268
3	csiph-out.news.weretis.net	1253	220	2	1031
4	newsfeed.fu-berlin.de	870	39	0	831
5	feeder.eternal-september.org	771	57	0	714
6	news-out.mixmin.net	725	4	0	721
7	news.fcku.it	99	0	2	97
8	newsfeeds.xmission.com	41	1	0	40
9	news.freedyn.net	39	0	0	39
10	news-out.aioe.org	33	25	0	8
11	nntp.pasdenom.info	29	2	1	26
12	news.redatomik.org	22	0	0	22
13	xanadu-bbs.net	7	0	0	7
14	news.swapon.de	3	0	0	3
TOTAL: 14		17236	1130	28	16078

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	224
ut.test	111
lada.talk	111
alt.survival	71
fa.netbsd.bugs	43
alt.windows7.general	38
it-alt.sport.calcio.juventus	32
fa.openbsd.source-changes	30
mozilla.support.seamonkey	29
cakewalk.audio	27
fa.freebsd.cvs-all	19
mpc.lists.nanog	19
spline.eisfair	19
lada.auto	17
alt.philosophy	14
fa.openbsd.tech	14
mozilla.support.firefox	12
mpc.lists.freebsd.gecko	11
alt.pl.nieruchomosci.gielda	11
mozilla.governance	11
TOTAL: 127	1130

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	11518
EMP (phn path)	2111
EMP (phl)	863
Binary: misplaced par2	208
EMP (phn nph)	193
Too many newsgroups	64
Binary Payload	25
User-issued cancel	15
Scoring filter (18)	11
Scoring filter (9)	9
HTML Multipart	8
Scoring filter (12)	5
Binary Image: misplaced jpg	4
HTML post	3
Scoring filter (13)	3
Binary: misplaced rar	3
Too many newsgroups (low_xpost)	2
Scoring filter (11)	2
Scoring filter (14)	2
Poison newsgroup	2
TOTAL: 27	15060

NoCeM on Spool:

Id	Good	Bad	Unique	Total
bleachbot@httrack.com	42	0	44	44
TOTAL: 1	42	0	44	44

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Article posted in the future
	csiph-out.feeder.erje.net	83
	TOTAL: 1	83
Huge articles
	news.fcku.it	84
	csiph-out.news.weretis.net	77
	feeder.eternal-september.org	68
	newsfeed.fu-berlin.de	52
	newsfeeds.xmission.com	37
	news.freedyn.net	26
	news-out.mixmin.net	10
	nntp.pasdenom.info	6
	news.redatomik.org	2
	xanadu-bbs.net	1
	TOTAL: 10	363
Including strange strings
	newsfeed.fu-berlin.de	403
	feeder.eternal-september.org	48
	csiph-out.news.weretis.net	39
	csiph-out.feeder.erje.net	25
	news-out.mixmin.net	20
	news.redatomik.org	11
	newsfeed.neva.ru	9
	news-out.aioe.org	7
	news.swapon.de	3
	newsfeeds.xmission.com	2
	TOTAL: 11	568
TOTAL: 3		1014

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	news.bbs.geek.nz	38170	2439	18175	51	0	6%	23:57:52
2	news.freedyn.net	22181	1340	19933	8	0	6%	23:50:00
3	xanadu-bbs	23618	852	20465	7	123	3%	23:59:42
4	fu-berlin.de	19888	695	19192	0	0	3%	23:50:53
5	erje	17054	367	15709	77	0	2%	23:50:00
6	usenet.pasdenom.info	23859	332	19792	1274	21	1%	23:59:56
7	news.redatomik.org	21219	67	19900	3	0	0%	23:54:55
8	aioe	19123	12	18131	2	0	0%	23:50:01
9	weretis.net	14964	9	14214	0	0	0%	23:50:00
10	xmission	22895	6	19570	2	0	0%	23:59:54
11	eternal-september	19103	6	17350	0	0	0%	23:59:38
12	news.fcku.it	1967	4	1883	0	0	0%	22:38:05
13	news.mixmin.net	19632	3	18813	0	0	0%	23:58:23
14	neva.ru	20344	2	18949	15	0	0%	23:59:02
15	au2pb	0	0	0	0	20604	0%	23:50:06
16	bwh	0	0	0	0	20584	0%	23:50:05
17	news.swapon.de	1964	0	1916	3	0	0%	23:50:19
TOTAL: 17		285981	6134	243992	1442	41332	2%	405:08:51

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.freedyn.net	7.2 MB	29.0 KB	7.3 MB	0.1 KB/s	5.5 KB	23:50:00
2	news.bbs.geek.nz	6.1 MB	178.4 KB	6.3 MB	0.1 KB/s	2.6 KB	23:57:52
3	xanadu-bbs	6.1 MB	12.0 KB	6.1 MB	0.1 KB/s	7.3 KB	23:59:42
4	fu-berlin.de	5.7 MB	0.0 KB	5.7 MB	0.1 KB/s	8.4 KB	23:50:53
5	erje	1.1 MB	289.6 KB	1.4 MB	0.0 KB/s	3.1 KB	23:50:00
6	usenet.pasdenom.info	843.0 KB	6.7 MB	7.5 MB	0.1 KB/s	4.8 KB	23:59:56
7	news.redatomik.org	157.0 KB	10.8 KB	167.8 KB	0.0 KB/s	2.4 KB	23:54:55
8	aioe	32.6 KB	8.0 KB	40.6 KB	0.0 KB/s	2.9 KB	23:50:01
9	weretis.net	21.7 KB	0.0 KB	21.7 KB	0.0 KB/s	2.4 KB	23:50:00
10	eternal-september	15.9 KB	0.0 KB	15.9 KB	0.0 KB/s	2.6 KB	23:59:38
11	news.mixmin.net	12.3 KB	0.0 KB	12.3 KB	0.0 KB/s	4.1 KB	23:58:23
12	xmission	11.9 KB	2.5 KB	14.3 KB	0.0 KB/s	1.8 KB	23:59:54
13	news.fcku.it	9.7 KB	0.0 KB	9.7 KB	0.0 KB/s	2.4 KB	22:38:05
14	neva.ru	4.1 KB	30.9 KB	35.1 KB	0.0 KB/s	2.1 KB	23:59:02
15	au2pb	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:50:06
16	bwh	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:50:05
17	news.swapon.de	0.0 KB	5.8 KB	5.8 KB	0.0 KB/s	1.9 KB	23:50:19
TOTAL: 17		27.3 MB	7.2 MB	34.5 MB	0.0 KB/s	4.7 KB	405:08:51

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	tempe0.bbox.io	30	44	166.3 KB	2	0	0	04:34:55
2	challenger.nielsenmedia.com	6	6	11.5 KB	2	0	0	01:01:33
3	c-73-195-247-24.hsd1.nj.comcast.net	3	5	9.8 KB	2	0	0	01:14:00
4	cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	2	1	2.6 KB	1	1	1	00:34:55
TOTAL: 4		41	56	190.2 KB	7	1	1	16:00:38

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	*.bbox.io	30	44	166.3 KB	2	0	0	04:34:55
2	*.nielsenmedia.com	6	6	11.5 KB	2	0	0	01:01:33
3	*.hsd1.nj.comcast.net	3	5	9.8 KB	2	0	0	01:14:00
4	*.19-1.cable.virginm.net	2	1	2.6 KB	1	1	1	00:34:55
5	*.dhcp.mdsn.wi.charter.com	6	0	0.0 KB	0	0	0	01:30:52
6	*.chello.nl	8	0	0.0 KB	0	0	0	01:14:09
7	unresolved	14	0	0.0 KB	0	0	0	05:50:12
TOTAL: 7		69	56	190.2 KB	7	1	1	16:00:38

NNRP auth users [Top 20]:

User	Conn
jwood	1
TOTAL: 1	1

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
216.239.174.218	0.973	0.348	0.000	05:50:12
tempe0.bbox.io	2.554	0.774	0.000	04:34:55
68-185-181-64.dhcp.mdsn.wi.charter.com	0.474	0.156	0.000	01:30:52
dhcp-089-099-203-254.chello.nl	0.631	0.171	0.000	01:14:09
c-73-195-247-24.hsd1.nj.comcast.net	0.473	0.070	0.000	01:14:00
challenger.nielsenmedia.com	0.523	0.129	0.000	01:01:33
cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	0.235	0.071	0.005	00:34:55
TOTAL: 7	5.863	1.719	0.005	16:00:38

Curious NNRP server explorers [Top 20]:

System	Conn
216.239.174.218	14
dhcp-089-099-203-254.chello.nl	8
68-185-181-64.dhcp.mdsn.wi.charter.com	6
TOTAL: 3	28

NNRP client timeouts [Top 20]:

System	Conn	Peer
216.239.174.218	10	0
tempe0.bbox.io	7	0
challenger.nielsenmedia.com	2	0
68-185-181-64.dhcp.mdsn.wi.charter.com	2	0
c-73-195-247-24.hsd1.nj.comcast.net	2	0
cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	1	0
TOTAL: 6	24	0

Newsgroup request counts (by category):

Category		Count	Pct
1	muc	39	69.6%
2	comp	12	21.4%
3	news	5	8.9%
TOTAL: 3		56	100.0%

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

Newsgroup		Count
1	muc.lists.freebsd.current	39
2	comp.lang.awk	11
3	news.admin.peering	5
4	comp.lang.pl1	1
TOTAL: 4		56

Daily Usenet report for csiph.com

Oct 9 04:15:00 -- Oct 10 04:15:00