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

Unknown entries from news log file:

First 50 / 2827 lines (1.8%)

Nov 18 04:15:13 csiph nnrpd[38972]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:15:43 csiph nnrpd[38980]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:16:15 csiph nnrpd[39012]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:16:45 csiph nnrpd[39022]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:17:15 csiph nnrpd[39054]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:17:45 csiph nnrpd[39061]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:18:16 csiph nnrpd[39096]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:18:47 csiph nnrpd[39103]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:19:18 csiph nnrpd[39140]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:19:48 csiph nnrpd[39149]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:20:19 csiph nnrpd[39208]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:20:49 csiph nnrpd[39229]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:21:20 csiph nnrpd[39230]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:21:51 csiph nnrpd[39259]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:22:21 csiph nnrpd[39281]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:22:51 csiph nnrpd[39310]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:23:23 csiph nnrpd[39311]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:23:54 csiph nnrpd[39338]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:24:25 csiph nnrpd[39351]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:24:56 csiph nnrpd[39377]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:25:27 csiph nnrpd[39388]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:25:57 csiph nnrpd[39414]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:26:28 csiph nnrpd[39415]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:26:59 csiph nnrpd[39441]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:27:32 csiph nnrpd[39442]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:28:03 csiph nnrpd[39468]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:28:34 csiph nnrpd[39469]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:29:05 csiph nnrpd[39486]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:29:35 csiph nnrpd[39496]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:30:05 csiph nnrpd[39507]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:30:36 csiph nnrpd[39533]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:31:07 csiph nnrpd[39540]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:31:37 csiph nnrpd[39566]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:32:08 csiph nnrpd[39570]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:32:38 csiph nnrpd[39596]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:33:09 csiph nnrpd[39618]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:33:40 csiph nnrpd[39779]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:34:11 csiph nnrpd[39780]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:34:41 csiph nnrpd[39806]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:35:11 csiph nnrpd[39817]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:35:41 csiph nnrpd[39841]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:36:12 csiph nnrpd[39844]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:36:43 csiph nnrpd[39852]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:37:14 csiph nnrpd[39871]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:37:44 csiph nnrpd[39872]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:38:15 csiph nnrpd[39898]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:38:46 csiph nnrpd[39899]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:39:16 csiph nnrpd[39925]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:39:46 csiph nnrpd[39926]: snorky.mixmin.net noperm ihave without permission
Nov 18 04:40:16 csiph nnrpd[39962]: snorky.mixmin.net noperm ihave without permission

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	54107	43.0%	7.8 MB	53.9%
nnrpd	46346	36.8%	4.1 MB	28.4%
innd	23681	18.8%	2.3 MB	15.7%
innfeed	1814	1.4%	299.9 KB	2.0%
TOTAL: 4	125948	100.0%	14.5 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	265275	45.9%
Negative hits	259542	44.9%
Do not exist	53130	9.2%
Cache misses	108	0.0%
TOTAL: 4	578055	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.766	0.0%	200	0.000	3.830	43.000
article cleanup	00:00:00.350	0.0%	49872	0.000	0.007	0.026
article logging	00:00:00.660	0.0%	50356	0.000	0.013	0.037
article parse	00:00:11.108	0.0%	577420	0.004	0.019	0.087
article write	00:01:29.680	0.1%	27290	0.212	3.286	12.407
artlog/artcncl	00:00:00.002	0.0%	160	0.000	0.013	0.500
artlog/artparse	00:00:00.048	0.0%	3720	0.000	0.013	1.000
data move	00:00:00.593	0.0%	1078105	0.000	0.001	0.002
hisgrep/artcncl	00:00:00.059	0.0%	190	0.000	0.311	7.000
hishave/artcncl	00:00:00.000	0.0%	200	0.000	0.000	0.000
hishave/artparse	00:00:00.014	0.0%	3720	0.000	0.004	1.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:05.352	0.0%	578504	0.001	0.009	0.181
history sync	00:00:02.141	0.0%	345	0.000	6.206	54.500
history write	00:01:05.922	0.1%	49857	0.048	1.322	7.276
hiswrite/artcncl	00:00:00.011	0.0%	10	0.000	1.100	4.000
hiswrite/artparse	00:00:06.484	0.0%	3718	0.000	1.744	17.600
idle	23:53:58.913	99.5%	1044914	22.755	82.341	240.406
nntp read	00:00:03.595	0.0%	1042613	0.002	0.003	0.008
overview write	00:01:15.048	0.1%	27290	0.763	2.750	14.247
perl filter	00:01:33.757	0.1%	49857	0.912	1.881	3.524
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.498	0.0%	54580	0.000	0.009	0.028
TOTAL: 24:00:44.930	23:59:55.001	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.085	0.0%	27219	0.000	0.003	0.020
article prepare	00:00:00.002	0.0%	5984	0.000	0.000	0.011
article read	00:00:00.223	0.0%	1226	0.000	0.182	33.500
backlog stats	00:00:00.083	0.0%	297185	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.337	0.0%	231637	0.002	0.006	0.014
data write	00:00:01.602	0.0%	208171	0.001	0.008	0.015
idle	23:54:31.516	100.0%	297185	155.520	289.623	855.154
status file	00:00:00.077	0.0%	172	0.000	0.448	1.000
TOTAL: 23:54:38.821	23:54:34.925	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:01.577	0.0%	21235	0.000	0.074	0.091
idle	84:44:04.772	99.9%	61307	0.000	4975.692	600142.333
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.789	0.0%	123734	0.000	0.006	0.333
readart	00:00:00.443	0.0%	147	0.000	3.014	111.000
TOTAL: 84:50:04.760	84:44:07.581	99.9%	-	-	-	-

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	6	45730	7078	36035	2617	15%	24:27:34
2	au2pb.net	1	30079	5600	23367	1112	18%	23:15:18
3	news-out.mixmin.net	3	35626	4792	26190	4644	13%	24:17:58
4	xanadu-bbs.net	1	53280	3078	39019	11183	5%	23:46:52
5	newsfeeds.xmission.com	1	29184	2689	26409	86	9%	25:35:20
6	newsfeed.neva.ru	142	58373	2421	49855	6097	4%	71:33:05
7	newsfeed.fu-berlin.de	56	31525	1236	29958	331	3%	31:53:42
8	news.swapon.de	1	2446	220	2203	23	8%	22:18:58
9	nntp.pasdenom.info	3	28911	165	28674	72	0%	24:08:35
10	localhost	27	1	1	0	0	100%	00:00:00
TOTAL: 10		241	315155	27280	261710	26165	8%	271:17:22

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	feeder.eternal-september.org	19.3 MB	58.9 KB	19.4 MB	38.7 MB	49%	4.1 KB
2	news-out.mixmin.net	16.3 MB	0.0 KB	10.5 MB	26.7 MB	60%	2.9 KB
3	au2pb.net	15.1 MB	0.0 KB	7.5 MB	22.6 MB	66%	3.5 KB
4	xanadu-bbs.net	8.0 MB	49.5 KB	729.6 MB	737.6 MB	1%	53.0 KB
5	newsfeeds.xmission.com	8.0 MB	22.3 KB	1.4 MB	9.4 MB	84%	3.5 KB
6	newsfeed.neva.ru	7.1 MB	133.6 KB	42.5 MB	49.7 MB	14%	6.0 KB
7	newsfeed.fu-berlin.de	2.9 MB	0.0 KB	1.2 MB	4.0 MB	71%	2.6 KB
8	news.swapon.de	559.2 KB	0.0 KB	65.1 KB	624.4 KB	89%	2.6 KB
9	nntp.pasdenom.info	352.9 KB	0.0 KB	1.3 MB	1.6 MB	21%	7.0 KB
10	localhost	1.5 KB	0.0 KB	0.0 KB	1.5 KB	100%	1.5 KB
TOTAL: 10		77.5 MB	264.3 KB	813.3 MB	891.1 MB	8%	17.1 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Nov 18 04:15:00 - 04:59:59	383	1.4%	0.14	1.3 MB	1.7%	0.51
Nov 18 05:00:00 - 05:59:59	546	2.0%	0.15	1.6 MB	2.0%	0.44
Nov 18 06:00:00 - 06:59:59	624	2.3%	0.17	1.9 MB	2.4%	0.54
Nov 18 07:00:00 - 07:59:59	772	2.8%	0.21	2.1 MB	2.7%	0.59
Nov 18 08:00:00 - 08:59:59	1140	4.2%	0.32	3.1 MB	4.0%	0.89
Nov 18 09:00:00 - 09:59:59	1252	4.6%	0.35	3.7 MB	4.8%	1.06
Nov 18 10:00:00 - 10:59:59	1243	4.6%	0.35	3.0 MB	3.8%	0.85
Nov 18 11:00:00 - 11:59:59	1313	4.8%	0.36	3.7 MB	4.7%	1.05
Nov 18 12:00:00 - 12:59:59	1307	4.8%	0.36	3.3 MB	4.3%	0.95
Nov 18 13:00:00 - 13:59:59	1445	5.3%	0.40	3.9 MB	4.9%	1.10
Nov 18 14:00:00 - 14:59:59	1549	5.7%	0.43	3.9 MB	5.0%	1.11
Nov 18 15:00:00 - 15:59:59	1700	6.2%	0.47	4.4 MB	5.7%	1.26
Nov 18 16:00:00 - 16:59:59	1637	6.0%	0.45	4.7 MB	6.0%	1.33
Nov 18 17:00:00 - 17:59:59	1684	6.2%	0.47	4.6 MB	5.9%	1.31
Nov 18 18:00:00 - 18:59:59	1630	6.0%	0.45	4.7 MB	6.0%	1.33
Nov 18 19:00:00 - 19:59:59	1489	5.5%	0.41	4.4 MB	5.6%	1.24
Nov 18 20:00:00 - 20:59:59	1413	5.2%	0.39	3.7 MB	4.7%	1.04
Nov 18 21:00:00 - 21:59:59	1486	5.5%	0.41	4.9 MB	6.3%	1.40
Nov 18 22:00:00 - 22:59:59	1199	4.4%	0.33	3.2 MB	4.1%	0.91
Nov 18 23:00:00 - 23:59:59	946	3.5%	0.26	2.9 MB	3.7%	0.83
Nov 19 00:00:00 - 00:59:59	687	2.5%	0.19	2.1 MB	2.6%	0.58
Nov 19 01:00:00 - 01:59:59	682	2.5%	0.19	2.4 MB	3.1%	0.69
Nov 19 02:00:00 - 02:59:59	480	1.8%	0.13	1.9 MB	2.4%	0.54
Nov 19 03:00:00 - 03:59:59	504	1.8%	0.14	2.0 MB	2.6%	0.57
Nov 19 04:00:00 - 04:15:00	149	0.5%	0.17	691.1 KB	0.9%	0.77
TOTAL: 24:00:00	27260	100.0%	0.32	77.9 MB	100.0%	0.92

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	xanadu-bbs.net	11132	582	3	10547
2	newsfeed.neva.ru	6104	1786	8	4310
3	news-out.mixmin.net	4666	26	0	4640
4	feeder.eternal-september.org	2659	503	3	2153
5	au2pb.net	1149	1052	0	97
6	newsfeed.fu-berlin.de	764	45	0	719
7	newsfeeds.xmission.com	89	68	1	20
8	nntp.pasdenom.info	71	61	0	10
9	news.swapon.de	53	0	0	53
TOTAL: 9		26687	4123	15	22549

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	973
alt.politics.scorched-earth	328
mailing.freebsd.pkg-fallout	210
lada.talk	195
lada.auto	147
ut.test	142
mailing.freebsd.ports-bugs	97
gmane.linux.alsa.devel	91
fa.linux.680x0	78
mailing.gcc.gcc-cvs	71
mailing.freebsd.svn-ports-all	68
alt.politics	68
mailing.freebsd.svn-ports-head	65
mailing.openbsd.source-changes	53
mozilla.dev.tree-alerts	52
fa.freebsd.cvs-all	48
mailing.freebsd.svn-src-all	48
pld.cvs.commit	45
mailing.database.pgsql-general	43
mailing.openbsd.ports-changes	43
TOTAL: 261	4123

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	13570
EMP (phn path)	3091
EMP (phl)	942
PFM bot misc	226
EMP (phn nph)	191
Too many newsgroups	131
HTML Multipart	100
HTML post	61
Binary Image: misplaced jpg	37
HTML Image Tags	5
Binary: misplaced nfo	1
User-issued spam cancel	1
Binary: misplaced m3u	1
Binary Payload	1
Binary: misplaced sfv	1
U2 violation - invalid distribution	1
TOTAL: 16	18360

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	xanadu-bbs.net	3526
	feeder.eternal-september.org	82
	au2pb.net	52
	news-out.mixmin.net	21
	newsfeeds.xmission.com	13
	nntp.pasdenom.info	8
	newsfeed.fu-berlin.de	4
	TOTAL: 7	3706
Including strange strings
	newsfeed.fu-berlin.de	371
	feeder.eternal-september.org	34
	news-out.mixmin.net	31
	news.swapon.de	27
	au2pb.net	9
	xanadu-bbs.net	5
	newsfeeds.xmission.com	4
	newsfeed.neva.ru	2
	TOTAL: 8	483
TOTAL: 2		4189

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	au2pb	22324	213	21140	199	0	0%	23:59:57
2	usenet.pasdenom.info	31658	152	26253	691	3	0%	23:59:57
3	xanadu-bbs	26717	84	24055	48	0	0%	23:59:54
4	fu-berlin.de	25531	20	25497	14	0	0%	23:59:57
5	xmission	30745	16	24416	0	0	0%	23:59:57
6	news.mixmin.net	23192	5	22371	0	0	0%	23:59:57
7	neva.ru	25440	3	24654	40	0	0%	23:59:57
8	eternal-september	20389	2	19414	2	0	0%	23:59:57
9	news.swapon.de	2261	1	2220	6	0	0%	23:59:57
TOTAL: 9		208257	496	190020	1000	3	0%	215:59:30

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	au2pb	969.1 KB	500.3 KB	1.4 MB	3.6 KB	23:59:57
2	usenet.pasdenom.info	569.2 KB	1.5 MB	2.0 MB	2.4 KB	23:59:57
3	xanadu-bbs	490.7 KB	92.4 KB	583.1 KB	4.4 KB	23:59:54
4	fu-berlin.de	87.6 KB	19.4 KB	107.0 KB	3.1 KB	23:59:57
5	xmission	41.0 KB	0.0 KB	41.0 KB	2.6 KB	23:59:57
6	neva.ru	24.2 KB	222.4 KB	246.6 KB	5.7 KB	23:59:57
7	eternal-september	16.3 KB	3.1 KB	19.4 KB	4.8 KB	23:59:57
8	news.mixmin.net	9.0 KB	0.0 KB	9.0 KB	1.8 KB	23:59:57
9	news.swapon.de	3.5 KB	15.0 KB	18.5 KB	2.6 KB	23:59:57
TOTAL: 9		2.2 MB	2.3 MB	4.4 MB	3.0 KB	215:59:30

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	202.89.176.220	288	86	220.6 KB	79	0	0	04:12:19
2	challenger.nielsenmedia.com	47	45	107.7 KB	17	0	0	07:59:16
3	tempe0.bbox.io	17	7	26.3 KB	3	1	1	03:24:35
4	pool-71-98-160-84.tampfl.dsl-w.verizon.net	8	7	12.3 KB	3	0	0	02:07:30
5	dhcp-089-099-203-254.chello.nl	7	2	2.7 KB	2	0	0	01:43:05
TOTAL: 5		367	147	369.5 KB	104	1	1	84:49:37

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	unresolved	323	86	220.6 KB	79	0	0	68:07:22
2	*.nielsenmedia.com	47	45	107.7 KB	17	0	0	07:59:16
3	*.tampfl.dsl-w.verizon.net	8	7	12.3 KB	3	0	0	02:07:30
4	*.bbox.io	17	7	26.3 KB	3	1	1	03:24:35
5	*.chello.nl	7	2	2.7 KB	2	0	0	01:43:05
6	*.154.22.98.dynamic.ip.windstream.net	2	0	0.0 KB	0	0	0	01:00:36
7	*.mixmin.net	2827	0	0.0 KB	0	0	0	00:27:09
TOTAL: 7		3231	147	369.5 KB	104	1	1	84:49:37

NNRP auth users [Top 20]:

User	Conn
moussa	288
kev009	1
TOTAL: 2	289

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
162.212.88.214	0.846	0.849	0.000	63:54:58
challenger.nielsenmedia.com	4.403	0.950	0.000	07:59:16
202.89.176.220	29.816	5.908	0.732	04:12:19
tempe0.bbox.io	1.398	0.307	0.003	03:24:35
pool-71-98-160-84.tampfl.dsl-w.verizon.net	0.870	0.125	0.000	02:07:30
dhcp-089-099-203-254.chello.nl	0.634	0.101	0.000	01:43:05
h112.154.22.98.dynamic.ip.windstream.net	0.165	0.060	0.000	01:00:36
snorky.mixmin.net	236.214	46.119	0.000	00:27:09
69.160.37.54	2.013	0.416	0.000	00:00:02
208.100.26.231	0.164	0.024	0.000	00:00:01
TOTAL: 10	276.523	54.859	0.735	84:49:37

Curious NNRP server explorers [Top 20]:

System	Conn
snorky.mixmin.net	2827
69.160.37.54	25
162.212.88.214	8
h112.154.22.98.dynamic.ip.windstream.net	2
208.100.26.231	2
TOTAL: 5	2864

NNRP client timeouts [Top 20]:

System	Conn	Peer
challenger.nielsenmedia.com	14	0
tempe0.bbox.io	6	0
pool-71-98-160-84.tampfl.dsl-w.verizon.net	3	0
h112.154.22.98.dynamic.ip.windstream.net	2	0
TOTAL: 4	25	0

Newsgroup request counts (by category):

Category		Count	Pct
1	comp	143	97.3%
2	news	4	2.7%
TOTAL: 2		147	100.0%

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

Newsgroup		Count
1	comp.lang.awk	52
2	comp.arch	46
3	comp.os.vms	15
4	comp.sys.ibm.ps2.hardware	8
5	comp.arch.embedded	6
6	comp.os.linux.networking	5
7	news.software.nntp	4
8	comp.sys.ibm.pc.games.action	3
9	comp.sys.ibm.pc.hardware.storage	3
10	comp.sys.ibm.pc.games.war-historical	1
11	comp.os.os2.announce	1
12	comp.ai.neural-nets	1
13	comp.os.os2.ecomstation	1
14	comp.ai.nat-lang	1
TOTAL: 14		147

Daily Usenet report for csiph.com

Nov 18 04:15:00 -- Nov 19 04:15:00