Daily Usenet report: May 31 15:00:10

Unknown entries from news log file:

First 2 / 2 lines (100.0%)

May 31 15:04:04 colo-sc-1 innd: message repeated 2 times: [ ctlinnd command s]
Jun 1 00:04:08 colo-sc-1 pgpverify[19649]: pgpverify: verification failed

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	16084	77.4%	1.9 MB	74.8%
innd	2825	13.6%	393.5 KB	15.0%
innfeed	1261	6.1%	175.4 KB	6.7%
cnfsstat	576	2.8%	86.2 KB	3.3%
controlchan	22	0.1%	5.3 KB	0.2%
nnrpd	4	0.0%	0.5 KB	0.0%
pgpverify	1	0.0%	0.1 KB	0.0%
overchan	1	0.0%	0.1 KB	0.0%
TOTAL: 8	20774	100.0%	2.6 MB	100.0%

History cache:

Reason	Count	%Count
Negative hits	49088	47.5%
Positive hits	38646	37.4%
Do not exist	15634	15.1%
Cache misses	21	0.0%
TOTAL: 4	103389	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:10.094	0.0%	37	0.000	272.811	3325.000
article cleanup	00:00:00.112	0.0%	15755	0.000	0.007	0.037
article logging	00:00:00.521	0.0%	16058	0.000	0.032	0.106
article parse	00:00:00.296	0.0%	28885	0.000	0.010	0.032
article write	00:00:07.652	0.0%	14355	0.000	0.533	20.738
artlog/artcncl	00:00:00.001	0.0%	37	0.000	0.027	1.000
data move	00:00:00.169	0.0%	113120	0.000	0.001	0.007
hisgrep/artcncl	00:00:00.000	0.0%	35	0.000	0.000	0.000
hishave/artcncl	00:00:05.023	0.0%	37	0.000	135.757	1374.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:13:38.218	0.9%	104152	0.002	7.856	59.556
history sync	00:00:00.021	0.0%	357	0.000	0.059	0.500
history write	00:00:17.094	0.0%	15755	0.000	1.085	31.152
hiswrite/artcncl	00:00:00.000	0.0%	2	0.000	0.000	0.000
idle	23:45:37.717	98.9%	108968	412.880	784.980	1978.570
nntp read	00:00:00.802	0.0%	112515	0.000	0.007	0.023
overview write	00:00:00.063	0.0%	14355	0.000	0.004	0.024
perl filter	00:00:27.129	0.0%	15755	0.740	1.722	15.510
python filter	00:00:00.440	0.0%	15755	0.000	0.028	0.074
site send	00:00:02.700	0.0%	43066	0.022	0.063	0.106
TOTAL: 24:00:54.478	24:00:28.052	100.0%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.027	0.0%	14330	0.000	0.002	0.026
article prepare	00:00:00.000	0.0%	523	0.000	0.000	0.000
article read	00:00:00.119	0.0%	451	0.000	0.264	51.500
backlog stats	00:00:00.049	0.0%	66138	0.000	0.001	0.009
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:00.380	0.0%	44189	0.000	0.009	0.034
data write	00:00:00.793	0.0%	30103	0.000	0.026	0.057
idle	23:59:12.613	100.0%	66138	715.025	1305.643	3078.477
status file	00:00:02.121	0.0%	252	0.000	8.417	357.750
TOTAL: 23:59:18.100	23:59:16.102	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	00:00:00.000	0.0%	0	0.000	0.000	0.000
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.000	0.0%	1	0.000	0.000	0.000
TOTAL: 00:00:00.186	00:00:00.000	0.0%	-	-	-	-

Control commands to INND:

Command	Number
flush	5
flushlogs	2
go	2
logmode	2
lowmark	1
mode	147
name	2
pause	2
paused	2
reserve	2
TOTAL: 10	167

Control Channel:

Sender	Other	Bad PGP	OK
news@sfere.anjou.terraraq.org.uk	1	0	1
us-control@lists.killfile.org	0	1	0
TOTAL	1	1	1

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	hasname-out.news.weretis.net	3	27021	8316	18311	394	30%	48:43:16
2	news-out.aioe.org	9	13016	4879	8097	40	37%	24:50:09
3	news.nntp4.net	2	15201	1507	12717	977	9%	23:42:33
4	localhost	1	0	0	0	0	0%	00:00:00
TOTAL: 4		15	55238	14702	39125	1411	26%	97:15:58

Incoming Volume (INN):

Server		AcceptVol	RejVol	TotalVol	%Acc	Vol/Art
1	hasname-out.news.weretis.net	24.5 MB	1.1 MB	25.6 MB	95%	3.0 KB
2	news-out.aioe.org	14.0 MB	67.1 KB	14.1 MB	99%	2.9 KB
3	news.nntp4.net	4.1 MB	3.7 MB	7.7 MB	52%	3.2 KB
4	localhost	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 4		42.6 MB	4.9 MB	47.4 MB	89%	3.0 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
May 31 15:00:10 - 15:59:59	919	6.4%	0.26	2.6 MB	6.1%	0.73
May 31 16:00:00 - 16:59:59	801	5.6%	0.22	2.3 MB	5.6%	0.67
May 31 17:00:00 - 17:59:59	769	5.4%	0.21	2.1 MB	5.1%	0.60
May 31 18:00:00 - 18:59:59	754	5.3%	0.21	2.1 MB	5.2%	0.61
May 31 19:00:00 - 19:59:59	789	5.5%	0.22	2.5 MB	6.0%	0.71
May 31 20:00:00 - 20:59:59	839	5.8%	0.23	2.6 MB	6.3%	0.75
May 31 21:00:00 - 21:59:59	747	5.2%	0.21	2.3 MB	5.5%	0.65
May 31 22:00:00 - 22:59:59	496	3.5%	0.14	1.9 MB	4.7%	0.55
May 31 23:00:00 - 23:59:59	394	2.7%	0.11	1.3 MB	3.0%	0.36
Jun 1 00:00:00 - 00:59:59	344	2.4%	0.10	1.3 MB	3.2%	0.38
Jun 1 01:00:00 - 01:59:59	338	2.4%	0.09	1.1 MB	2.7%	0.32
Jun 1 02:00:00 - 02:59:59	301	2.1%	0.08	956.3 KB	2.2%	0.27
Jun 1 03:00:00 - 03:59:59	272	1.9%	0.08	837.2 KB	2.0%	0.23
Jun 1 04:00:00 - 04:59:59	338	2.4%	0.09	871.6 KB	2.0%	0.24
Jun 1 05:00:00 - 05:59:59	369	2.6%	0.10	1.1 MB	2.5%	0.30
Jun 1 06:00:00 - 06:59:59	518	3.6%	0.14	1.6 MB	4.0%	0.47
Jun 1 07:00:00 - 07:59:59	606	4.2%	0.17	1.5 MB	3.7%	0.44
Jun 1 08:00:00 - 08:59:59	587	4.1%	0.16	1.4 MB	3.3%	0.39
Jun 1 09:00:00 - 09:59:59	659	4.6%	0.18	1.8 MB	4.3%	0.51
Jun 1 10:00:00 - 10:59:59	707	4.9%	0.20	1.8 MB	4.3%	0.51
Jun 1 11:00:00 - 11:59:59	637	4.4%	0.18	1.7 MB	4.1%	0.49
Jun 1 12:00:00 - 12:59:59	696	4.9%	0.19	1.9 MB	4.5%	0.53
Jun 1 13:00:00 - 13:59:59	720	5.0%	0.20	1.9 MB	4.6%	0.54
Jun 1 14:00:00 - 14:59:59	737	5.1%	0.20	2.0 MB	4.9%	0.58
Jun 1 15:00:00 - 15:00:04	11	0.1%	2.75	25.3 KB	0.1%	6.32
TOTAL: 23:59:54	14348	100.0%	0.17	41.6 MB	100.0%	0.49

CNFS buffer status:

Buffer	Class	Size	Used	%Used	Cycles	KB/sec	Days
FOUR	DEFAULT	1024.0 MB	209.4 MB	20.4%	1	0.21	56.87
ONE	DEFAULT	1024.0 MB	368.7 MB	36.0%	3	0.21	58.21
THREE	DEFAULT	1024.0 MB	213.8 MB	20.9%	1	0.21	57.55
TWO	DEFAULT	1024.0 MB	211.1 MB	20.6%	1	0.21	58.01
TOTAL: 4	-	4.0 GB	1002.9 MB	24.5%	6	0.21	-

Sites sending bad articles:

Server		Total	Group	Unapp	Other
1	news.nntp4.net	985	25	1	959
2	hasname-out.news.weretis.net	537	4	0	533
3	news-out.aioe.org	177	0	0	177
TOTAL: 3		1699	29	1	1669

Unwanted newsgroups [Top 20]:

Newsgroup	Count
alt.blah	12
alt.sex.female	6
wolfsburg.talk	2
tw.environment	1
alt.aliens.imprisoned	1
rec.arts.sf.starwars.collecting.customizing	1
alt.math	1
sg.singnet.test	1
arcor.help	1
borland.public.test	1
netscape.public.mozilla.test	1
uklinux.test	1
TOTAL: 12	29

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

Groups	Count
bit.listserv.catholic	1
TOTAL: 1	1

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	556
EMP (phn path)	532
EMP (phl)	139
EMP (phn nph)	115
User-issued spam cancel	8
Scoring filter	6
HTML Multipart	4
HTML post	2
Too many newsgroups (meow)	2
Too many newsgroups	1
U2 violation - invalid distribution	1
TOTAL: 11	1366

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Including strange strings
	hasname-out.news.weretis.net	150
	news-out.aioe.org	139
	news.nntp4.net	14
	TOTAL: 3	303
TOTAL: 1		303

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	%Took	Elapsed
1	bbsgslincom	427	427	0	0	100%	19:16:49
2	aioe	9797	6	9477	3	0%	24:06:53
3	nntp4	13191	1	12921	0	0%	24:05:25
4	weretis	6363	0	6139	14	0%	24:04:07
TOTAL: 4		29778	434	28537	17	1%	91:33:14

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	bbsgslincom	1.7 MB	0.0 KB	1.7 MB	4.1 KB	19:16:49
2	aioe	21.4 KB	5.0 KB	26.4 KB	2.9 KB	24:06:53
3	nntp4	3.9 KB	0.0 KB	3.9 KB	3.9 KB	24:05:25
4	weretis	0.0 KB	83.6 KB	83.6 KB	6.0 KB	24:04:07
TOTAL: 4		1.7 MB	88.6 KB	1.8 MB	4.1 KB	91:33:14

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
scanner-04.ch1.censys-scanner.com	0.000	0.003	0.000	00:00:00
TOTAL: 1	0.000	0.003	0.000	00:00:00

NNRP no permission clients:

System	Conn
scanner-04.ch1.censys-scanner.com	1
TOTAL: 1	1

Daily Usenet report

May 31 15:00:10 -- Jun 1 15:00:04