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

Unknown entries from news log file:

First 50 / 3717 lines (1.3%)

Aug 12 10:31:44 csiph nnrpd[72667]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:32:15 csiph nnrpd[72686]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:32:45 csiph nnrpd[72692]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:33:15 csiph nnrpd[72716]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:33:45 csiph nnrpd[72740]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:34:16 csiph nnrpd[72741]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:34:47 csiph nnrpd[72765]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:35:18 csiph nnrpd[72779]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:35:48 csiph nnrpd[72803]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:36:18 csiph nnrpd[72804]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:36:48 csiph nnrpd[72828]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:37:19 csiph nnrpd[72829]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:37:49 csiph nnrpd[72856]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:38:19 csiph nnrpd[72857]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:38:49 csiph nnrpd[72884]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:39:19 csiph nnrpd[72885]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:39:49 csiph nnrpd[72899]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:40:19 csiph nnrpd[72926]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:40:50 csiph nnrpd[72927]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:41:20 csiph nnrpd[73086]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:41:52 csiph nnrpd[73090]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:42:22 csiph nnrpd[73114]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:42:52 csiph nnrpd[73115]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:43:22 csiph nnrpd[73142]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:43:52 csiph nnrpd[73143]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:44:22 csiph nnrpd[73190]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:44:53 csiph nnrpd[73191]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:45:23 csiph nnrpd[73225]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:45:53 csiph nnrpd[73226]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:46:23 csiph nnrpd[73252]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:46:54 csiph nnrpd[73268]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:47:25 csiph nnrpd[73294]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:47:55 csiph nnrpd[73311]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:48:26 csiph nnrpd[73312]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:48:57 csiph nnrpd[73336]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:49:28 csiph nnrpd[73337]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:49:59 csiph nnrpd[73361]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:50:30 csiph nnrpd[73372]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:51:01 csiph nnrpd[73399]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:51:32 csiph nnrpd[73535]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:52:02 csiph nnrpd[73559]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:52:33 csiph nnrpd[73560]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:53:04 csiph nnrpd[73584]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:53:35 csiph nnrpd[73593]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:54:05 csiph nnrpd[73627]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:54:35 csiph nnrpd[73649]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:55:06 csiph nnrpd[73720]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:55:36 csiph nnrpd[73733]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:56:06 csiph nnrpd[73756]: snorky.mixmin.net noperm ihave without permission
Aug 12 10:56:36 csiph nnrpd[73796]: snorky.mixmin.net noperm ihave without permission

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	57140	42.1%	7.2 MB	50.3%
nnrpd	50554	37.2%	4.5 MB	31.2%
innd	26585	19.6%	2.5 MB	17.1%
innfeed	1448	1.1%	200.1 KB	1.4%
controlchan	5	0.0%	0.7 KB	0.0%
TOTAL: 5	135732	100.0%	14.3 MB	100.0%

History cache:

Reason	Count	%Count
Negative hits	225167	44.5%
Positive hits	221092	43.6%
Do not exist	55861	11.0%
Cache misses	4415	0.9%
TOTAL: 4	506535	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.832	0.0%	593	0.000	1.403	8.111
article cleanup	00:00:00.360	0.0%	53721	0.000	0.007	0.025
article logging	00:00:00.662	0.0%	54177	0.000	0.012	0.040
article parse	00:00:05.032	0.0%	635180	0.003	0.008	0.031
article write	00:00:06.422	0.0%	27177	0.137	0.236	0.348
artlog/artcncl	00:00:00.007	0.0%	569	0.000	0.012	0.250
artlog/artparse	00:00:00.025	0.0%	2303	0.000	0.011	1.000
data move	00:00:00.505	0.0%	995634	0.000	0.001	0.002
hisgrep/artcncl	00:00:00.022	0.0%	569	0.000	0.039	1.556
hishave/artcncl	00:00:00.000	0.0%	593	0.000	0.000	0.000
hishave/artparse	00:00:00.006	0.0%	2303	0.000	0.003	0.091
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:01.350	0.0%	504752	0.000	0.003	0.013
history sync	00:00:00.448	0.0%	331	0.000	1.353	5.667
history write	00:00:12.538	0.0%	53600	0.104	0.234	1.009
hiswrite/artcncl	00:00:00.000	0.0%	24	0.000	0.000	0.000
hiswrite/artparse	00:00:00.612	0.0%	2299	0.000	0.266	2.000
idle	23:57:04.442	99.7%	982840	9.512	87.730	460.579
nntp read	00:00:03.314	0.0%	975839	0.001	0.003	0.007
overview write	00:00:08.184	0.0%	27177	0.084	0.301	3.565
perl filter	00:02:11.896	0.2%	53600	1.040	2.461	4.991
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.582	0.0%	54356	0.000	0.011	0.027
TOTAL: 24:00:44.645	23:59:57.239	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.073	0.0%	27028	0.000	0.003	0.018
article prepare	00:00:00.001	0.0%	7756	0.000	0.000	0.014
article read	00:00:00.313	0.0%	1597	0.000	0.196	15.000
backlog stats	00:00:00.070	0.0%	244724	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.041	0.0%	176809	0.001	0.006	0.015
data write	00:00:01.402	0.0%	151441	0.002	0.009	0.021
idle	23:43:41.605	100.0%	244724	186.241	349.053	930.637
status file	00:00:00.045	0.0%	165	0.000	0.273	1.000
TOTAL: 23:43:47.602	23:43:44.550	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:00.171	0.0%	11303	0.009	0.015	0.031
idle	40:08:21.475	99.7%	53879	0.000	2681.963	600519.333
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.614	0.0%	108692	0.000	0.006	0.333
readart	00:00:00.113	0.0%	80	0.000	1.413	44.000
TOTAL: 40:15:38.002	40:08:22.373	99.7%	-	-	-	-

Control commands to INND:

Command	Number
L	1
flush	4
flushlogs	2
go	2
logmode	2
mode	147
newgroup	2
pause	2
paused	2
reload	2
reserve	2
TOTAL: 11	168

Newsgroups created:

Group	Mode
alt.binaries.sounds.mp3.test	y
alt.binaries.sounds.test	y
TOTAL	2

Control Channel:

Sender	newgroup	rmgroup	Other	Bad PGP	DoIt	OK
153fishare@gmail.com	2	0	0	0	2	2
TOTAL	2	0	0	0	2	2

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	feeder.eternal-september.org	4	50628	9507	32506	8615	18%	24:32:05
2	au2pb.net	5	28344	6531	21148	665	23%	22:20:33
3	xanadu-bbs.net	8	65240	4686	51856	8698	7%	26:53:48
4	newsfeeds.xmission.com	5	28330	3346	24511	473	11%	25:30:23
5	newsfeed.neva.ru	148	100037	2909	86788	10340	2%	72:24:43
6	nntp.pasdenom.info	4	42758	580	42063	115	1%	28:02:39
7	localhost	48	10749	0	10749	0	0%	00:00:55
TOTAL: 7		222	326086	27559	269621	28906	8%	199:45:06

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	feeder.eternal-september.org	28.1 MB	431.5 KB	87.6 MB	116.1 MB	24%	6.6 KB
2	au2pb.net	15.2 MB	31.5 KB	5.9 MB	21.2 MB	71%	3.0 KB
3	xanadu-bbs.net	14.5 MB	140.2 KB	580.5 MB	595.1 MB	2%	45.5 KB
4	newsfeeds.xmission.com	9.6 MB	10.7 KB	3.7 MB	13.4 MB	72%	3.6 KB
5	newsfeed.neva.ru	8.6 MB	974.9 KB	93.4 MB	102.9 MB	8%	8.0 KB
6	nntp.pasdenom.info	1.6 MB	0.0 KB	1.6 MB	3.2 MB	49%	4.7 KB
7	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 7		77.6 MB	1.6 MB	772.7 MB	851.9 MB	9%	15.4 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Aug 12 04:15:00 - 04:59:59	430	1.6%	0.16	1.4 MB	1.8%	0.53
Aug 12 05:00:00 - 05:59:59	563	2.1%	0.16	1.5 MB	2.0%	0.43
Aug 12 06:00:00 - 06:59:59	794	2.9%	0.22	2.3 MB	2.9%	0.64
Aug 12 07:00:00 - 07:59:59	1172	4.3%	0.33	3.5 MB	4.6%	1.01
Aug 12 08:00:00 - 08:59:59	1180	4.3%	0.33	3.1 MB	4.1%	0.89
Aug 12 09:00:00 - 09:59:59	1443	5.3%	0.40	3.9 MB	5.1%	1.12
Aug 12 10:00:00 - 10:59:59	1326	4.9%	0.37	3.7 MB	4.9%	1.06
Aug 12 11:00:00 - 11:59:59	1174	4.3%	0.33	3.1 MB	4.0%	0.88
Aug 12 12:00:00 - 12:59:59	1324	4.9%	0.37	3.8 MB	4.9%	1.07
Aug 12 13:00:00 - 13:59:59	1301	4.8%	0.36	3.6 MB	4.6%	1.01
Aug 12 14:00:00 - 14:59:59	1684	6.2%	0.47	4.3 MB	5.6%	1.23
Aug 12 15:00:00 - 15:59:59	1496	5.5%	0.42	3.8 MB	4.9%	1.08
Aug 12 16:00:00 - 16:59:59	1634	6.0%	0.45	4.5 MB	5.8%	1.28
Aug 12 17:00:00 - 17:59:59	1630	6.0%	0.45	4.6 MB	6.0%	1.31
Aug 12 18:00:00 - 18:59:59	1499	5.5%	0.42	4.0 MB	5.2%	1.13
Aug 12 19:00:00 - 19:59:59	1450	5.3%	0.40	4.0 MB	5.2%	1.14
Aug 12 20:00:00 - 20:59:59	1372	5.0%	0.38	3.6 MB	4.7%	1.04
Aug 12 21:00:00 - 21:59:59	1310	4.8%	0.36	4.0 MB	5.2%	1.13
Aug 12 22:00:00 - 22:59:59	1056	3.9%	0.29	3.2 MB	4.2%	0.92
Aug 12 23:00:00 - 23:59:59	791	2.9%	0.22	2.2 MB	2.8%	0.62
Aug 13 00:00:00 - 00:59:59	713	2.6%	0.20	2.3 MB	3.0%	0.65
Aug 13 01:00:00 - 01:59:59	566	2.1%	0.16	1.6 MB	2.1%	0.45
Aug 13 02:00:00 - 02:59:59	533	2.0%	0.15	1.6 MB	2.1%	0.45
Aug 13 03:00:00 - 03:59:59	565	2.1%	0.16	2.8 MB	3.6%	0.79
Aug 13 04:00:00 - 04:15:00	166	0.6%	0.18	662.3 KB	0.8%	0.74
TOTAL: 24:00:00	27172	100.0%	0.31	77.1 MB	100.0%	0.91

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	newsfeed.neva.ru	10351	1544	75	1	8731
2	feeder.eternal-september.org	8828	493	35	0	8300
3	xanadu-bbs.net	8750	650	8	0	8092
4	au2pb.net	883	617	1	0	265
5	newsfeeds.xmission.com	482	421	2	0	59
6	nntp.pasdenom.info	106	85	0	0	21
TOTAL: 6		29400	3810	121	1	25468

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	919
mailing.freebsd.pkg-fallout	187
alt.politics.scorched-earth	173
lada.auto	172
ut.test	133
lada.talk	124
alt.politics	115
alt.windows7.general	76
mailing.freebsd.svn-src-all	74
fa.freebsd.cvs-all	69
mailing.openbsd.ports-changes	67
mozilla.dev.tree-alerts	59
free.it.calcio.juventus	55
mailing.freebsd.svn-ports-all	54
mailing.freebsd.svn-src-head	53
mailing.freebsd.svn-ports-head	52
alt.job	48
mailing.freebsd.ports-bugs	47
mailing.gcc.gcc-cvs	47
mpc.lists.freebsd.ports.bugs	46
TOTAL: 262	3810

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

Groups	Count
uk.legal.moderated	1
TOTAL: 1	1

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	18572
EMP (phn path)	3095
EMP (phl)	726
PFM bot misc	113
HTML Multipart	61
Too many newsgroups	56
EMP (phn nph)	33
Binary Image: misplaced jpg	27
HTML post	10
Too many test groups in crosspost	10
Too many newsgroups (meow)	2
Binary: misplaced par2	1
Binary: misplaced PAR2	1
Binary: misplaced pdf	1
Binary: misplaced rar	1
TOTAL: 15	22709

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	xanadu-bbs.net	2108
	feeder.eternal-september.org	112
	newsfeeds.xmission.com	34
	au2pb.net	33
	nntp.pasdenom.info	16
	TOTAL: 5	2303
Including strange strings
	au2pb.net	208
	feeder.eternal-september.org	180
	newsfeed.neva.ru	25
	xanadu-bbs.net	21
	newsfeeds.xmission.com	20
	nntp.pasdenom.info	2
	TOTAL: 6	456
TOTAL: 2		2759

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	usenet.pasdenom.info	33135	432	25493	748	4	1%	23:59:40
2	au2pb	21465	274	20038	238	0	1%	23:59:52
3	xanadu-bbs	24688	103	22293	60	52	0%	23:59:53
4	xmission	29109	12	23829	1	3	0%	23:59:53
5	neva.ru	25133	6	23994	70	0	0%	23:59:42
6	eternal-september	18892	5	17465	1	0	0%	23:59:52
TOTAL: 6		152422	832	133112	1118	59	0%	143:58:52

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	usenet.pasdenom.info	1.4 MB	1.5 MB	2.9 MB	2.6 KB	23:59:40
2	au2pb	1.1 MB	607.4 KB	1.7 MB	3.4 KB	23:59:52
3	xanadu-bbs	557.8 KB	119.4 KB	677.2 KB	4.2 KB	23:59:53
4	neva.ru	30.4 KB	266.8 KB	297.2 KB	3.9 KB	23:59:42
5	xmission	23.7 KB	1.1 KB	24.8 KB	1.9 KB	23:59:53
6	eternal-september	23.6 KB	1.6 KB	25.2 KB	4.2 KB	23:59:52
TOTAL: 6		3.1 MB	2.5 MB	5.6 MB	3.0 KB	143:58:52

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Elapsed
1	202.89.176.220	288	67	183.2 KB	61	04:24:59
2	107.160.61.188.dynamic.wline.res.cust.swisscom.ch	1	5	9.3 KB	1	00:30:59
3	92-108-162-83.dynamic.upc.nl	2	2	2.6 KB	1	00:01:16
4	tempe0.bbox.io	9	2	2.5 KB	2	02:08:16
5	dhcp-089-099-203-254.chello.nl	13	2	4.2 KB	2	04:30:59
6	pool-71-98-160-84.tampfl.dsl-w.verizon.net	6	1	1.7 KB	1	00:28:38
7	challenger.nielsenmedia.com	14	1	1.7 KB	1	02:35:42
TOTAL: 7		333	80	205.1 KB	69	40:15:03

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	unresolved	317	67	183.2 KB	61	28:59:42
2	*.160.61.188.dynamic.wline.res.cust.swisscom.ch	1	5	9.3 KB	1	00:30:59
3	*.dynamic.upc.nl	2	2	2.6 KB	1	00:01:16
4	*.bbox.io	9	2	2.5 KB	2	02:08:16
5	*.chello.nl	13	2	4.2 KB	2	04:30:59
6	*.nielsenmedia.com	14	1	1.7 KB	1	02:35:42
7	*.tampfl.dsl-w.verizon.net	6	1	1.7 KB	1	00:28:38
8	*.br.br.cox.net	5	0	0.0 KB	0	00:10:18
9	*.zedat.fu-berlin.de	1	0	0.0 KB	0	00:00:04
10	*.de	1627	0	0.0 KB	0	00:16:58
11	*.mixmin.net	2090	0	0.0 KB	0	00:19:01
12	*.ip-188-165-239.eu	4	0	0.0 KB	0	00:13:04
TOTAL: 12		4089	80	205.1 KB	69	40:15:03

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.198	0.764	0.597	0.000	24:34:41
dhcp-089-099-203-254.chello.nl	1.068	0.134	0.000	04:30:59
202.89.176.220	26.947	5.375	0.667	04:24:59
challenger.nielsenmedia.com	1.183	0.182	0.000	02:35:42
tempe0.bbox.io	0.882	0.127	0.000	02:08:16
107.160.61.188.dynamic.wline.res.cust.swisscom.ch	0.143	0.015	0.000	00:30:59
pool-71-98-160-84.tampfl.dsl-w.verizon.net	0.414	0.056	0.000	00:28:38
snorky.mixmin.net	163.981	28.938	0.000	00:19:01
swapon.de	128.357	22.864	0.000	00:16:58
ns342002.ip-188-165-239.eu	0.310	0.063	0.000	00:13:04
ip70-186-187-149.br.br.cox.net	0.471	0.094	0.000	00:10:18
92-108-162-83.dynamic.upc.nl	0.202	0.040	0.000	00:01:16
irland.zedat.fu-berlin.de	0.088	0.016	0.000	00:00:04
69.160.37.54	1.984	0.301	0.000	00:00:02
TOTAL: 14	326.794	58.802	0.667	40:15:03

Curious NNRP server explorers [Top 20]:

System	Conn
snorky.mixmin.net	2090
swapon.de	1627
69.160.37.54	25
ip70-186-187-149.br.br.cox.net	5
ns342002.ip-188-165-239.eu	4
162.212.88.198	4
irland.zedat.fu-berlin.de	1
TOTAL: 7	3756

NNRP client timeouts [Top 20]:

System	Conn	Peer
dhcp-089-099-203-254.chello.nl	7	0
challenger.nielsenmedia.com	5	0
tempe0.bbox.io	4	0
107.160.61.188.dynamic.wline.res.cust.swisscom.ch	1	0
TOTAL: 4	17	0

Newsgroup request counts (by category):

Category		Count	Pct
1	comp	78	97.5%
2	news	2	2.5%
TOTAL: 2		80	100.0%

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

Newsgroup		Count
1	comp.os.vms	43
2	comp.os.os2.advocacy	10
3	comp.sys.ibm.ps2.hardware	10
4	comp.os.msdos.misc	3
5	comp.lang.awk	2
6	comp.arch.fpga	2
7	comp.ai.nat-lang	2
8	news.admin.peering	2
9	comp.ai.philosophy	1
10	comp.os.os2.announce	1
11	comp.arch.embedded	1
12	comp.sys.ibm.as400.misc	1
13	comp.arch	1
14	comp.sys.ibm.pc.hardware.storage	1
TOTAL: 14		80

Daily Usenet report for csiph.com

Aug 12 04:15:00 -- Aug 13 04:15:00