Daily Usenet report: Sep 30 15:00:02

Unknown entries from news log file:

First 2 / 2 lines (100.0%)

Sep 30 15:01:03 colo-sc-1 innd: message repeated 2 times: [ ctlinnd command s]
Oct 1 00:04:02 colo-sc-1 pgpverify[15230]: pgpverify: verification failed

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	17075	79.4%	2.1 MB	77.2%
innd	2613	12.2%	366.7 KB	13.4%
innfeed	1212	5.6%	171.1 KB	6.3%
cnfsstat	576	2.7%	79.9 KB	2.9%
controlchan	23	0.1%	5.3 KB	0.2%
nnrpd	4	0.0%	0.3 KB	0.0%
pgpverify	1	0.0%	0.1 KB	0.0%
overchan	1	0.0%	0.1 KB	0.0%
TOTAL: 8	21505	100.0%	2.7 MB	100.0%

History cache:

Reason	Count	%Count
Negative hits	45648	44.1%
Positive hits	41299	39.9%
Do not exist	16573	16.0%
Cache misses	53	0.1%
TOTAL: 4	103573	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:04.189	0.0%	73	0.000	57.384	320.333
article cleanup	00:00:00.106	0.0%	16705	0.000	0.006	0.037
article logging	00:00:00.452	0.0%	17071	0.000	0.026	0.080
article parse	00:00:00.284	0.0%	32693	0.000	0.009	0.034
article write	00:00:02.963	0.0%	15722	0.000	0.188	7.402
artlog/artcncl	00:00:00.002	0.0%	73	0.000	0.027	0.250
data move	00:00:00.078	0.0%	115707	0.000	0.001	0.005
hisgrep/artcncl	00:00:00.001	0.0%	72	0.000	0.014	0.500
hishave/artcncl	00:00:01.393	0.0%	73	0.000	19.082	206.667
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:03:19.253	0.2%	104119	0.002	1.914	71.981
history sync	00:00:00.011	0.0%	409	0.000	0.027	1.000
history write	00:00:01.926	0.0%	16671	0.000	0.116	5.769
hiswrite/artcncl	00:00:00.000	0.0%	1	0.000	0.000	0.000
idle	23:56:58.353	99.7%	115118	338.312	748.956	2060.601
nntp read	00:00:00.878	0.0%	115610	0.000	0.008	0.018
overview write	00:00:00.042	0.0%	15722	0.000	0.003	0.041
perl filter	00:00:19.905	0.0%	16671	0.791	1.194	12.197
python filter	00:00:00.424	0.0%	16671	0.000	0.025	0.087
site send	00:00:02.587	0.0%	47168	0.012	0.055	0.105
TOTAL: 24:01:07.515	24:00:52.847	100.0%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.034	0.0%	15574	0.000	0.002	0.028
article prepare	00:00:00.001	0.0%	812	0.000	0.001	0.167
article read	00:00:00.029	0.0%	530	0.000	0.055	1.000
backlog stats	00:00:00.047	0.0%	82860	0.000	0.001	0.007
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:00.413	0.0%	51832	0.000	0.008	0.028
data write	00:00:01.017	0.0%	36577	0.000	0.028	0.073
idle	23:48:06.863	100.0%	82860	467.277	1034.116	2865.813
status file	00:00:01.733	0.0%	235	0.000	7.374	417.500
TOTAL: 23:48:13.015	23:48:10.137	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.574	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	8	27285	9955	17142	188	36%	47:11:28
2	news-out.aioe.org	4	13442	3833	9606	3	28%	23:49:27
3	news.nntp4.net	4	16531	1512	14180	839	9%	24:25:55
4	localhost	1	0	0	0	0	0%	00:00:00
TOTAL: 4		17	57258	15300	40928	1030	26%	95:26:50

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	hasname-out.news.weretis.net	34.2 MB	222.3 KB	508.3 KB	35.0 MB	97%	3.5 KB
2	news-out.aioe.org	10.0 MB	7.3 KB	7.3 KB	10.0 MB	99%	2.7 KB
3	news.nntp4.net	4.2 MB	5.8 KB	7.1 MB	11.3 MB	37%	4.9 KB
4	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 4		48.5 MB	235.4 KB	7.6 MB	56.3 MB	86%	3.5 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Sep 30 15:00:02 - 15:59:59	848	5.4%	0.24	2.4 MB	4.9%	0.69
Sep 30 16:00:00 - 16:59:59	726	4.6%	0.20	2.1 MB	4.2%	0.59
Sep 30 17:00:00 - 17:59:59	812	5.2%	0.23	2.6 MB	5.3%	0.74
Sep 30 18:00:00 - 18:59:59	925	5.9%	0.26	3.2 MB	6.4%	0.90
Sep 30 19:00:00 - 19:59:59	902	5.8%	0.25	2.4 MB	4.8%	0.67
Sep 30 20:00:00 - 20:59:59	873	5.6%	0.24	2.5 MB	5.0%	0.71
Sep 30 21:00:00 - 21:59:59	624	4.0%	0.17	1.7 MB	3.5%	0.49
Sep 30 22:00:00 - 22:59:59	495	3.2%	0.14	2.1 MB	4.3%	0.61
Sep 30 23:00:00 - 23:59:59	488	3.1%	0.14	1.8 MB	3.6%	0.51
Oct 1 00:00:00 - 00:59:59	337	2.2%	0.09	2.2 MB	4.5%	0.63
Oct 1 01:00:00 - 01:59:59	339	2.2%	0.09	1.8 MB	3.6%	0.50
Oct 1 02:00:00 - 02:59:59	364	2.3%	0.10	1.4 MB	2.7%	0.39
Oct 1 03:00:00 - 03:59:59	277	1.8%	0.08	1.0 MB	2.0%	0.28
Oct 1 04:00:00 - 04:59:59	315	2.0%	0.09	1000.1 KB	2.0%	0.28
Oct 1 05:00:00 - 05:59:59	329	2.1%	0.09	932.9 KB	1.8%	0.26
Oct 1 06:00:00 - 06:59:59	588	3.8%	0.16	1.8 MB	3.6%	0.51
Oct 1 07:00:00 - 07:59:59	640	4.1%	0.18	1.9 MB	3.9%	0.55
Oct 1 08:00:00 - 08:59:59	821	5.2%	0.23	2.4 MB	4.9%	0.69
Oct 1 09:00:00 - 09:59:59	816	5.2%	0.23	2.1 MB	4.2%	0.59
Oct 1 10:00:00 - 10:59:59	811	5.2%	0.23	2.4 MB	4.9%	0.68
Oct 1 11:00:00 - 11:59:59	683	4.4%	0.19	1.7 MB	3.4%	0.49
Oct 1 12:00:00 - 12:59:59	911	5.8%	0.25	3.1 MB	6.2%	0.87
Oct 1 13:00:00 - 13:59:59	842	5.4%	0.23	2.3 MB	4.6%	0.64
Oct 1 14:00:00 - 14:59:59	899	5.7%	0.25	2.9 MB	5.8%	0.82
Oct 1 15:00:00 - 15:00:01	1	0.0%	1.00	2.2 KB	0.0%	2.23
TOTAL: 23:59:59	15666	100.0%	0.18	49.5 MB	100.0%	0.59

CNFS buffer status:

Buffer	Class	Size	Used	%Used	Cycles	KB/sec	Days
FOUR	DEFAULT	1024.0 MB	255.3 MB	24.9%	3	0.24	50.18
ONE	DEFAULT	1024.0 MB	417.1 MB	40.7%	5	0.24	49.63
THREE	DEFAULT	1024.0 MB	258.4 MB	25.2%	3	0.25	48.64
TWO	DEFAULT	1024.0 MB	252.2 MB	24.6%	3	0.24	50.66
TOTAL: 4	-	4.0 GB	1.2 GB	28.9%	14	0.24	-

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	news.nntp4.net	779	8	2	1	768
2	hasname-out.news.weretis.net	510	5	29	0	476
3	news-out.aioe.org	47	0	3	0	44
TOTAL: 3		1336	13	34	1	1288

Unwanted newsgroups [Top 20]:

Newsgroup	Count
0.test	2
mozilla.dev.ports.os2	2
alt.pcnews	1
mozilla.dev.tech.js-engine	1
panix.chat.politics	1
alt.college.recovery	1
macromedia.general.france	1
alt.blah	1
alt.math	1
tmnet.communities	1
alt.ufo	1
TOTAL: 11	13

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)	505
EMP (phn path)	274
EMP (phl)	70
EMP (phn nph)	39
User-issued spam cancel	25
Too many newsgroups	13
HTML Multipart	4
Scoring filter	1
TOTAL: 8	931

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Including strange strings
	hasname-out.news.weretis.net	314
	news-out.aioe.org	44
	news.nntp4.net	6
	TOTAL: 3	364
TOTAL: 1		364

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	bbsgslincom	440	440	0	0	0	100%	20:11:57
2	aioe	13729	38	11421	6	10	0%	23:51:02
3	weretis	5550	4	5276	46	0	0%	23:51:02
4	nntp4	16418	0	14091	0	2	0%	23:51:02
TOTAL: 4		36137	482	30788	52	12	1%	91:45:03

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	bbsgslincom	2.4 MB	0.0 KB	2.4 MB	5.5 KB	20:11:57
2	aioe	193.8 KB	22.0 KB	215.9 KB	4.9 KB	23:51:02
3	weretis	26.6 KB	184.0 KB	210.7 KB	4.2 KB	23:51:02
4	nntp4	0.0 KB	0.0 KB	0.0 KB	0	23:51:02
TOTAL: 4		2.6 MB	206.1 KB	2.8 MB	5.4 KB	91:45:03

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
news.nntp4.net	0.002	0.002	0.000	00:00:00
TOTAL: 1	0.002	0.002	0.000	00:00:00

NNRP no permission clients:

System	Conn
news.nntp4.net	1
TOTAL: 1	1

Daily Usenet report

Sep 30 15:00:02 -- Oct 1 15:00:01