Daily Usenet report for csiph.com: Jan 12 04:15:00

Unknown entries from news log file:

First 1 / 1 lines (100.0%)

Jan 12 15:20:02 csiph controlchan[55412]: Unknown "forwarded" control by robomod@news.nic.it

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	56312	58.3%	9.5 MB	69.0%
innd	35887	37.1%	3.6 MB	26.0%
innfeed	3182	3.3%	560.2 KB	4.0%
nnrpd	1223	1.3%	134.7 KB	1.0%
nocem	63	0.1%	6.6 KB	0.0%
controlchan	2	0.0%	0.2 KB	0.0%
TOTAL: 6	96669	100.0%	13.8 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	464510	54.4%
Negative hits	333442	39.0%
Do not exist	55176	6.5%
Cache misses	1236	0.1%
TOTAL: 4	854364	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.670	0.0%	231	0.000	2.900	44.000
article cleanup	00:00:00.327	0.0%	55298	0.000	0.006	0.026
article logging	00:00:04.966	0.0%	55918	0.003	0.089	0.755
article parse	00:00:03.533	0.0%	169700	0.004	0.021	0.125
article write	00:03:02.540	0.2%	24570	0.198	7.429	16.584
artlog/artcncl	00:00:00.004	0.0%	179	0.000	0.022	0.500
artlog/artparse	00:00:00.016	0.0%	234	0.000	0.068	1.667
data move	00:00:00.327	0.0%	767212	0.000	0.000	0.002
hisgrep/artcncl	00:00:00.121	0.0%	224	0.000	0.540	18.000
hishave/artcncl	00:00:00.022	0.0%	231	0.000	0.095	10.000
hishave/artparse	00:00:00.000	0.0%	234	0.000	0.000	0.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:01:27.651	0.1%	858399	0.002	0.102	0.307
history sync	00:00:07.789	0.0%	337	0.000	23.113	174.667
history write	00:04:30.425	0.3%	55225	0.091	4.897	19.586
hiswrite/artcncl	00:00:00.048	0.0%	7	0.000	6.857	35.000
hiswrite/artparse	00:00:01.294	0.0%	234	0.000	5.530	28.000
idle	23:43:26.136	98.8%	754295	29.713	113.226	364.138
nntp read	00:00:03.476	0.0%	783971	0.002	0.004	0.007
overview write	00:04:39.479	0.3%	24570	1.429	11.375	226.889
perl filter	00:01:54.984	0.1%	55043	1.011	2.089	3.818
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.445	0.0%	49199	0.000	0.009	0.026
TOTAL: 24:00:50.036	23:59:24.253	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.070	0.0%	24523	0.000	0.003	0.033
article prepare	00:00:00.004	0.0%	43258	0.000	0.000	0.004
article read	00:00:03.260	0.0%	8372	0.018	0.389	3.759
backlog stats	00:00:00.244	0.0%	448052	0.000	0.001	0.003
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:02.261	0.0%	346797	0.001	0.007	0.013
data write	00:00:02.006	0.0%	330701	0.002	0.006	0.013
idle	23:54:03.536	100.0%	448052	102.736	192.039	583.829
status file	00:00:00.243	0.0%	288	0.000	0.844	6.000
TOTAL: 23:54:20.120	23:54:11.624	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:02.605	0.0%	2609	0.000	0.998	24.000
idle	76:39:00.560	99.8%	3141	1033.000	87851.181	900273.500
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.014	0.0%	6407	0.000	0.002	0.250
readart	00:00:00.525	0.0%	35	0.000	15.000	52.000
TOTAL: 76:48:27.706	76:39:03.704	99.8%	-	-	-	-

Control commands to INND:

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

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	csiph-out.feeder.erje.net	1152	159276	7094	129827	22355	4%	94:58:00
2	csiph-out.news.weretis.net	4	60662	5447	54018	1197	8%	56:50:09
3	feeder.eternal-september.org	1	38918	3499	31235	4184	8%	24:17:09
4	news-out.aioe.org	2	23652	3004	20616	32	12%	24:09:55
5	newsfeed.neva.ru	147	54003	1499	50101	2403	2%	71:24:10
6	newsfeed.fu-berlin.de	54	27231	1416	25422	393	5%	36:54:02
7	news-out.mixmin.net	2	26055	923	24840	292	3%	24:08:56
8	news.redatomik.org	1	25060	631	24420	9	2%	27:19:53
9	newsfeeds.xmission.com	2	20890	553	20336	1	2%	19:34:15
10	news.freedyn.net	4	27544	158	27236	150	0%	24:12:12
11	news.swapon.de	0	2259	119	2137	3	5%	24:28:22
12	news.fcku.it	2	10438	109	10294	35	1%	23:59:47
13	xanadu-bbs.net	14	744	87	655	2	11%	19:31:16
14	nntp.pasdenom.info	3	37946	33	37888	25	0%	24:09:00
15	news.bbs.geek.nz	2	18999	2	18997	0	0%	23:59:31
16	localhost	33	1	1	0	0	100%	00:00:09
TOTAL: 16		1423	533678	24575	478022	31081	4%	519:56:46

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	csiph-out.feeder.erje.net	23.2 MB	679.8 KB	166.8 MB	190.7 MB	12%	6.6 KB
2	csiph-out.news.weretis.net	15.3 MB	0.0 KB	15.5 MB	30.9 MB	49%	4.8 KB
3	feeder.eternal-september.org	9.5 MB	27.3 KB	60.5 MB	70.0 MB	13%	9.3 KB
4	news-out.aioe.org	7.6 MB	0.0 KB	41.4 KB	7.7 MB	99%	2.6 KB
5	news-out.mixmin.net	4.8 MB	3.2 KB	1.5 MB	6.3 MB	75%	5.3 KB
6	newsfeed.neva.ru	3.8 MB	77.0 KB	18.4 MB	22.3 MB	17%	5.9 KB
7	newsfeed.fu-berlin.de	3.3 MB	0.0 KB	860.1 KB	4.2 MB	79%	2.4 KB
8	news.redatomik.org	1.8 MB	0.0 KB	517.5 KB	2.3 MB	78%	3.7 KB
9	newsfeeds.xmission.com	1.6 MB	0.8 KB	0.8 KB	1.6 MB	99%	2.9 KB
10	news.freedyn.net	552.5 KB	0.0 KB	2.8 MB	3.3 MB	16%	11.0 KB
11	news.swapon.de	283.5 KB	0.0 KB	6.5 KB	290.0 KB	97%	2.4 KB
12	news.fcku.it	251.0 KB	0.0 KB	706.3 KB	957.2 KB	26%	6.6 KB
13	xanadu-bbs.net	205.7 KB	0.0 KB	12.2 KB	217.9 KB	94%	2.4 KB
14	nntp.pasdenom.info	68.8 KB	0.0 KB	56.5 KB	125.3 KB	54%	2.2 KB
15	news.bbs.geek.nz	5.8 KB	0.0 KB	0.0 KB	5.8 KB	100%	2.9 KB
16	localhost	1.0 KB	0.0 KB	0.0 KB	1.0 KB	100%	1.0 KB
TOTAL: 16		72.2 MB	788.1 KB	267.7 MB	340.8 MB	21%	6.3 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Jan 12 04:15:00 - 04:59:59	316	1.3%	0.12	929.6 KB	1.3%	0.34
Jan 12 05:00:00 - 05:59:59	528	2.1%	0.15	1.9 MB	2.6%	0.54
Jan 12 06:00:00 - 06:59:59	610	2.5%	0.17	2.4 MB	3.3%	0.69
Jan 12 07:00:00 - 07:59:59	561	2.3%	0.16	1.6 MB	2.3%	0.47
Jan 12 08:00:00 - 08:59:59	976	4.0%	0.27	3.0 MB	4.2%	0.86
Jan 12 09:00:00 - 09:59:59	1045	4.3%	0.29	3.2 MB	4.4%	0.91
Jan 12 10:00:00 - 10:59:59	1318	5.4%	0.37	3.9 MB	5.4%	1.11
Jan 12 11:00:00 - 11:59:59	1152	4.7%	0.32	3.1 MB	4.2%	0.87
Jan 12 12:00:00 - 12:59:59	1095	4.5%	0.30	2.9 MB	4.0%	0.83
Jan 12 13:00:00 - 13:59:59	1174	4.8%	0.33	3.0 MB	4.1%	0.85
Jan 12 14:00:00 - 14:59:59	1191	4.8%	0.33	2.9 MB	4.0%	0.82
Jan 12 15:00:00 - 15:59:59	1375	5.6%	0.38	4.1 MB	5.7%	1.18
Jan 12 16:00:00 - 16:59:59	1613	6.6%	0.45	5.2 MB	7.2%	1.47
Jan 12 17:00:00 - 17:59:59	1662	6.8%	0.46	4.8 MB	6.7%	1.37
Jan 12 18:00:00 - 18:59:59	1338	5.4%	0.37	4.1 MB	5.7%	1.18
Jan 12 19:00:00 - 19:59:59	1441	5.9%	0.40	4.3 MB	6.0%	1.23
Jan 12 20:00:00 - 20:59:59	1309	5.3%	0.36	3.4 MB	4.7%	0.98
Jan 12 21:00:00 - 21:59:59	1292	5.3%	0.36	3.5 MB	4.9%	1.00
Jan 12 22:00:00 - 22:59:59	1186	4.8%	0.33	3.2 MB	4.5%	0.92
Jan 12 23:00:00 - 23:59:59	984	4.0%	0.27	3.3 MB	4.5%	0.93
Jan 13 00:00:00 - 00:59:59	751	3.1%	0.21	2.2 MB	3.1%	0.64
Jan 13 01:00:00 - 01:59:59	563	2.3%	0.16	1.5 MB	2.1%	0.43
Jan 13 02:00:00 - 02:59:59	473	1.9%	0.13	1.5 MB	2.0%	0.41
Jan 13 03:00:00 - 03:59:59	476	1.9%	0.13	1.5 MB	2.1%	0.43
Jan 13 04:00:00 - 04:15:00	158	0.6%	0.18	680.8 KB	0.9%	0.76
TOTAL: 24:00:00	24587	100.0%	0.28	72.3 MB	100.0%	0.86

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	csiph-out.feeder.erje.net	22369	459	61	2	21847
2	feeder.eternal-september.org	4164	53	2	0	4109
3	newsfeed.neva.ru	2395	326	8	0	2061
4	csiph-out.news.weretis.net	1189	223	0	0	966
5	newsfeed.fu-berlin.de	817	32	0	0	785
6	news-out.mixmin.net	298	0	1	0	297
7	news.freedyn.net	148	17	0	0	131
8	news-out.aioe.org	66	30	0	0	36
9	news.fcku.it	36	0	0	0	36
10	nntp.pasdenom.info	24	0	0	0	24
11	news.swapon.de	20	0	0	0	20
12	news.redatomik.org	11	0	0	0	11
13	newsfeeds.xmission.com	5	1	1	0	3
14	xanadu-bbs.net	4	0	0	0	4
TOTAL: 14		31546	1141	73	2	30330

Unwanted newsgroups [Top 20]:

Newsgroup	Count
ut.test	146
lada.auto	116
lada.talk	109
it.annunci.commerciali	58
it.annunci.immobiliari	58
it.annunci.varie	57
it-alt.sport.calcio.juventus	48
mozilla.test	43
alt.windows7.general	31
gmane.comp.gis.openstreetmap.tagging	29
mpc.lists.nanog	25
gmane.linux.alsa.devel	23
alt.survival	17
gmane.linux.kernel	16
mozilla.support.seamonkey	16
alt.computer.workshop	16
mozilla.dev.security.policy	14
spline.eisfair	11
mozilla.support.thunderbird	10
lada.commerce	10
TOTAL: 141	1141

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

Groups	Count
nz.politics.announce	2
TOTAL: 1	2

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	15088
Too many newsgroups	11681
EMP (phn path)	1769
EMP (phl)	457
EMP (phn nph)	173
User-issued cancel	22
Scoring filter (8)	22
HTML Multipart	18
Binary Payload	16
Scoring filter (9)	11
HTML post	8
Scoring filter (12)	7
Scoring filter (13)	5
Scoring filter (18)	5
Scoring filter (10)	4
User-issued spam cancel	4
Scoring filter (11)	3
Binary: misplaced par2	3
HTML Image Tags	2
Scoring filter (16)	1
TOTAL: 21	29300

NoCeM on Spool:

Id	Good	Bad	Unique	Total
bleachbot@httrack.com	58	0	63	63
TOTAL: 1	58	0	63	63

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Article posted in the future
	csiph-out.feeder.erje.net	182
	TOTAL: 1	182
Bad Message-ID's offered
	csiph-out.feeder.erje.net	16
	TOTAL: 1	16
Huge articles
	feeder.eternal-september.org	126
	csiph-out.news.weretis.net	55
	news.freedyn.net	23
	news-out.mixmin.net	22
	news.fcku.it	5
	news.redatomik.org	1
	TOTAL: 6	232
Including strange strings
	newsfeed.fu-berlin.de	451
	csiph-out.news.weretis.net	45
	news-out.aioe.org	33
	csiph-out.feeder.erje.net	30
	feeder.eternal-september.org	21
	news.swapon.de	17
	newsfeed.neva.ru	9
	news-out.mixmin.net	4
	news.redatomik.org	3
	newsfeeds.xmission.com	3
	TOTAL: 10	616
TOTAL: 4		1046

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Miss	Spool	%Took	Elapsed
1	news.bbs.geek.nz	40758	6590	17224	110	1	0	16%	23:58:41
2	news.freedyn.net	24876	764	23562	2	0	0	3%	23:50:05
3	xanadu-bbs	27342	654	23801	1	0	18	2%	23:59:55
4	fu-berlin.de	22855	604	22250	0	0	0	2%	23:50:05
5	erje	18488	167	17134	12	0	0	0%	23:55:18
6	usenet.pasdenom.info	27202	97	22774	1673	0	4	0%	23:59:55
7	eternal-september	21599	36	20045	1	0	1	0%	23:59:55
8	aioe	20650	27	19583	4	0	0	0%	23:58:29
9	news.redatomik.org	24322	16	23220	3	0	0	0%	23:51:11
10	xmission	26381	15	23097	3	0	2	0%	23:59:56
11	weretis.net	18083	10	17735	0	0	0	0%	23:50:36
12	news.mixmin.net	22406	2	21647	0	0	0	0%	23:58:18
13	neva.ru	23112	2	22056	32	0	1	0%	23:59:54
14	news.swapon.de	2229	2	2206	0	0	0	0%	23:55:17
15	news.fcku.it	2843	0	2778	0	0	0	0%	22:36:24
16	bwh	0	0	0	0	0	23837	0%	23:50:02
17	au2pb	0	0	0	0	0	23859	0%	23:50:02
TOTAL: 17		323146	8986	279112	1841	1	47722	2%	405:24:03

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.bbs.geek.nz	17.5 MB	466.3 KB	18.0 MB	0.2 KB/s	2.8 KB	23:58:41
2	news.freedyn.net	6.3 MB	36.4 KB	6.3 MB	0.1 KB/s	8.4 KB	23:50:05
3	xanadu-bbs	6.0 MB	1.7 KB	6.0 MB	0.1 KB/s	9.3 KB	23:59:55
4	fu-berlin.de	5.8 MB	0.0 KB	5.8 MB	0.1 KB/s	9.8 KB	23:50:05
5	erje	515.7 KB	90.3 KB	606.0 KB	0.0 KB/s	3.4 KB	23:55:18
6	usenet.pasdenom.info	335.7 KB	7.7 MB	8.0 MB	0.1 KB/s	4.7 KB	23:59:55
7	eternal-september	105.3 KB	1.3 KB	106.6 KB	0.0 KB/s	2.9 KB	23:59:55
8	aioe	87.2 KB	30.2 KB	117.4 KB	0.0 KB/s	3.8 KB	23:58:29
9	news.redatomik.org	66.1 KB	37.7 KB	103.9 KB	0.0 KB/s	5.5 KB	23:51:11
10	xmission	49.1 KB	5.7 KB	54.9 KB	0.0 KB/s	3.0 KB	23:59:56
11	weretis.net	22.3 KB	0.0 KB	22.3 KB	0.0 KB/s	2.2 KB	23:50:36
12	news.mixmin.net	17.1 KB	0.0 KB	17.1 KB	0.0 KB/s	8.6 KB	23:58:18
13	neva.ru	5.0 KB	148.4 KB	153.3 KB	0.0 KB/s	4.5 KB	23:59:54
14	news.swapon.de	2.7 KB	0.0 KB	2.7 KB	0.0 KB/s	1.4 KB	23:55:17
15	news.fcku.it	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	22:36:24
16	bwh	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:50:02
17	au2pb	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:50:02
TOTAL: 17		36.7 MB	8.5 MB	45.3 MB	0.0 KB/s	4.3 KB	405:24:03

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	tempe0.bbox.io	20	25	99.5 KB	5	0	0	05:20:29
2	194-73-239-109.cust.centrio.cz	23	7	26.5 KB	7	0	0	05:16:18
3	dhcp-089-099-203-254.chello.nl	30	2	1.9 KB	2	0	0	08:09:14
4	68-185-181-64.dhcp.mdsn.wi.charter.com	17	1	1.0 KB	1	1	1	04:49:27
TOTAL: 4		90	35	128.8 KB	15	1	1	76:48:25

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	*.bbox.io	20	25	99.5 KB	5	0	0	05:20:29
2	*.cust.centrio.cz	23	7	26.5 KB	7	0	0	05:16:18
3	*.chello.nl	30	2	1.9 KB	2	0	0	08:09:14
4	*.dhcp.mdsn.wi.charter.com	17	1	1.0 KB	1	1	1	04:49:27
5	unresolved	101	0	0.0 KB	0	0	0	49:41:37
6	*.251.91.75.dynamic.ip.windstream.net	2	0	0.0 KB	0	0	0	03:31:17
TOTAL: 6		193	35	128.8 KB	15	1	1	76:48:25

NNRP auth users [Top 20]:

User	Conn
ctomczyk	14
ohlandl	1
TOTAL: 2	15

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
216.239.174.218	7.909	1.691	0.000	49:41:37
dhcp-089-099-203-254.chello.nl	2.510	0.569	0.000	08:09:14
tempe0.bbox.io	1.939	0.357	0.000	05:20:29
194-73-239-109.cust.centrio.cz	1.925	0.449	0.045	05:16:18
68-185-181-64.dhcp.mdsn.wi.charter.com	1.359	0.343	0.004	04:49:27
h23.251.91.75.dynamic.ip.windstream.net	0.214	0.169	0.000	03:31:17
TOTAL: 6	15.856	3.578	0.049	76:48:25

Curious NNRP server explorers [Top 20]:

System	Conn
216.239.174.218	101
h23.251.91.75.dynamic.ip.windstream.net	2
TOTAL: 2	103

NNRP client timeouts [Top 20]:

System	Conn	Peer
216.239.174.218	97	0
194-73-239-109.cust.centrio.cz	10	0
tempe0.bbox.io	9	0
68-185-181-64.dhcp.mdsn.wi.charter.com	5	0
h23.251.91.75.dynamic.ip.windstream.net	2	0
TOTAL: 5	123	0

Newsgroup request counts (by category):

Category		Count	Pct
1	muc	25	71.4%
2	comp	10	28.6%
TOTAL: 2		35	100.0%

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

Newsgroup		Count
1	muc.lists.freebsd.current	18
2	comp.lang.javascript	7
3	muc.lists.freebsd.hackers	6
4	comp.sys.ibm.ps2.hardware	3
5	muc.lists.freebsd.security	1
TOTAL: 5		35

Daily Usenet report for csiph.com

Jan 12 04:15:00 -- Jan 13 04:15:00