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

Unknown entries from news log file:

First 50 / 2825 lines (1.8%)

Nov 11 04:15:22 csiph nnrpd[61428]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:15:54 csiph nnrpd[61441]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:16:24 csiph nnrpd[61455]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:16:54 csiph nnrpd[61456]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:17:25 csiph nnrpd[61482]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:17:55 csiph nnrpd[61483]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:18:25 csiph nnrpd[61509]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:18:55 csiph nnrpd[61515]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:19:25 csiph nnrpd[61541]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:19:55 csiph nnrpd[61568]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:20:26 csiph nnrpd[61615]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:20:57 csiph nnrpd[61616]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:21:28 csiph nnrpd[61642]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:21:59 csiph nnrpd[61643]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:22:30 csiph nnrpd[61689]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:23:01 csiph nnrpd[61691]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:23:31 csiph nnrpd[61701]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:24:02 csiph nnrpd[61730]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:24:32 csiph nnrpd[61731]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:25:03 csiph nnrpd[61769]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:25:33 csiph nnrpd[61774]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:26:03 csiph nnrpd[61800]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:26:34 csiph nnrpd[61801]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:27:04 csiph nnrpd[61827]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:27:35 csiph nnrpd[61828]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:28:07 csiph nnrpd[61854]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:28:38 csiph nnrpd[61855]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:29:09 csiph nnrpd[61881]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:29:40 csiph nnrpd[61882]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:30:10 csiph nnrpd[61918]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:30:40 csiph nnrpd[62054]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:31:11 csiph nnrpd[62066]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:31:41 csiph nnrpd[62087]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:32:12 csiph nnrpd[62088]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:32:43 csiph nnrpd[62117]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:33:14 csiph nnrpd[62139]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:33:45 csiph nnrpd[62165]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:34:16 csiph nnrpd[62166]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:34:46 csiph nnrpd[62192]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:35:16 csiph nnrpd[62203]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:35:47 csiph nnrpd[62229]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:36:18 csiph nnrpd[62230]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:36:48 csiph nnrpd[62256]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:37:19 csiph nnrpd[62257]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:37:50 csiph nnrpd[62283]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:38:21 csiph nnrpd[62284]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:38:52 csiph nnrpd[62296]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:39:22 csiph nnrpd[62311]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:39:53 csiph nnrpd[62312]: snorky.mixmin.net noperm ihave without permission
Nov 11 04:40:24 csiph nnrpd[62486]: snorky.mixmin.net noperm ihave without permission

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	55783	42.9%	8.0 MB	54.0%
nnrpd	46466	35.8%	4.1 MB	27.7%
innd	25732	19.8%	2.4 MB	16.4%
innfeed	1921	1.5%	281.0 KB	1.8%
controlchan	1	0.0%	0.1 KB	0.0%
TOTAL: 5	129903	100.0%	14.9 MB	100.0%

History cache:

Reason	Count	%Count
Negative hits	264207	45.4%
Positive hits	262309	45.0%
Do not exist	54858	9.4%
Cache misses	1059	0.2%
TOTAL: 4	582433	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.743	0.0%	169	0.000	4.396	37.833
article cleanup	00:00:00.385	0.0%	50370	0.000	0.008	0.021
article logging	00:00:00.748	0.0%	50931	0.000	0.015	0.073
article parse	00:00:14.947	0.0%	1017454	0.004	0.015	0.077
article write	00:01:16.399	0.1%	28204	0.182	2.709	6.788
artlog/artcncl	00:00:00.003	0.0%	147	0.000	0.020	0.125
artlog/artparse	00:00:00.060	0.0%	4869	0.000	0.012	0.333
data move	00:00:00.896	0.0%	1470523	0.000	0.001	0.002
hisgrep/artcncl	00:00:00.039	0.0%	169	0.000	0.231	3.143
hishave/artcncl	00:00:00.002	0.0%	169	0.000	0.012	0.250
hishave/artparse	00:00:00.018	0.0%	4869	0.000	0.004	0.167
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:04.432	0.0%	579339	0.001	0.008	0.083
history sync	00:00:02.336	0.0%	340	0.000	6.871	79.000
history write	00:01:03.410	0.1%	50365	0.108	1.259	12.088
hiswrite/artcncl	00:00:00.000	0.0%	0	0.000	0.000	0.000
hiswrite/artparse	00:00:06.631	0.0%	4868	0.000	1.362	19.125
idle	23:53:48.891	99.5%	1449871	10.391	59.336	415.671
nntp read	00:00:04.979	0.0%	1448999	0.001	0.003	0.008
overview write	00:01:23.049	0.1%	28204	0.510	2.945	14.184
perl filter	00:01:43.134	0.1%	50365	1.077	2.048	4.092
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.517	0.0%	56408	0.000	0.009	0.028
TOTAL: 24:00:46.991	23:59:51.619	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.082	0.0%	30405	0.000	0.003	0.031
article prepare	00:00:00.000	0.0%	5844	0.000	0.000	0.000
article read	00:00:00.199	0.0%	1241	0.000	0.160	15.333
backlog stats	00:00:00.122	0.0%	302947	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.282	0.0%	236686	0.001	0.005	0.011
data write	00:00:01.566	0.0%	213115	0.001	0.007	0.014
idle	23:54:28.741	100.0%	302947	173.139	284.105	843.259
status file	00:00:00.086	0.0%	214	0.000	0.402	1.000
TOTAL: 23:54:38.412	23:54:32.078	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:00.376	0.0%	12123	0.000	0.031	0.143
idle	55:52:39.745	99.7%	52126	0.000	3859.106	600101.667
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.683	0.0%	105229	0.000	0.006	0.333
readart	00:00:00.117	0.0%	80	0.000	1.462	62.000
TOTAL: 56:02:52.679	55:52:40.921	99.7%	-	-	-	-

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	1	46682	8008	35294	3380	17%	23:50:27
2	news-out.mixmin.net	2	34275	5761	24800	3714	16%	24:08:44
3	au2pb.net	1	30565	4247	25394	924	13%	23:33:07
4	newsfeeds.xmission.com	1	28122	3055	24889	178	10%	22:37:45
5	xanadu-bbs.net	48	62260	2657	46466	13137	4%	81:27:28
6	newsfeed.neva.ru	151	54944	2461	43509	8974	4%	71:44:48
7	newsfeed.fu-berlin.de	52	30349	1375	28662	312	4%	30:21:37
8	news.swapon.de	4	2407	207	2185	15	8%	24:30:52
9	nntp.pasdenom.info	8	28798	198	28527	73	0%	24:17:08
10	localhost	26	0	0	0	0	0%	00:00:00
TOTAL: 10		294	318402	27969	259726	30707	8%	326:31:56

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	feeder.eternal-september.org	21.2 MB	14.3 KB	26.1 MB	47.3 MB	44%	4.3 KB
2	news-out.mixmin.net	18.0 MB	0.0 KB	7.5 MB	25.4 MB	70%	2.7 KB
3	au2pb.net	12.0 MB	10.2 KB	7.2 MB	19.2 MB	62%	3.8 KB
4	newsfeeds.xmission.com	8.4 MB	0.0 KB	3.3 MB	11.8 MB	71%	3.7 KB
5	xanadu-bbs.net	7.4 MB	11.8 KB	2.4 GB	2.4 GB	0%	158.8 KB
6	newsfeed.neva.ru	7.3 MB	12.6 KB	86.1 MB	93.4 MB	7%	8.4 KB
7	newsfeed.fu-berlin.de	3.1 MB	0.0 KB	1.2 MB	4.3 MB	71%	2.6 KB
8	news.swapon.de	506.5 KB	0.0 KB	422.1 KB	928.6 KB	54%	4.2 KB
9	nntp.pasdenom.info	447.2 KB	0.0 KB	801.2 KB	1.2 MB	35%	4.6 KB
10	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 10		78.4 MB	48.9 KB	2.5 GB	2.6 GB	2%	46.3 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Nov 11 04:15:00 - 04:59:59	405	1.4%	0.15	1.2 MB	1.5%	0.44
Nov 11 05:00:00 - 05:59:59	593	2.1%	0.16	1.9 MB	2.4%	0.54
Nov 11 06:00:00 - 06:59:59	593	2.1%	0.16	1.8 MB	2.2%	0.50
Nov 11 07:00:00 - 07:59:59	798	2.8%	0.22	2.3 MB	2.9%	0.66
Nov 11 08:00:00 - 08:59:59	1333	4.7%	0.37	3.8 MB	4.9%	1.09
Nov 11 09:00:00 - 09:59:59	1411	5.0%	0.39	4.4 MB	5.6%	1.26
Nov 11 10:00:00 - 10:59:59	1443	5.1%	0.40	4.0 MB	5.1%	1.14
Nov 11 11:00:00 - 11:59:59	1261	4.5%	0.35	3.3 MB	4.1%	0.93
Nov 11 12:00:00 - 12:59:59	1421	5.0%	0.39	3.9 MB	4.9%	1.10
Nov 11 13:00:00 - 13:59:59	1549	5.5%	0.43	4.4 MB	5.6%	1.26
Nov 11 14:00:00 - 14:59:59	1547	5.5%	0.43	3.8 MB	4.8%	1.08
Nov 11 15:00:00 - 15:59:59	1515	5.4%	0.42	3.8 MB	4.8%	1.08
Nov 11 16:00:00 - 16:59:59	1809	6.4%	0.50	5.1 MB	6.4%	1.45
Nov 11 17:00:00 - 17:59:59	1515	5.4%	0.42	3.8 MB	4.8%	1.09
Nov 11 18:00:00 - 18:59:59	1585	5.6%	0.44	4.7 MB	5.9%	1.33
Nov 11 19:00:00 - 19:59:59	1690	6.0%	0.47	4.5 MB	5.7%	1.28
Nov 11 20:00:00 - 20:59:59	1554	5.5%	0.43	4.4 MB	5.6%	1.26
Nov 11 21:00:00 - 21:59:59	1360	4.8%	0.38	3.6 MB	4.6%	1.04
Nov 11 22:00:00 - 22:59:59	1213	4.3%	0.34	3.5 MB	4.5%	1.00
Nov 11 23:00:00 - 23:59:59	1056	3.7%	0.29	3.1 MB	3.9%	0.89
Nov 12 00:00:00 - 00:59:59	757	2.7%	0.21	2.2 MB	2.8%	0.62
Nov 12 01:00:00 - 01:59:59	552	2.0%	0.15	1.6 MB	2.1%	0.47
Nov 12 02:00:00 - 02:59:59	573	2.0%	0.16	1.9 MB	2.4%	0.53
Nov 12 03:00:00 - 03:59:59	536	1.9%	0.15	1.6 MB	2.1%	0.46
Nov 12 04:00:00 - 04:15:00	125	0.4%	0.14	340.3 KB	0.4%	0.38
TOTAL: 24:00:00	28194	100.0%	0.33	79.0 MB	100.0%	0.94

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	xanadu-bbs.net	9235	430	1	8804
2	newsfeed.neva.ru	9013	1353	1	7659
3	news-out.mixmin.net	3744	33	0	3711
4	feeder.eternal-september.org	3454	374	2	3078
5	au2pb.net	913	846	1	66
6	newsfeed.fu-berlin.de	763	31	0	732
7	newsfeeds.xmission.com	206	162	0	44
8	nntp.pasdenom.info	76	51	0	25
9	news.swapon.de	39	0	0	39
TOTAL: 9		27443	3280	5	24158

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	617
alt.politics.scorched-earth	159
ut.test	127
lada.talk	111
mailing.freebsd.svn-ports-all	99
mailing.freebsd.svn-ports-head	95
mailing.freebsd.ports-bugs	93
pld.cvs.commit	71
alt.windows7.general	60
gmane.linux.alsa.devel	58
mailing.gcc.gcc-cvs	58
mailing.freebsd.current	57
it-alt.sport.calcio.juventus	57
alt.politics	55
fa.freebsd.current	53
mailing.freebsd.pkg-fallout	48
lada.auto	44
mailing.freebsd.security	43
mailing.openbsd.source-changes	42
alt.survival	40
TOTAL: 268	3280

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	14118
EMP (phn path)	3058
EMP (phl)	875
EMP (phn nph)	278
PFM bot misc	231
Binary: misplaced rar	131
HTML Multipart	81
Too many newsgroups	56
Binary Image: misplaced jpg	24
HTML post	21
HTML Image Tags	12
Binary: misplaced rev	10
Too many newsgroups (low_xpost)	9
User-issued spam cancel	7
Too many newsgroups (meow)	2
Binary Payload	1
TOTAL: 16	18914

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	xanadu-bbs.net	4480
	feeder.eternal-september.org	93
	au2pb.net	42
	newsfeeds.xmission.com	30
	news-out.mixmin.net	19
	nntp.pasdenom.info	8
	newsfeed.fu-berlin.de	6
	news.swapon.de	4
	TOTAL: 8	4682
Including strange strings
	newsfeed.fu-berlin.de	445
	feeder.eternal-september.org	40
	news-out.mixmin.net	27
	news.swapon.de	24
	newsfeeds.xmission.com	12
	newsfeed.neva.ru	5
	xanadu-bbs.net	5
	au2pb.net	3
	nntp.pasdenom.info	1
	TOTAL: 9	562
TOTAL: 2		5244

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	au2pb	25417	220	23473	225	0	0%	23:59:55
2	usenet.pasdenom.info	32042	133	27246	618	47	0%	23:59:55
3	xanadu-bbs	28235	80	25399	71	2202	0%	23:59:55
4	fu-berlin.de	26397	24	26357	16	0	0%	23:59:54
5	xmission	30310	12	24767	4	0	0%	23:59:55
6	news.mixmin.net	23135	9	22309	0	0	0%	23:59:44
7	neva.ru	26581	5	25550	35	0	0%	23:59:55
8	eternal-september	20381	2	19431	1	0	0%	23:59:55
9	news.swapon.de	2417	1	2390	6	0	0%	23:58:11
TOTAL: 9		214915	486	196922	976	2249	0%	215:57:19

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	au2pb	1017.1 KB	495.7 KB	1.5 MB	3.4 KB	23:59:55
2	usenet.pasdenom.info	518.3 KB	1.4 MB	1.9 MB	2.6 KB	23:59:55
3	xanadu-bbs	392.3 KB	152.1 KB	544.4 KB	3.6 KB	23:59:55
4	fu-berlin.de	107.3 KB	20.7 KB	128.0 KB	3.2 KB	23:59:54
5	news.mixmin.net	58.1 KB	0.0 KB	58.1 KB	6.5 KB	23:59:44
6	xmission	33.0 KB	18.8 KB	51.8 KB	3.2 KB	23:59:55
7	neva.ru	25.2 KB	181.2 KB	206.5 KB	5.2 KB	23:59:55
8	eternal-september	3.9 KB	1.9 KB	5.8 KB	1.9 KB	23:59:55
9	news.swapon.de	1.5 KB	11.2 KB	12.7 KB	1.8 KB	23:58:11
TOTAL: 9		2.1 MB	2.3 MB	4.4 MB	3.1 KB	215:57:19

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Elapsed
1	202.89.176.220	288	70	208.2 KB	68	04:31:19
2	challenger.nielsenmedia.com	25	7	19.7 KB	6	04:45:40
3	pool-71-98-160-84.tampfl.dsl-w.verizon.net	15	3	8.9 KB	2	01:39:31
TOTAL: 3		328	80	236.8 KB	76	56:02:24

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	unresolved	375	70	208.2 KB	68	43:36:51
2	*.nielsenmedia.com	25	7	19.7 KB	6	04:45:40
3	*.tampfl.dsl-w.verizon.net	15	3	8.9 KB	2	01:39:31
4	*.mixmin.net	2825	0	0.0 KB	0	00:27:09
5	*.chello.nl	17	0	0.0 KB	0	02:32:17
6	*.dsl.klmzmi.sbcglobal.net	1	0	0.0 KB	0	00:00:03
7	*.bbox.io	8	0	0.0 KB	0	02:30:32
8	*.139.22.98.dynamic.ip.windstream.net	2	0	0.0 KB	0	00:30:17
TOTAL: 8		3268	80	236.8 KB	76	56:02:24

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
162.212.88.214	0.856	0.564	0.000	35:56:11
challenger.nielsenmedia.com	2.403	0.388	0.000	04:45:40
202.89.176.220	28.509	6.228	0.717	04:31:19
63.142.120.8	3.902	0.912	0.000	03:09:18
dhcp-089-099-203-254.chello.nl	1.409	0.228	0.000	02:32:17
tempe0.bbox.io	0.690	0.155	0.000	02:30:32
pool-71-98-160-84.tampfl.dsl-w.verizon.net	1.308	0.256	0.000	01:39:31
h10.139.22.98.dynamic.ip.windstream.net	0.090	0.025	0.000	00:30:17
snorky.mixmin.net	235.748	44.834	0.000	00:27:09
adsl-76-235-161-18.dsl.klmzmi.sbcglobal.net	0.097	0.008	0.000	00:00:03
69.160.37.54	2.064	0.375	0.000	00:00:02
TOTAL: 11	277.076	53.973	0.717	56:02:24

Curious NNRP server explorers [Top 20]:

System	Conn
snorky.mixmin.net	2825
63.142.120.8	54
69.160.37.54	25
dhcp-089-099-203-254.chello.nl	17
tempe0.bbox.io	8
162.212.88.214	8
h10.139.22.98.dynamic.ip.windstream.net	2
adsl-76-235-161-18.dsl.klmzmi.sbcglobal.net	1
TOTAL: 8	2940

NNRP client timeouts [Top 20]:

System	Conn	Peer
challenger.nielsenmedia.com	8	0
tempe0.bbox.io	5	0
162.212.88.214	4	4
pool-71-98-160-84.tampfl.dsl-w.verizon.net	2	0
h10.139.22.98.dynamic.ip.windstream.net	1	0
TOTAL: 5	20	4

Newsgroup request counts (by category):

Category		Count	Pct
1	comp	80	100.0%
TOTAL: 1		80	100.0%

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

Newsgroup		Count
1	comp.os.vms	17
2	comp.arch	17
3	comp.sys.ibm.pc.games.war-historical	13
4	comp.lang.awk	10
5	comp.arch.embedded	7
6	comp.sys.ibm.pc.games.rpg	6
7	comp.sys.ibm.pc.games.action	4
8	comp.os.os2.apps	1
9	comp.ai.alife	1
10	comp.os.qnx	1
11	comp.ai.genetic	1
12	comp.ai.neural-nets	1
13	comp.sys.hp.hardware	1
TOTAL: 13		80

Daily Usenet report for csiph.com

Nov 11 04:15:00 -- Nov 12 04:15:00