Daily Usenet report for csiph.com: Apr 8 04:15:00

Unknown entries from news log file:

First 1 / 1 lines (100.0%)

Apr 8 13:00:02 csiph controlchan[68326]: Multiple control headers in article <ttY89-5k1-3@gated-at.bofh.it>

Log entries by program:

Program name	Lines	%Lines	Size	%Size
nnrpd	51975	44.4%	5.5 MB	35.7%
inn	37974	32.4%	6.8 MB	44.3%
innd	23870	20.4%	2.6 MB	16.7%
innfeed	3200	2.7%	522.3 KB	3.3%
nocem	98	0.1%	10.4 KB	0.1%
controlchan	2	0.0%	0.2 KB	0.0%
TOTAL: 6	117119	100.0%	15.3 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	347224	55.0%
Negative hits	246646	39.1%
Do not exist	36927	5.8%
Cache misses	526	0.1%
TOTAL: 4	631323	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:03.053	0.0%	286	0.000	10.675	106.833
article cleanup	00:00:00.266	0.0%	37167	0.000	0.007	0.032
article logging	00:00:04.808	0.0%	37687	0.000	0.128	1.558
article parse	00:00:02.378	0.0%	124697	0.005	0.019	0.412
article write	00:02:35.878	0.2%	18574	0.214	8.392	45.310
artlog/artcncl	00:00:00.007	0.0%	198	0.000	0.035	0.667
artlog/artparse	00:00:00.025	0.0%	120	0.000	0.208	7.333
data move	00:00:00.251	0.0%	589786	0.000	0.000	0.002
hisgrep/artcncl	00:00:01.559	0.0%	285	0.000	5.470	74.944
hishave/artcncl	00:00:00.423	0.0%	286	0.000	1.479	16.667
hishave/artparse	00:00:00.002	0.0%	120	0.000	0.017	0.333
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:02:14.695	0.2%	635139	0.003	0.212	1.835
history sync	00:00:04.289	0.0%	358	0.000	11.980	66.000
history write	00:03:47.979	0.3%	37098	0.171	6.145	51.910
hiswrite/artcncl	00:00:00.002	0.0%	1	2.000	2.000	2.000
hiswrite/artparse	00:00:00.947	0.0%	120	0.000	7.892	55.800
idle	23:44:08.157	98.8%	580611	85.886	147.169	558.495
nntp read	00:00:02.899	0.0%	603620	0.002	0.005	0.050
overview write	00:04:54.526	0.3%	18574	1.319	15.857	158.208
perl filter	00:01:38.798	0.1%	36983	1.362	2.671	5.535
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.363	0.0%	37241	0.000	0.010	0.032
TOTAL: 24:00:56.893	23:59:41.305	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.043	0.0%	18572	0.000	0.002	0.029
article prepare	00:00:00.002	0.0%	37432	0.000	0.000	0.006
article read	00:00:01.610	0.0%	6656	0.000	0.242	31.667
backlog stats	00:00:00.209	0.0%	336878	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.782	0.0%	264000	0.003	0.007	0.013
data write	00:00:01.561	0.0%	248007	0.001	0.006	0.013
idle	23:54:19.494	100.0%	336878	141.589	255.462	690.300
status file	00:00:00.488	0.0%	277	0.000	1.762	36.000
TOTAL: 23:54:32.926	23:54:25.189	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:01.654	0.0%	1414	1.170	1.170	1.170
idle	67:10:00.440	99.4%	1046823	60.000	230.985	600446.000
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:15.257	0.0%	2584111	0.000	0.006	0.167
readart	00:19:14.226	0.5%	980323	0.000	1.177	126.000
TOTAL: 67:33:05.009	67:29:31.577	99.9%	-	-	-	-

Control commands to INND:

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

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	csiph-out.news.weretis.net	2	35342	5187	29258	897	14%	42:44:46
2	csiph-out.feeder.erje.net	1152	116591	4728	99152	12711	4%	94:57:53
3	feeder.eternal-september.org	5	32432	2421	26192	3819	7%	24:37:59
4	news-out.aioe.org	2	18241	1245	16977	19	6%	24:09:01
5	news-out.mixmin.net	3	19776	1209	18165	402	6%	24:08:45
6	newsfeed.fu-berlin.de	16	21303	986	20072	245	4%	28:57:43
7	newsfeeds.xmission.com	2	16608	912	15688	8	5%	22:02:04
8	newsfeed.neva.ru	149	49406	856	46585	1965	1%	72:25:26
9	news.redatomik.org	1	17284	467	16814	3	2%	23:40:14
10	news.fcku.it	1	7695	229	7389	77	2%	23:59:55
11	xanadu-bbs.net	13	826	183	640	3	22%	26:49:41
12	news.swapon.de	3	2603	77	2524	2	2%	32:59:04
13	nntp.pasdenom.info	2	16764	52	16702	10	0%	23:58:55
14	news.freedyn.net	2	21314	50	21154	110	0%	23:59:47
15	news.bbs.geek.nz	1	14248	15	14232	1	0%	23:59:46
16	localhost	32	0	0	0	0	0%	00:00:01
TOTAL: 16		1386	390433	18617	351544	20272	4%	513:31:00

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	csiph-out.feeder.erje.net	17.9 MB	773.0 KB	73.7 MB	92.3 MB	19%	5.4 KB
2	csiph-out.news.weretis.net	15.3 MB	11.9 KB	11.7 MB	27.0 MB	56%	4.5 KB
3	feeder.eternal-september.org	6.3 MB	62.6 KB	48.0 MB	54.3 MB	11%	8.9 KB
4	news-out.mixmin.net	4.4 MB	0.0 KB	1.3 MB	5.7 MB	77%	3.6 KB
5	news-out.aioe.org	3.1 MB	0.0 KB	62.6 KB	3.2 MB	98%	2.6 KB
6	newsfeeds.xmission.com	2.8 MB	0.0 KB	517.2 KB	3.4 MB	84%	3.7 KB
7	newsfeed.fu-berlin.de	2.1 MB	0.0 KB	587.3 KB	2.7 MB	78%	2.2 KB
8	newsfeed.neva.ru	2.0 MB	24.9 KB	19.9 MB	21.9 MB	9%	8.0 KB
9	news.redatomik.org	1.2 MB	0.0 KB	409.8 KB	1.6 MB	75%	3.6 KB
10	news.fcku.it	548.8 KB	0.0 KB	3.2 MB	3.8 MB	14%	12.6 KB
11	xanadu-bbs.net	527.5 KB	0.0 KB	4.2 KB	531.6 KB	99%	2.9 KB
12	news.freedyn.net	270.3 KB	37.3 KB	3.5 MB	3.8 MB	7%	24.1 KB
13	news.swapon.de	184.0 KB	0.0 KB	202.4 KB	386.3 KB	47%	4.9 KB
14	nntp.pasdenom.info	171.2 KB	0.0 KB	10.4 KB	181.6 KB	94%	2.9 KB
15	news.bbs.geek.nz	42.3 KB	0.0 KB	1.2 KB	43.5 KB	97%	2.7 KB
16	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 16		56.9 MB	909.7 KB	162.9 MB	220.7 MB	25%	5.8 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Apr 8 04:15:00 - 04:59:59	270	1.5%	0.10	748.2 KB	1.3%	0.28
Apr 8 05:00:00 - 05:59:59	486	2.6%	0.14	1.7 MB	2.9%	0.47
Apr 8 06:00:00 - 06:59:59	653	3.5%	0.18	2.4 MB	4.2%	0.68
Apr 8 07:00:00 - 07:59:59	750	4.0%	0.21	2.6 MB	4.5%	0.74
Apr 8 08:00:00 - 08:59:59	947	5.1%	0.26	2.9 MB	5.1%	0.83
Apr 8 09:00:00 - 09:59:59	905	4.9%	0.25	2.5 MB	4.5%	0.72
Apr 8 10:00:00 - 10:59:59	767	4.1%	0.21	2.7 MB	4.7%	0.76
Apr 8 11:00:00 - 11:59:59	880	4.7%	0.24	2.9 MB	5.0%	0.82
Apr 8 12:00:00 - 12:59:59	881	4.7%	0.24	2.6 MB	4.6%	0.74
Apr 8 13:00:00 - 13:59:59	1088	5.9%	0.30	3.2 MB	5.7%	0.92
Apr 8 14:00:00 - 14:59:59	1043	5.6%	0.29	3.0 MB	5.3%	0.86
Apr 8 15:00:00 - 15:59:59	1087	5.9%	0.30	3.2 MB	5.7%	0.92
Apr 8 16:00:00 - 16:59:59	1072	5.8%	0.30	3.3 MB	5.8%	0.94
Apr 8 17:00:00 - 17:59:59	947	5.1%	0.26	2.5 MB	4.4%	0.72
Apr 8 18:00:00 - 18:59:59	977	5.3%	0.27	3.1 MB	5.5%	0.89
Apr 8 19:00:00 - 19:59:59	1052	5.7%	0.29	2.8 MB	4.9%	0.79
Apr 8 20:00:00 - 20:59:59	879	4.7%	0.24	2.4 MB	4.3%	0.70
Apr 8 21:00:00 - 21:59:59	786	4.2%	0.22	2.2 MB	3.9%	0.63
Apr 8 22:00:00 - 22:59:59	626	3.4%	0.17	2.0 MB	3.6%	0.58
Apr 8 23:00:00 - 23:59:59	607	3.3%	0.17	1.9 MB	3.4%	0.55
Apr 9 00:00:00 - 00:59:59	542	2.9%	0.15	1.7 MB	3.1%	0.50
Apr 9 01:00:00 - 01:59:59	406	2.2%	0.11	1.3 MB	2.2%	0.36
Apr 9 02:00:00 - 02:59:59	390	2.1%	0.11	1.3 MB	2.3%	0.37
Apr 9 03:00:00 - 03:59:59	386	2.1%	0.11	1.3 MB	2.2%	0.36
Apr 9 04:00:00 - 04:15:00	143	0.8%	0.16	527.9 KB	0.9%	0.59
TOTAL: 24:00:00	18570	100.0%	0.21	57.0 MB	100.0%	0.68

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	csiph-out.feeder.erje.net	11183	233	60	2	10888
2	feeder.eternal-september.org	3805	79	5	0	3721
3	newsfeed.neva.ru	1958	235	2	0	1721
4	csiph-out.news.weretis.net	1044	164	1	0	879
5	newsfeed.fu-berlin.de	558	8	0	0	550
6	news-out.mixmin.net	422	2	0	0	420
7	news.freedyn.net	110	8	1	0	101
8	news.fcku.it	72	0	0	0	72
9	news-out.aioe.org	24	14	0	0	10
10	nntp.pasdenom.info	11	9	0	0	2
11	newsfeeds.xmission.com	8	0	0	0	8
12	news.swapon.de	5	0	0	0	5
13	news.redatomik.org	4	0	0	0	4
14	xanadu-bbs.net	3	0	0	0	3
TOTAL: 14		19207	752	69	2	18384

Unwanted newsgroups [Top 20]:

Newsgroup	Count
ut.test	123
lada.talk	86
mozilla.support.thunderbird	48
alt.survival	44
lada.kitchen	37
lada.auto	29
it-alt.sport.calcio.juventus	26
alt.binaries.bungalow	25
it.annunci.varie	24
alt.politics.scorched-earth	17
mpc.lists.freebsd.ports.bugs	17
alt.windows7.general	16
mozilla.general	13
mozilla.support.firefox	13
alt.2600	13
mozilla.support.seamonkey	12
lada.commerce	11
alt.tv.star-trek	10
alt.computer.workshop	9
gmane.comp.gis.openstreetmap.tagging	9
TOTAL: 103	752

Supposedly-moderated groups with unmoderated postings [Top 20]:

Groups	Count
it.scienza.astronomia	1
nz.politics.announce	1
TOTAL: 2	2

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	16124
EMP (phn path)	1128
EMP (phn nph)	88
Too many newsgroups	75
Binary Payload	59
User-issued cancel	41
Scoring filter (10)	28
Scoring filter (8)	25
HTML Multipart	25
Scoring filter (9)	8
Too many newsgroups (low_xpost)	8
Scoring filter (11)	7
Scoring filter (12)	6
Binary Image: misplaced jpg	2
Binary: non-binary distribution	2
Too many newsgroups (meow)	1
Scoring filter (13)	1
Scoring filter (14)	1
EMP (phl)	1
TOTAL: 19	17630

NoCeM on Spool:

Id	Good	Bad	Unique	Total
bleachbot@httrack.com	92	0	107	107
TOTAL: 1	92	0	107	107

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Article posted in the future
	csiph-out.feeder.erje.net	114
	TOTAL: 1	114
Bad Message-ID's offered
	csiph-out.feeder.erje.net	4
	TOTAL: 1	4
Huge articles
	csiph-out.news.weretis.net	75
	news.freedyn.net	15
	feeder.eternal-september.org	11
	news.fcku.it	7
	news-out.mixmin.net	6
	newsfeeds.xmission.com	3
	news.redatomik.org	2
	news.swapon.de	1
	TOTAL: 8	120
Including strange strings
	newsfeed.fu-berlin.de	359
	csiph-out.feeder.erje.net	59
	csiph-out.news.weretis.net	51
	news-out.mixmin.net	30
	feeder.eternal-september.org	4
	news.swapon.de	4
	news-out.aioe.org	4
	newsfeed.neva.ru	3
	newsfeeds.xmission.com	2
	news.fcku.it	2
	TOTAL: 11	519
TOTAL: 4		757

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	news.bbs.geek.nz	29967	4624	13052	110	0	15%	23:59:55
2	xanadu-bbs	20360	885	17527	2	49	4%	23:59:55
3	news.freedyn.net	19210	884	17632	3	0	4%	23:59:55
4	fu-berlin.de	17442	728	16714	0	0	4%	23:59:55
5	usenet.pasdenom.info	19961	170	16508	1843	4	0%	23:59:50
6	xmission	18974	47	16780	7	0	0%	23:59:55
7	news.redatomik.org	17804	16	17280	4	0	0%	23:59:51
8	aioe	16620	16	15816	0	0	0%	23:59:55
9	weretis.net	12033	6	11612	0	0	0%	23:59:55
10	erje	13805	3	13754	6	0	0%	23:59:47
11	eternal-september	16346	3	15188	0	0	0%	23:59:54
12	news.mixmin.net	16954	3	16390	0	0	0%	23:59:53
13	news.fcku.it	1250	0	1240	0	0	0%	22:08:58
14	neva.ru	17241	0	16777	10	0	0%	23:59:55
15	au2pb	0	0	0	0	17796	0%	23:58:42
16	news.swapon.de	1855	0	1824	1	0	0%	23:44:34
17	bwh	0	0	0	0	17793	0%	23:58:42
TOTAL: 17		239822	7385	208094	1986	35642	3%	405:49:31

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.bbs.geek.nz	12.5 MB	575.8 KB	13.1 MB	0.2 KB/s	2.8 KB	23:59:55
2	news.freedyn.net	6.8 MB	11.6 KB	6.8 MB	0.1 KB/s	7.8 KB	23:59:55
3	xanadu-bbs	6.8 MB	4.4 KB	6.8 MB	0.1 KB/s	7.8 KB	23:59:55
4	fu-berlin.de	6.3 MB	0.0 KB	6.3 MB	0.1 KB/s	8.9 KB	23:59:55
5	usenet.pasdenom.info	638.3 KB	8.2 MB	8.8 MB	0.1 KB/s	4.5 KB	23:59:50
6	xmission	97.9 KB	20.8 KB	118.6 KB	0.0 KB/s	2.2 KB	23:59:55
7	news.redatomik.org	44.9 KB	12.0 KB	56.9 KB	0.0 KB/s	2.8 KB	23:59:51
8	aioe	35.7 KB	0.0 KB	35.7 KB	0.0 KB/s	2.2 KB	23:59:55
9	weretis.net	17.9 KB	0.0 KB	17.9 KB	0.0 KB/s	3.0 KB	23:59:55
10	eternal-september	10.0 KB	0.0 KB	10.0 KB	0.0 KB/s	3.3 KB	23:59:54
11	news.mixmin.net	8.7 KB	0.0 KB	8.7 KB	0.0 KB/s	2.9 KB	23:59:53
12	erje	8.2 KB	66.6 KB	74.9 KB	0.0 KB/s	8.3 KB	23:59:47
13	news.fcku.it	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	22:08:58
14	neva.ru	0.0 KB	64.3 KB	64.3 KB	0.0 KB/s	6.4 KB	23:59:55
15	au2pb	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:58:42
16	news.swapon.de	0.0 KB	2.2 KB	2.2 KB	0.0 KB/s	2.2 KB	23:44:34
17	bwh	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:58:42
TOTAL: 17		33.2 MB	9.0 MB	42.2 MB	0.0 KB/s	4.6 KB	405:49:31

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Elapsed
1	mtrlpq2314w-lp130-04-70-54-157-241.dsl.bell.ca	1252	244754	850.4 MB	2956	27:11:05
2	ess-p-144-138-90-254.mega.tmns.net.au	291	70	269.9 KB	67	03:30:25
3	204-73-239-109.cust.centrio.cz	8	10	19.2 KB	4	01:32:33
4	dhcp-089-099-203-254.chello.nl	78	2	2.5 KB	2	24:47:04
5	68-185-181-64.dhcp.mdsn.wi.charter.com	10	1	1.5 KB	1	02:27:17
TOTAL: 5		1639	244837	850.7 MB	3030	67:32:51

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	*.dsl.bell.ca	1252	244754	850.4 MB	2956	27:11:05
2	*.mega.tmns.net.au	291	70	269.9 KB	67	03:30:25
3	*.cust.centrio.cz	8	10	19.2 KB	4	01:32:33
4	*.chello.nl	78	2	2.5 KB	2	24:47:04
5	*.dhcp.mdsn.wi.charter.com	10	1	1.5 KB	1	02:27:17
6	*.bbox.io	9	0	0.0 KB	0	04:07:44
7	*.hsd1.wa.comcast.net	4	0	0.0 KB	0	02:00:05
8	*.141.22.98.dynamic.ip.windstream.net	1	0	0.0 KB	0	01:56:31
9	unresolved	2	0	0.0 KB	0	00:00:02
TOTAL: 9		1655	244837	850.7 MB	3030	67:32:51

NNRP auth users [Top 20]:

User	Conn
moussa	291
ctomczyk	4
TOTAL: 2	295

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
mtrlpq2314w-lp130-04-70-54-157-241.dsl.bell.ca	159.801	114.513	0.000	27:11:05
dhcp-089-099-203-254.chello.nl	5.601	1.209	0.000	24:47:04
tempe0.bbox.io	0.712	0.155	0.000	04:07:44
ess-p-144-138-90-254.mega.tmns.net.au	24.768	6.305	1.029	03:30:25
68-185-181-64.dhcp.mdsn.wi.charter.com	0.786	0.168	0.000	02:27:17
c-174-61-130-222.hsd1.wa.comcast.net	0.321	0.068	0.000	02:00:05
h69.141.22.98.dynamic.ip.windstream.net	0.111	0.103	0.000	01:56:31
204-73-239-109.cust.centrio.cz	0.826	0.125	0.014	01:32:33
94.164.10.215	0.081	0.024	0.000	00:00:02
66.240.219.146	0.090	0.016	0.000	00:00:00
TOTAL: 10	193.097	122.686	1.043	67:32:51

Curious NNRP server explorers [Top 20]:

System	Conn
tempe0.bbox.io	9
c-174-61-130-222.hsd1.wa.comcast.net	4
66.240.219.146	1
94.164.10.215	1
h69.141.22.98.dynamic.ip.windstream.net	1
TOTAL: 5	16

NNRP client timeouts [Top 20]:

System	Conn	Peer
tempe0.bbox.io	8	0
c-174-61-130-222.hsd1.wa.comcast.net	4	0
68-185-181-64.dhcp.mdsn.wi.charter.com	2	0
204-73-239-109.cust.centrio.cz	2	0
h69.141.22.98.dynamic.ip.windstream.net	1	0
TOTAL: 5	17	0

Newsgroup request counts (by category):

Category		Count	Pct
1	talk	244532	99.9%
2	alt	192	0.1%
3	comp	82	0.0%
4	fr	12	0.0%
5	uk	7	0.0%
6	sci	4	0.0%
7	soc	4	0.0%
8	rec	2	0.0%
9	aus	1	0.0%
10	pl	1	0.0%
TOTAL: 10		244837	100.0%

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

Newsgroup		Count
1	talk.politics.guns	244532
2	alt.atheism	161
3	comp.os.vms	31
4	comp.arch	30
5	fr.soc.politique	12
6	comp.lang.javascript	9
7	alt.home.repair	9
8	uk.rec.drugs.cannabis	6
9	comp.sys.ibm.ps2.hardware	5
10	alt.society.liberalism	4
11	alt.california	4
12	sci.physics	4
13	soc.culture.usa	4
14	alt.comp.freeware	3
15	alt.christnet.christianlife	3
16	alt.bible.prophecy	3
17	comp.ai.philosophy	2
18	comp.os.os2.programmer.misc	2
19	alt.religion.christian	2
20	comp.os.os2.advocacy	1
21	rec.crafts.metalworking	1
22	alt.messianic	1
23	pl.comp.www	1
24	alt.politics.trump	1
25	comp.sys.ibm.pc.games.adventure	1
26	rec.arts.tv	1
27	uk.legal	1
28	comp.sys.ibm.pc.games.action	1
29	alt.talk.creationism	1
30	aus.politics	1
TOTAL: 30		244837

Daily Usenet report for csiph.com

Apr 8 04:15:00 -- Apr 9 04:15:00