Daily Usenet report for csiph.com: Oct 7 04:15:00

Unknown entries from news log file:

First 3 / 3 lines (100.0%)

Oct 7 12:06:07 csiph pgpverify[85471]: pgpverify: verification failed
Oct 7 12:06:07 csiph controlchan[61723]: skipping newgroup m grisbi-control@grisbi.org (pgpverify failed) in <newgroup-grisbi.admin-1475841506@news.grisbi.org>
Oct 7 12:06:52 csiph pgpverify[85501]: pgpverify: verification failed

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	43452	61.4%	8.2 MB	72.3%
innd	23172	32.7%	2.5 MB	22.1%
innfeed	3284	4.6%	550.9 KB	4.7%
nnrpd	832	1.2%	89.9 KB	0.8%
nocem	64	0.1%	6.9 KB	0.1%
controlchan	8	0.0%	1.1 KB	0.0%
pgpverify	2	0.0%	0.2 KB	0.0%
TOTAL: 7	70814	100.0%	11.3 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	461146	56.6%
Negative hits	309967	38.1%
Do not exist	42647	5.2%
Cache misses	528	0.1%
TOTAL: 4	814288	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.988	0.0%	212	0.000	4.660	45.000
article cleanup	00:00:00.265	0.0%	42397	0.000	0.006	0.029
article logging	00:00:00.599	0.0%	42883	0.000	0.014	0.103
article parse	00:00:01.593	0.0%	147981	0.001	0.011	0.024
article write	00:05:23.739	0.4%	24066	0.614	13.452	58.447
artlog/artcncl	00:00:00.004	0.0%	197	0.000	0.020	0.200
artlog/artparse	00:00:00.004	0.0%	341	0.000	0.012	1.000
data move	00:00:00.300	0.0%	767103	0.000	0.000	0.001
hisgrep/artcncl	00:00:00.055	0.0%	211	0.000	0.261	12.000
hishave/artcncl	00:00:00.000	0.0%	212	0.000	0.000	0.000
hishave/artparse	00:00:00.000	0.0%	341	0.000	0.000	0.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:00:06.172	0.0%	816661	0.001	0.008	0.209
history sync	00:00:01.071	0.0%	321	0.000	3.336	43.500
history write	00:00:25.931	0.0%	42373	0.105	0.612	8.827
hiswrite/artcncl	00:00:00.000	0.0%	1	0.000	0.000	0.000
hiswrite/artparse	00:00:00.156	0.0%	338	0.000	0.462	3.000
idle	23:50:16.777	99.3%	776521	65.041	110.514	376.020
nntp read	00:00:02.660	0.0%	793503	0.002	0.003	0.006
overview write	00:01:29.631	0.1%	24066	0.262	3.724	75.254
perl filter	00:01:49.554	0.1%	42373	1.620	2.585	3.870
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.456	0.0%	48192	0.000	0.009	0.026
TOTAL: 24:00:34.742	23:59:39.955	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.078	0.0%	24130	0.000	0.003	0.023
article prepare	00:00:00.005	0.0%	26396	0.000	0.000	0.010
article read	00:00:03.619	0.0%	3434	0.000	1.054	13.200
backlog stats	00:00:00.214	0.0%	465919	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.939	0.0%	348020	0.001	0.006	0.010
data write	00:00:02.480	0.0%	330727	0.004	0.007	0.018
idle	23:53:58.538	100.0%	465919	106.730	184.664	537.007
status file	00:00:00.464	0.0%	306	0.000	1.516	22.000
TOTAL: 23:54:14.990	23:54:07.337	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:00.003	0.0%	1573	0.001	0.002	0.010
idle	28:57:46.605	100.0%	2074	258.000	50273.194	600133.667
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.370	0.0%	4269	0.000	0.087	4.649
readart	00:00:05.109	0.0%	2270	0.000	2.251	63.000
TOTAL: 28:58:35.731	28:57:52.087	100.0%	-	-	-	-

Control commands to INND:

Command	Number
L	1
flush	5
flushlogs	2
go	2
logmode	2
mode	137
pause	2
paused	2
reload	2
reserve	2
TOTAL: 10	157

Control Channel:

Sender	Other	Bad PGP	DoIt	OK
grisbi-control@grisbi.org	0	1	0	0
news@fu-berlin.de	1	0	1	1
TOTAL	1	1	1	1

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	csiph-out.feeder.erje.net	1152	132787	8160	115238	9389	6%	95:03:17
2	csiph-out.news.weretis.net	5	53811	3717	48812	1282	6%	47:48:25
3	feeder.eternal-september.org	5	37262	3530	33022	710	9%	24:51:15
4	news-out.aioe.org	4	23264	1903	21337	24	8%	24:09:37
5	news-out.mixmin.net	3	27208	1664	24880	664	6%	24:08:50
6	newsfeed.neva.ru	147	56159	1514	48736	5909	2%	72:00:00
7	newsfeed.fu-berlin.de	48	27186	1201	25585	400	4%	33:53:42
8	newsfeeds.xmission.com	1	24441	884	23496	61	3%	25:29:59
9	news.redatomik.org	2	26375	873	25454	48	3%	28:18:12
10	news.fcku.it	2	10433	653	9629	151	6%	23:59:53
11	xanadu-bbs.net	13	815	87	720	8	10%	24:33:59
12	news.swapon.de	2	1791	66	1724	1	3%	24:56:07
13	news.freedyn.net	3	27127	46	27057	24	0%	24:10:32
14	news.bbs.geek.nz	2	24067	10	24057	0	0%	25:07:48
15	nntp.pasdenom.info	4	39218	2	39152	64	0%	24:08:21
16	localhost	34	0	0	0	0	0%	00:00:00
TOTAL: 16		1427	511944	24310	468899	18735	4%	522:39:57

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	csiph-out.feeder.erje.net	26.2 MB	128.6 KB	44.2 MB	70.6 MB	37%	4.1 KB
2	csiph-out.news.weretis.net	10.3 MB	0.0 KB	19.3 MB	29.6 MB	34%	6.1 KB
3	feeder.eternal-september.org	9.4 MB	0.0 KB	13.3 MB	22.6 MB	41%	5.5 KB
4	news-out.mixmin.net	6.6 MB	0.0 KB	1.9 MB	8.5 MB	77%	3.7 KB
5	news-out.aioe.org	4.7 MB	0.0 KB	41.5 KB	4.7 MB	99%	2.5 KB
6	newsfeed.neva.ru	4.6 MB	92.2 KB	55.1 MB	59.8 MB	7%	8.3 KB
7	newsfeeds.xmission.com	3.1 MB	0.0 KB	4.4 MB	7.5 MB	40%	8.1 KB
8	newsfeed.fu-berlin.de	2.6 MB	0.0 KB	980.1 KB	3.6 MB	73%	2.3 KB
9	news.redatomik.org	2.2 MB	0.0 KB	1.3 MB	3.5 MB	62%	3.9 KB
10	news.fcku.it	1.5 MB	0.0 KB	1.4 MB	2.9 MB	51%	3.7 KB
11	xanadu-bbs.net	297.2 KB	0.0 KB	106.2 KB	403.4 KB	73%	4.2 KB
12	news.freedyn.net	185.6 KB	0.0 KB	1.1 MB	1.3 MB	13%	19.4 KB
13	news.swapon.de	162.1 KB	0.0 KB	4.0 KB	166.1 KB	97%	2.5 KB
14	news.bbs.geek.nz	35.3 KB	0.0 KB	0.0 KB	35.3 KB	100%	3.5 KB
15	nntp.pasdenom.info	3.5 KB	4.5 KB	304.0 KB	312.0 KB	1%	4.7 KB
16	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 16		71.7 MB	225.3 KB	143.5 MB	215.4 MB	33%	5.1 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Oct 7 04:15:00 - 04:59:59	363	1.5%	0.13	1.4 MB	2.0%	0.54
Oct 7 05:00:00 - 05:59:59	528	2.2%	0.15	2.1 MB	2.9%	0.59
Oct 7 06:00:00 - 06:59:59	684	2.8%	0.19	2.0 MB	2.8%	0.57
Oct 7 07:00:00 - 07:59:59	1023	4.3%	0.28	2.5 MB	3.5%	0.71
Oct 7 08:00:00 - 08:59:59	1041	4.3%	0.29	2.7 MB	3.7%	0.76
Oct 7 09:00:00 - 09:59:59	1072	4.5%	0.30	2.5 MB	3.5%	0.71
Oct 7 10:00:00 - 10:59:59	1172	4.9%	0.33	2.9 MB	4.1%	0.84
Oct 7 11:00:00 - 11:59:59	1101	4.6%	0.31	2.9 MB	4.1%	0.84
Oct 7 12:00:00 - 12:59:59	1145	4.8%	0.32	3.2 MB	4.5%	0.91
Oct 7 13:00:00 - 13:59:59	1340	5.6%	0.37	3.5 MB	5.0%	1.00
Oct 7 14:00:00 - 14:59:59	1487	6.2%	0.41	4.4 MB	6.2%	1.26
Oct 7 15:00:00 - 15:59:59	1647	6.8%	0.46	5.4 MB	7.6%	1.55
Oct 7 16:00:00 - 16:59:59	1299	5.4%	0.36	3.9 MB	5.4%	1.10
Oct 7 17:00:00 - 17:59:59	1360	5.7%	0.38	4.6 MB	6.5%	1.31
Oct 7 18:00:00 - 18:59:59	1398	5.8%	0.39	4.5 MB	6.3%	1.27
Oct 7 19:00:00 - 19:59:59	1206	5.0%	0.34	3.4 MB	4.9%	0.98
Oct 7 20:00:00 - 20:59:59	1062	4.4%	0.29	2.9 MB	4.1%	0.82
Oct 7 21:00:00 - 21:59:59	1204	5.0%	0.33	3.8 MB	5.3%	1.08
Oct 7 22:00:00 - 22:59:59	901	3.7%	0.25	2.7 MB	3.9%	0.78
Oct 7 23:00:00 - 23:59:59	938	3.9%	0.26	2.7 MB	3.8%	0.76
Oct 8 00:00:00 - 00:59:59	681	2.8%	0.19	2.5 MB	3.5%	0.70
Oct 8 01:00:00 - 01:59:59	497	2.1%	0.14	1.5 MB	2.1%	0.42
Oct 8 02:00:00 - 02:59:59	386	1.6%	0.11	1.2 MB	1.7%	0.35
Oct 8 03:00:00 - 03:59:59	389	1.6%	0.11	1.3 MB	1.8%	0.36
Oct 8 04:00:00 - 04:15:00	127	0.5%	0.14	556.2 KB	0.8%	0.62
TOTAL: 24:00:00	24051	100.0%	0.28	71.1 MB	100.0%	0.84

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	csiph-out.feeder.erje.net	9462	424	15	1	9022
2	newsfeed.neva.ru	5909	1082	8	0	4819
3	csiph-out.news.weretis.net	1325	191	0	0	1134
4	feeder.eternal-september.org	730	68	0	0	662
5	news-out.mixmin.net	681	3	0	0	678
6	newsfeed.fu-berlin.de	681	29	0	0	652
7	news.fcku.it	170	0	0	0	170
8	newsfeeds.xmission.com	64	0	0	0	64
9	nntp.pasdenom.info	62	5	1	0	56
10	news.redatomik.org	50	0	0	0	50
11	news-out.aioe.org	30	20	0	0	10
12	news.freedyn.net	24	0	0	0	24
13	xanadu-bbs.net	10	0	0	0	10
14	news.swapon.de	7	0	0	0	7
TOTAL: 14		19205	1822	24	1	17358

Unwanted newsgroups [Top 20]:

Newsgroup	Count
fa.linux.kernel	620
lada.talk	241
lada.auto	126
ut.test	114
alt.survival	56
fa.freebsd.cvs-all	38
fa.openbsd.source-changes	31
it-alt.sport.calcio.juventus	29
lada.photo	24
mozilla.dev.security.policy	23
fa.openbsd.tech	23
alt.windows7.general	21
mpc.lists.freebsd.ports.bugs	17
mozilla.support.thunderbird	17
lada.fishing	15
alt.english.usage	15
fa.freebsd.stable	15
spline.eisfair	14
fa.philos-l	13
mozilla.dev.platform	12
TOTAL: 158	1822

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

Groups	Count
alt.culture.china	1
TOTAL: 1	1

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	12959
EMP (phn path)	2547
EMP (phl)	684
EMP (phn nph)	117
Binary Payload	73
Too many newsgroups	20
Binary: non-binary distribution	19
User-issued cancel	15
HTML post	15
HTML Multipart	13
Scoring filter (10)	13
Scoring filter (9)	12
Scoring filter (13)	11
Scoring filter (8)	10
Scoring filter (18)	7
Scoring filter (11)	5
Scoring filter (19)	4
Too many newsgroups (low_xpost)	3
Scoring filter (12)	2
Scoring filter (17)	2
TOTAL: 24	16536

NoCeM on Spool:

Id	Good	Bad	Unique	Total
bleachbot@httrack.com	56	0	57	57
TOTAL: 1	56	0	57	57

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	csiph-out.news.weretis.net	118
	feeder.eternal-september.org	95
	newsfeeds.xmission.com	61
	news.fcku.it	25
	news-out.mixmin.net	16
	news.freedyn.net	12
	news.redatomik.org	9
	newsfeed.fu-berlin.de	2
	nntp.pasdenom.info	2
	xanadu-bbs.net	1
	TOTAL: 10	341
Including strange strings
	newsfeed.fu-berlin.de	319
	csiph-out.feeder.erje.net	42
	csiph-out.news.weretis.net	33
	feeder.eternal-september.org	32
	news-out.mixmin.net	18
	news.redatomik.org	16
	news-out.aioe.org	7
	newsfeed.neva.ru	7
	news.swapon.de	5
	newsfeeds.xmission.com	2
	TOTAL: 10	481
TOTAL: 2		822

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	news.bbs.geek.nz	43693	1518	21707	37	1	3%	24:06:38
2	news.freedyn.net	25137	1465	22541	7	0	5%	24:00:26
3	xanadu-bbs	26474	896	23033	29	132	3%	23:59:56
4	fu-berlin.de	22643	734	21907	0	0	3%	24:03:24
5	usenet.pasdenom.info	27106	344	22434	1271	0	1%	23:59:56
6	xmission	27569	135	22264	6	0	0%	23:59:56
7	news.redatomik.org	24406	48	22317	12	0	0%	24:03:32
8	weretis.net	20162	48	18902	2	0	0%	24:09:48
9	aioe	21018	14	20012	2	0	0%	24:09:47
10	news.mixmin.net	22627	5	21108	1	0	0%	24:08:00
11	erje	16001	5	15883	8	0	0%	24:09:21
12	eternal-september	22233	3	19318	0	0	0%	23:59:38
13	news.fcku.it	3101	3	2946	0	0	0%	22:05:11
14	news.swapon.de	1928	2	1810	1	0	0%	24:05:48
15	neva.ru	23729	0	21275	34	0	0%	23:59:41
16	bwh	0	0	0	0	23262	0%	24:07:20
17	au2pb	0	0	0	0	23274	0%	24:07:21
TOTAL: 17		327827	5220	277457	1410	46669	1%	407:15:43

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.freedyn.net	8.5 MB	58.9 KB	8.5 MB	0.1 KB/s	5.9 KB	24:00:26
2	xanadu-bbs	7.1 MB	71.6 KB	7.2 MB	0.1 KB/s	8.0 KB	23:59:56
3	fu-berlin.de	6.7 MB	0.0 KB	6.7 MB	0.1 KB/s	9.4 KB	24:03:24
4	news.bbs.geek.nz	3.7 MB	204.2 KB	3.9 MB	0.0 KB/s	2.5 KB	24:06:38
5	usenet.pasdenom.info	940.0 KB	7.7 MB	8.6 MB	0.1 KB/s	5.5 KB	23:59:56
6	xmission	529.3 KB	20.3 KB	549.6 KB	0.0 KB/s	3.9 KB	23:59:56
7	weretis.net	198.2 KB	35.9 KB	234.1 KB	0.0 KB/s	4.7 KB	24:09:48
8	news.redatomik.org	122.8 KB	26.5 KB	149.3 KB	0.0 KB/s	2.5 KB	24:03:32
9	aioe	45.9 KB	5.5 KB	51.5 KB	0.0 KB/s	3.2 KB	24:09:47
10	news.mixmin.net	27.0 KB	2.0 KB	29.1 KB	0.0 KB/s	4.8 KB	24:08:00
11	erje	12.6 KB	73.5 KB	86.1 KB	0.0 KB/s	6.6 KB	24:09:21
12	eternal-september	9.1 KB	0.0 KB	9.1 KB	0.0 KB/s	3.0 KB	23:59:38
13	news.fcku.it	6.5 KB	0.0 KB	6.5 KB	0.0 KB/s	2.2 KB	22:05:11
14	news.swapon.de	5.2 KB	4.0 KB	9.1 KB	0.0 KB/s	3.0 KB	24:05:48
15	neva.ru	0.0 KB	72.1 KB	72.1 KB	0.0 KB/s	2.1 KB	23:59:41
16	bwh	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	24:07:20
17	au2pb	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	24:07:21
TOTAL: 17		27.8 MB	8.3 MB	36.1 MB	0.0 KB/s	5.6 KB	407:15:43

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Rej	Elapsed
1	tempe0.bbox.io	39	8	41.7 KB	2	0	06:42:42
2	cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	3	3	7.1 KB	1	2	00:07:31
3	challenger.nielsenmedia.com	16	1	4.0 KB	1	0	03:16:38
4	47.192.187.101	7	1	4.0 KB	1	0	01:58:55
5	dhcp-089-099-203-254.chello.nl	64	1	1.1 KB	1	0	11:56:36
6	92-108-162-83.dynamic.upc.nl	2	1	2.0 KB	1	0	01:00:09
TOTAL: 6		131	15	59.9 KB	7	2	28:58:34

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Rej	Elapsed
1	*.bbox.io	39	8	41.7 KB	2	0	06:42:42
2	unresolved	10	1	4.0 KB	1	0	02:02:03
3	*.chello.nl	64	1	1.1 KB	1	0	11:56:36
4	*.nielsenmedia.com	16	1	4.0 KB	1	0	03:16:38
5	*.dynamic.upc.nl	2	1	2.0 KB	1	0	01:00:09
6	*.dhcp.mdsn.wi.charter.com	5	0	0.0 KB	0	0	01:56:12
7	*.2.89.75.dynamic.ip.windstream.net	1	0	0.0 KB	0	0	01:56:39
TOTAL: 7		137	15	59.9 KB	7	2	28:51:03

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
dhcp-089-099-203-254.chello.nl	5.428	1.390	0.000	11:56:36
tempe0.bbox.io	3.369	0.834	0.000	06:42:42
challenger.nielsenmedia.com	1.284	0.359	0.000	03:16:38
47.192.187.101	0.675	0.161	0.000	01:58:55
h114.2.89.75.dynamic.ip.windstream.net	0.074	0.125	0.000	01:56:39
68-185-181-64.dhcp.mdsn.wi.charter.com	0.434	0.108	0.000	01:56:12
92-108-162-83.dynamic.upc.nl	0.246	0.033	0.000	01:00:09
cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	0.391	0.117	0.003	00:07:31
5.51.176.30	0.144	0.077	0.000	00:02:51
196.52.16.27	0.133	0.248	0.000	00:00:16
TOTAL: 10	12.178	3.452	0.003	28:58:34

Curious NNRP server explorers [Top 20]:

System	Conn
68-185-181-64.dhcp.mdsn.wi.charter.com	5
5.51.176.30	2
196.52.16.27	1
h114.2.89.75.dynamic.ip.windstream.net	1
TOTAL: 4	9

NNRP no permission clients:

System	Conn
cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	1
TOTAL: 1	1

NNRP client timeouts [Top 20]:

System	Conn	Peer
tempe0.bbox.io	10	0
challenger.nielsenmedia.com	6	0
47.192.187.101	3	0
68-185-181-64.dhcp.mdsn.wi.charter.com	3	0
92-108-162-83.dynamic.upc.nl	2	0
h114.2.89.75.dynamic.ip.windstream.net	1	0
TOTAL: 6	25	0

Newsgroup request counts (by category):

Category		Count	Pct
1	muc	8	53.3%
2	comp	7	46.7%
TOTAL: 2		15	100.0%

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

Newsgroup		Count
1	muc.lists.freebsd.stable	8
2	comp.lang.pl1	3
3	comp.sys.ibm.ps2.hardware	2
4	comp.lang.awk	2
TOTAL: 4		15

Daily Usenet report for csiph.com

Oct 7 04:15:00 -- Oct 8 04:15:00