Daily Usenet report for csiph.com: Nov 15 04:15:00

Unknown entries from news log file:

First 50 / 2843 lines (1.8%)

Nov 15 04:15:23 csiph nnrpd[29070]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:15:53 csiph nnrpd[29071]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:16:23 csiph nnrpd[29093]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:16:54 csiph nnrpd[29098]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:17:26 csiph nnrpd[29099]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:17:56 csiph nnrpd[29125]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:18:26 csiph nnrpd[29126]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:18:56 csiph nnrpd[29157]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:19:26 csiph nnrpd[29158]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:19:56 csiph nnrpd[29184]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:20:26 csiph nnrpd[29221]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:20:57 csiph nnrpd[29254]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:21:27 csiph nnrpd[29255]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:21:57 csiph nnrpd[29281]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:22:27 csiph nnrpd[29304]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:22:57 csiph nnrpd[29327]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:23:27 csiph nnrpd[29331]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:23:57 csiph nnrpd[29344]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:24:28 csiph nnrpd[29370]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:24:58 csiph nnrpd[29371]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:25:28 csiph nnrpd[29407]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:25:58 csiph nnrpd[29408]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:26:28 csiph nnrpd[29435]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:26:58 csiph nnrpd[29436]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:27:28 csiph nnrpd[29462]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:27:58 csiph nnrpd[29463]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:28:28 csiph nnrpd[29489]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:28:58 csiph nnrpd[29490]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:29:28 csiph nnrpd[29498]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:29:58 csiph nnrpd[29518]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:30:28 csiph nnrpd[29529]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:30:58 csiph nnrpd[29555]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:31:28 csiph nnrpd[29565]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:31:58 csiph nnrpd[29591]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:32:28 csiph nnrpd[29727]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:32:58 csiph nnrpd[29753]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:33:28 csiph nnrpd[29775]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:33:58 csiph nnrpd[29801]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:34:28 csiph nnrpd[29802]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:34:58 csiph nnrpd[29815]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:35:28 csiph nnrpd[29839]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:35:59 csiph nnrpd[29840]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:36:30 csiph nnrpd[29866]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:37:00 csiph nnrpd[29867]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:37:30 csiph nnrpd[29893]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:38:00 csiph nnrpd[29894]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:38:30 csiph nnrpd[29920]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:39:01 csiph nnrpd[29921]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:39:31 csiph nnrpd[29947]: snorky.mixmin.net noperm ihave without permission
Nov 15 04:40:01 csiph nnrpd[29959]: snorky.mixmin.net noperm ihave without permission

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	51717	41.4%	7.5 MB	52.2%
nnrpd	46551	37.2%	4.1 MB	29.0%
innd	24889	19.9%	2.4 MB	17.0%
innfeed	1844	1.5%	272.3 KB	1.9%
TOTAL: 4	125001	100.0%	14.3 MB	100.0%

History cache:

Reason	Count	%Count
Negative hits	243086	45.4%
Positive hits	241137	45.0%
Do not exist	50918	9.5%
Cache misses	226	0.0%
TOTAL: 4	535367	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.684	0.0%	233	0.000	2.936	40.000
article cleanup	00:00:00.318	0.0%	46145	0.000	0.007	0.020
article logging	00:00:00.595	0.0%	46684	0.000	0.013	0.047
article parse	00:00:13.709	0.0%	1126596	0.004	0.012	0.121
article write	00:01:08.376	0.1%	25197	0.140	2.714	9.276
artlog/artcncl	00:00:00.001	0.0%	156	0.000	0.006	0.500
artlog/artparse	00:00:00.103	0.0%	4896	0.000	0.021	7.000
data move	00:00:00.915	0.0%	1579347	0.000	0.001	0.002
hisgrep/artcncl	00:00:00.070	0.0%	231	0.000	0.303	22.000
hishave/artcncl	00:00:00.000	0.0%	233	0.000	0.000	0.000
hishave/artparse	00:00:00.020	0.0%	4896	0.000	0.004	0.250
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:03.522	0.0%	531769	0.001	0.007	0.036
history sync	00:00:01.647	0.0%	344	0.000	4.788	51.500
history write	00:00:51.799	0.1%	46144	0.048	1.123	7.386
hiswrite/artcncl	00:00:00.000	0.0%	2	0.000	0.000	0.000
hiswrite/artparse	00:00:04.838	0.0%	4891	0.000	0.989	17.611
idle	23:54:33.655	99.6%	1544366	10.623	55.734	279.374
nntp read	00:00:05.454	0.0%	1542011	0.002	0.004	0.006
overview write	00:01:08.776	0.1%	25197	0.385	2.730	11.830
perl filter	00:01:28.881	0.1%	46144	0.925	1.926	3.644
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.463	0.0%	50394	0.000	0.009	0.029
TOTAL: 24:00:43.796	23:59:43.826	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.082	0.0%	25173	0.000	0.003	0.021
article prepare	00:00:00.002	0.0%	5324	0.000	0.000	0.031
article read	00:00:00.217	0.0%	1060	0.000	0.205	33.500
backlog stats	00:00:00.096	0.0%	282226	0.000	0.000	0.002
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:01.208	0.0%	217356	0.000	0.006	0.012
data write	00:00:01.498	0.0%	194361	0.003	0.008	0.014
idle	23:54:32.828	100.0%	282226	148.934	304.978	817.581
status file	00:00:00.090	0.0%	186	0.000	0.484	1.000
TOTAL: 23:54:40.072	23:54:36.021	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:00.418	0.0%	5106	0.016	0.082	0.452
idle	35:26:13.010	99.6%	45158	0.000	2825.037	600094.333
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.616	0.0%	91279	0.000	0.007	0.500
readart	00:00:00.068	0.0%	71	0.000	0.958	21.000
TOTAL: 35:35:09.525	35:26:14.112	99.6%	-	-	-	-

Control commands to INND:

Command	Number
L	1
flush	4
flushlogs	2
go	2
logmode	2
mode	146
pause	2
paused	2
reload	2
reserve	2
TOTAL: 10	165

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	feeder.eternal-september.org	4	43261	6428	33995	2838	14%	24:39:53
2	news-out.mixmin.net	4	34034	4752	23758	5524	13%	24:17:56
3	au2pb.net	1	26871	4712	21367	792	17%	23:43:50
4	newsfeeds.xmission.com	1	25875	3580	22137	158	13%	24:50:29
5	xanadu-bbs.net	6	50167	1964	39086	9117	3%	26:48:17
6	newsfeed.neva.ru	143	48832	1959	40140	6733	4%	72:07:04
7	newsfeed.fu-berlin.de	31	28807	1319	27109	379	4%	26:14:22
8	nntp.pasdenom.info	3	25195	209	24897	89	0%	24:08:36
9	news.swapon.de	1	1990	189	1776	25	9%	18:20:13
10	localhost	26	0	0	0	0	0%	00:00:01
TOTAL: 10		220	285032	25112	234265	25655	8%	265:10:41

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	feeder.eternal-september.org	17.0 MB	3.1 KB	36.1 MB	53.1 MB	32%	5.9 KB
2	news-out.mixmin.net	16.6 MB	0.0 KB	10.0 MB	26.5 MB	62%	2.6 KB
3	au2pb.net	11.8 MB	0.0 KB	5.5 MB	17.3 MB	68%	3.2 KB
4	newsfeeds.xmission.com	9.9 MB	0.0 KB	1.6 MB	11.5 MB	86%	3.2 KB
5	newsfeed.neva.ru	6.7 MB	0.0 KB	60.6 MB	67.3 MB	9%	7.9 KB
6	xanadu-bbs.net	5.1 MB	0.0 KB	1.6 GB	1.6 GB	0%	152.5 KB
7	newsfeed.fu-berlin.de	3.0 MB	0.0 KB	868.6 KB	3.9 MB	78%	2.3 KB
8	news.swapon.de	524.7 KB	0.0 KB	71.0 KB	595.7 KB	88%	2.8 KB
9	nntp.pasdenom.info	492.5 KB	0.0 KB	1.5 MB	2.0 MB	24%	6.8 KB
10	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 10		71.2 MB	3.1 KB	1.7 GB	1.8 GB	3%	37.0 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Nov 15 04:15:00 - 04:59:59	332	1.3%	0.12	990.2 KB	1.4%	0.37
Nov 15 05:00:00 - 05:59:59	531	2.1%	0.15	1.6 MB	2.3%	0.46
Nov 15 06:00:00 - 06:59:59	539	2.1%	0.15	1.5 MB	2.1%	0.44
Nov 15 07:00:00 - 07:59:59	648	2.6%	0.18	1.6 MB	2.2%	0.45
Nov 15 08:00:00 - 08:59:59	849	3.4%	0.24	2.1 MB	3.0%	0.60
Nov 15 09:00:00 - 09:59:59	1032	4.1%	0.29	2.3 MB	3.2%	0.65
Nov 15 10:00:00 - 10:59:59	1028	4.1%	0.29	2.4 MB	3.4%	0.69
Nov 15 11:00:00 - 11:59:59	1772	7.0%	0.49	7.6 MB	10.6%	2.15
Nov 15 12:00:00 - 12:59:59	1575	6.3%	0.44	5.6 MB	7.8%	1.58
Nov 15 13:00:00 - 13:59:59	1432	5.7%	0.40	4.1 MB	5.7%	1.16
Nov 15 14:00:00 - 14:59:59	1268	5.0%	0.35	3.5 MB	5.0%	1.01
Nov 15 15:00:00 - 15:59:59	1202	4.8%	0.33	3.1 MB	4.4%	0.89
Nov 15 16:00:00 - 16:59:59	1317	5.2%	0.37	3.5 MB	4.9%	0.99
Nov 15 17:00:00 - 17:59:59	1327	5.3%	0.37	3.4 MB	4.8%	0.97
Nov 15 18:00:00 - 18:59:59	1337	5.3%	0.37	3.4 MB	4.7%	0.96
Nov 15 19:00:00 - 19:59:59	1394	5.5%	0.39	3.6 MB	5.0%	1.01
Nov 15 20:00:00 - 20:59:59	1384	5.5%	0.38	3.3 MB	4.6%	0.94
Nov 15 21:00:00 - 21:59:59	1386	5.5%	0.39	3.6 MB	5.1%	1.03
Nov 15 22:00:00 - 22:59:59	1128	4.5%	0.31	3.1 MB	4.3%	0.87
Nov 15 23:00:00 - 23:59:59	1030	4.1%	0.29	2.9 MB	4.0%	0.81
Nov 16 00:00:00 - 00:59:59	740	2.9%	0.21	2.1 MB	2.9%	0.60
Nov 16 01:00:00 - 01:59:59	690	2.7%	0.19	2.0 MB	2.8%	0.57
Nov 16 02:00:00 - 02:59:59	537	2.1%	0.15	1.9 MB	2.6%	0.53
Nov 16 03:00:00 - 03:59:59	528	2.1%	0.15	1.9 MB	2.6%	0.54
Nov 16 04:00:00 - 04:15:00	186	0.7%	0.21	498.7 KB	0.7%	0.55
TOTAL: 24:00:00	25192	100.0%	0.29	71.4 MB	100.0%	0.85

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	xanadu-bbs.net	9277	352	0	8925
2	newsfeed.neva.ru	6697	827	0	5870
3	news-out.mixmin.net	5571	13	0	5558
4	feeder.eternal-september.org	2865	256	1	2608
5	newsfeed.fu-berlin.de	835	52	0	783
6	au2pb.net	826	753	0	73
7	newsfeeds.xmission.com	161	140	0	21
8	nntp.pasdenom.info	82	58	0	24
9	news.swapon.de	55	0	0	55
TOTAL: 9		26369	2451	1	23917

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	211
lada.talk	168
mailing.freebsd.ports-bugs	92
mailing.freebsd.pkg-fallout	92
ut.test	91
alt.politics.scorched-earth	91
mailing.freebsd.current	75
mailing.freebsd.svn-ports-all	73
mailing.freebsd.svn-src-all	68
fa.freebsd.cvs-all	68
mailing.freebsd.svn-ports-head	65
fa.freebsd.current	64
pld.cvs.commit	62
alt.politics	62
alt.survival	58
mailing.openbsd.source-changes	52
mailing.freebsd.svn-src-head	42
fa.openbsd.source-changes	35
mailing.freebsd.testing	33
mpc.lists.freebsd.ports.bugs	29
TOTAL: 212	2451

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	12627
EMP (phn path)	4068
EMP (phl)	1128
PFM bot misc	174
Binary: misplaced rar	162
EMP (phn nph)	144
Too many newsgroups	47
Too many newsgroups (low_xpost)	41
HTML Multipart	27
HTML post	19
Binary: misplaced par2	15
Binary: misplaced rev	10
HTML Image Tags	9
Binary Payload	5
User-issued spam cancel	5
TOTAL: 15	18481

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	xanadu-bbs.net	4630
	feeder.eternal-september.org	175
	au2pb.net	42
	news-out.mixmin.net	23
	nntp.pasdenom.info	15
	newsfeeds.xmission.com	12
	TOTAL: 6	4897
Including strange strings
	newsfeed.fu-berlin.de	415
	feeder.eternal-september.org	46
	news.swapon.de	25
	news-out.mixmin.net	25
	au2pb.net	14
	newsfeeds.xmission.com	7
	newsfeed.neva.ru	5
	xanadu-bbs.net	2
	TOTAL: 8	539
TOTAL: 2		5436

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	au2pb	21423	187	20091	154	0	0%	23:59:57
2	usenet.pasdenom.info	29593	145	24247	592	3	0%	23:59:57
3	xanadu-bbs	26191	93	23018	63	12	0%	23:59:57
4	fu-berlin.de	23434	24	23396	14	0	0%	23:59:57
5	xmission	27338	10	21362	0	0	0%	23:59:56
6	news.mixmin.net	21149	8	20339	0	0	0%	23:59:57
7	eternal-september	18802	4	17971	2	0	0%	23:59:54
8	neva.ru	23838	4	23091	27	0	0%	23:59:47
9	news.swapon.de	2312	2	2281	4	0	0%	23:50:31
TOTAL: 9		194080	477	175796	856	15	0%	215:49:53

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	au2pb	751.5 KB	326.0 KB	1.1 MB	3.2 KB	23:59:57
2	usenet.pasdenom.info	566.4 KB	1.1 MB	1.7 MB	2.3 KB	23:59:57
3	xanadu-bbs	468.9 KB	122.7 KB	591.5 KB	3.8 KB	23:59:57
4	fu-berlin.de	117.6 KB	16.2 KB	133.7 KB	3.5 KB	23:59:57
5	xmission	66.3 KB	0.0 KB	66.3 KB	6.6 KB	23:59:56
6	news.mixmin.net	35.3 KB	0.0 KB	35.3 KB	4.4 KB	23:59:57
7	neva.ru	26.6 KB	87.8 KB	114.5 KB	3.7 KB	23:59:47
8	eternal-september	18.0 KB	1.9 KB	19.9 KB	3.3 KB	23:59:54
9	news.swapon.de	3.5 KB	6.4 KB	9.9 KB	1.6 KB	23:50:31
TOTAL: 9		2.0 MB	1.7 MB	3.7 MB	2.8 KB	215:49:53

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Elapsed
1	202.89.176.220	288	68	157.4 KB	63	04:08:20
2	tempe0.bbox.io	54	3	5.0 KB	1	08:20:13
TOTAL: 2		342	71	162.4 KB	64	35:34:41

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	unresolved	367	68	157.4 KB	63	22:18:07
2	*.bbox.io	54	3	5.0 KB	1	08:20:13
3	*.151.22.98.dynamic.ip.windstream.net	1	0	0.0 KB	0	00:30:16
4	*.tampfl.dsl-w.verizon.net	10	0	0.0 KB	0	01:56:39
5	*.mixmin.net	2843	0	0.0 KB	0	00:27:30
6	*.chello.nl	15	0	0.0 KB	0	02:01:52
TOTAL: 6		3290	71	162.4 KB	64	35:34:41

NNRP auth users [Top 20]:

User	Conn
moussa	288
TOTAL: 1	288

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
63.142.120.8	3.572	1.332	0.000	11:29:35
tempe0.bbox.io	4.329	0.805	0.000	08:20:13
162.212.88.214	0.303	0.158	0.000	06:40:08
202.89.176.220	28.236	6.191	0.733	04:08:20
dhcp-089-099-203-254.chello.nl	1.187	0.258	0.000	02:01:52
pool-71-98-160-84.tampfl.dsl-w.verizon.net	0.888	0.136	0.000	01:56:39
h110.151.22.98.dynamic.ip.windstream.net	0.100	0.015	0.000	00:30:16
snorky.mixmin.net	238.604	46.001	0.000	00:27:30
69.160.37.54	2.029	0.410	0.000	00:00:02
TOTAL: 9	279.248	55.306	0.733	35:34:41

Curious NNRP server explorers [Top 20]:

System	Conn
snorky.mixmin.net	2843
63.142.120.8	50
69.160.37.54	25
dhcp-089-099-203-254.chello.nl	15
pool-71-98-160-84.tampfl.dsl-w.verizon.net	10
162.212.88.214	4
h110.151.22.98.dynamic.ip.windstream.net	1
TOTAL: 7	2948

NNRP client timeouts [Top 20]:

System	Conn	Peer
tempe0.bbox.io	13	0
pool-71-98-160-84.tampfl.dsl-w.verizon.net	3	0
h110.151.22.98.dynamic.ip.windstream.net	1	0
TOTAL: 3	17	0

Newsgroup request counts (by category):

Category		Count	Pct
1	comp	68	95.8%
2	news	3	4.2%
TOTAL: 2		71	100.0%

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

Newsgroup		Count
1	comp.arch	24
2	comp.sys.ibm.pc.games.action	17
3	comp.sys.ibm.pc.games.war-historical	9
4	comp.ai.neural-nets	5
5	comp.os.os2.announce	4
6	comp.arch.embedded	3
7	news.admin.peering	3
8	comp.unix.aix	3
9	comp.os.os2.ecomstation	1
10	comp.sys.ibm.as400.misc	1
11	comp.os.os2.advocacy	1
TOTAL: 11		71

Daily Usenet report for csiph.com

Nov 15 04:15:00 -- Nov 16 04:15:00