Daily Usenet report for csiph.com: Feb 14 04:15:00

Unknown entries from news log file:

First 2 / 2 lines (100.0%)

Feb 14 14:27:30 csiph nnrpd[82406]: unable to get certificate from '/usr/local/news/etc/cert.pem'
Feb 14 14:27:30 csiph nnrpd[82406]: error initializing TLS: [CA_file: ] [CA_path: /usr/local/news/etc] [cert_file: /usr/local/news/etc/cert.pem] [key_file: /usr/local/news/etc/key.pem]

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	43478	60.5%	8.2 MB	71.8%
innd	23704	33.0%	2.5 MB	22.3%
innfeed	3288	4.6%	528.6 KB	4.5%
nnrpd	1309	1.8%	148.1 KB	1.3%
nocem	71	0.1%	7.5 KB	0.1%
controlchan	1	0.0%	0.1 KB	0.0%
TOTAL: 6	71851	100.0%	11.4 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	433819	57.0%
Negative hits	283989	37.3%
Do not exist	42078	5.5%
Cache misses	735	0.1%
TOTAL: 4	760621	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.602	0.0%	223	0.000	2.700	30.500
article cleanup	00:00:00.293	0.0%	42305	0.000	0.007	0.023
article logging	00:00:04.322	0.0%	42883	0.000	0.101	0.714
article parse	00:00:02.202	0.0%	141498	0.003	0.016	0.480
article write	00:03:18.315	0.2%	23859	0.192	8.312	30.788
artlog/artcncl	00:00:00.002	0.0%	178	0.000	0.011	0.125
artlog/artparse	00:00:00.001	0.0%	71	0.000	0.014	1.000
data move	00:00:00.485	0.0%	689402	0.000	0.001	0.029
hisgrep/artcncl	00:00:00.127	0.0%	222	0.000	0.572	16.500
hishave/artcncl	00:00:00.049	0.0%	223	0.000	0.220	8.000
hishave/artparse	00:00:00.000	0.0%	68	0.000	0.000	0.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:02:11.120	0.2%	760723	0.003	0.172	0.975
history sync	00:00:03.094	0.0%	333	0.000	9.291	70.500
history write	00:03:23.751	0.2%	41920	0.123	4.860	35.945
hiswrite/artcncl	00:00:00.002	0.0%	1	2.000	2.000	2.000
hiswrite/artparse	00:00:00.646	0.0%	68	0.000	9.500	55.667
idle	23:33:56.142	98.8%	668656	73.963	126.876	370.415
nntp read	00:00:03.368	0.0%	700126	0.002	0.005	0.047
overview write	00:04:28.346	0.3%	23859	1.751	11.247	101.788
perl filter	00:01:50.395	0.1%	41821	1.257	2.640	5.930
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:00:00.454	0.0%	47779	0.000	0.010	0.033
TOTAL: 23:50:44.059	23:49:23.716	99.9%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.064	0.0%	25228	0.000	0.003	0.032
article prepare	00:00:00.009	0.0%	45926	0.000	0.000	0.005
article read	00:00:03.571	0.0%	8765	0.000	0.407	9.618
backlog stats	00:00:00.264	0.0%	448378	0.000	0.001	0.002
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:02.357	0.0%	341362	0.002	0.007	0.011
data write	00:00:01.988	0.0%	325071	0.001	0.006	0.012
idle	23:54:04.703	100.0%	448378	100.435	191.902	482.475
status file	00:00:00.321	0.0%	327	0.000	0.982	26.000
TOTAL: 23:54:22.256	23:54:13.277	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:09.085	0.0%	11961	0.000	0.760	30.000
idle	78:35:23.845	99.8%	12577	70.000	22495.336	900169.500
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.151	0.0%	25379	0.000	0.006	0.250
readart	00:00:00.927	0.0%	87	0.000	10.655	63.000
TOTAL: 78:44:58.621	78:35:34.008	99.8%	-	-	-	-

Control commands to INND:

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

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	csiph-out.feeder.erje.net	1152	136674	8674	117329	10671	6%	95:01:26
2	feeder.eternal-september.org	4	38886	3813	29466	5607	9%	25:32:31
3	csiph-out.news.weretis.net	5	42790	3734	38523	533	8%	40:57:03
4	news.redatomik.org	1	20857	1594	19262	1	7%	20:54:13
5	newsfeed.neva.ru	145	56238	1433	52158	2647	2%	71:30:21
6	news-out.aioe.org	4	23092	1257	21801	34	5%	24:12:38
7	newsfeed.fu-berlin.de	43	25782	1158	24171	453	4%	34:31:07
8	news-out.mixmin.net	2	26213	767	25279	167	2%	24:08:56
9	newsfeeds.xmission.com	3	21232	607	20607	18	2%	21:23:21
10	news.freedyn.net	3	27052	329	26467	256	1%	24:09:51
11	news.fcku.it	2	9942	248	9619	75	2%	23:59:55
12	xanadu-bbs.net	11	1097	111	978	8	10%	24:46:06
13	news.swapon.de	2	2530	75	2409	46	2%	22:32:55
14	nntp.pasdenom.info	6	22850	58	22780	12	0%	23:54:58
15	news.bbs.geek.nz	1	18005	22	17982	1	0%	23:59:51
16	localhost	46	10	10	0	0	100%	00:00:00
TOTAL: 16		1430	473250	23890	428831	20529	5%	501:35:12

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	csiph-out.feeder.erje.net	27.0 MB	2.1 MB	55.4 MB	84.4 MB	31%	4.5 KB
2	csiph-out.news.weretis.net	10.9 MB	15.9 KB	6.0 MB	17.0 MB	64%	4.1 KB
3	feeder.eternal-september.org	10.5 MB	2.4 MB	72.7 MB	85.5 MB	12%	9.3 KB
4	news.redatomik.org	4.1 MB	0.0 KB	0.8 KB	4.1 MB	99%	2.6 KB
5	newsfeed.neva.ru	4.1 MB	386.3 KB	24.5 MB	28.9 MB	14%	7.3 KB
6	news-out.mixmin.net	3.9 MB	0.0 KB	1.2 MB	5.1 MB	76%	5.6 KB
7	news-out.aioe.org	3.5 MB	0.0 KB	45.4 KB	3.5 MB	98%	2.8 KB
8	newsfeed.fu-berlin.de	2.4 MB	0.0 KB	1.2 MB	3.6 MB	67%	2.3 KB
9	newsfeeds.xmission.com	1.9 MB	7.7 KB	420.9 KB	2.3 MB	81%	3.7 KB
10	news.freedyn.net	1.4 MB	0.0 KB	2.6 MB	4.0 MB	35%	7.0 KB
11	news.fcku.it	439.2 KB	0.0 KB	182.6 KB	621.8 KB	70%	1.9 KB
12	xanadu-bbs.net	225.9 KB	0.0 KB	38.1 KB	264.0 KB	85%	2.2 KB
13	news.swapon.de	209.9 KB	0.0 KB	415.3 KB	625.1 KB	33%	5.2 KB
14	nntp.pasdenom.info	147.8 KB	0.0 KB	24.8 KB	172.6 KB	85%	2.5 KB
15	news.bbs.geek.nz	45.1 KB	0.0 KB	1.8 KB	46.9 KB	96%	2.0 KB
16	localhost	12.1 KB	0.0 KB	0.0 KB	12.1 KB	100%	1.2 KB
TOTAL: 16		70.7 MB	4.8 MB	164.6 MB	240.1 MB	29%	5.5 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Feb 14 04:15:00 - 04:59:59	331	1.4%	0.12	1.2 MB	1.6%	0.44
Feb 14 05:00:00 - 05:59:59	585	2.4%	0.16	2.1 MB	3.0%	0.60
Feb 14 06:00:00 - 06:59:59	691	2.9%	0.19	2.4 MB	3.3%	0.68
Feb 14 07:00:00 - 07:59:59	784	3.3%	0.22	2.6 MB	3.7%	0.74
Feb 14 08:00:00 - 08:59:59	985	4.1%	0.27	2.9 MB	4.1%	0.83
Feb 14 09:00:00 - 09:59:59	1052	4.4%	0.29	3.4 MB	4.8%	0.98
Feb 14 10:00:00 - 10:59:59	953	4.0%	0.26	2.4 MB	3.3%	0.68
Feb 14 11:00:00 - 11:59:59	985	4.1%	0.27	2.5 MB	3.5%	0.71
Feb 14 12:00:00 - 12:59:59	948	4.0%	0.26	2.7 MB	3.8%	0.77
Feb 14 13:00:00 - 13:59:59	1208	5.0%	0.34	3.3 MB	4.6%	0.93
Feb 14 14:00:00 - 14:59:59	1185	5.0%	0.33	3.1 MB	4.4%	0.89
Feb 14 15:00:00 - 15:59:59	1301	5.4%	0.36	3.6 MB	5.0%	1.01
Feb 14 16:00:00 - 16:59:59	1428	6.0%	0.40	4.1 MB	5.8%	1.16
Feb 14 17:00:00 - 17:59:59	1501	6.3%	0.42	4.2 MB	5.8%	1.18
Feb 14 18:00:00 - 18:59:59	1492	6.2%	0.41	4.1 MB	5.8%	1.17
Feb 14 19:00:00 - 19:59:59	1474	6.2%	0.41	4.7 MB	6.6%	1.34
Feb 14 20:00:00 - 20:59:59	1354	5.7%	0.38	4.6 MB	6.4%	1.30
Feb 14 21:00:00 - 21:59:59	1296	5.4%	0.36	3.8 MB	5.4%	1.09
Feb 14 22:00:00 - 22:59:59	1083	4.5%	0.30	3.2 MB	4.4%	0.90
Feb 14 23:00:00 - 23:59:59	829	3.5%	0.23	2.6 MB	3.6%	0.74
Feb 15 00:00:00 - 00:59:59	714	3.0%	0.20	2.2 MB	3.2%	0.64
Feb 15 01:00:00 - 01:59:59	594	2.5%	0.17	1.8 MB	2.5%	0.50
Feb 15 02:00:00 - 02:59:59	506	2.1%	0.14	1.6 MB	2.2%	0.45
Feb 15 03:00:00 - 03:59:59	542	2.3%	0.15	1.9 MB	2.7%	0.54
Feb 15 04:00:00 - 04:15:00	103	0.4%	0.11	328.4 KB	0.5%	0.36
TOTAL: 24:00:00	23924	100.0%	0.28	71.2 MB	100.0%	0.84

Sites sending bad articles:

Server		Total	Group	Duplic	Other
1	csiph-out.feeder.erje.net	9059	425	171	8463
2	feeder.eternal-september.org	5550	45	184	5321
3	newsfeed.neva.ru	2682	246	31	2405
4	newsfeed.fu-berlin.de	794	22	0	772
5	csiph-out.news.weretis.net	654	126	1	527
6	news.freedyn.net	256	17	0	239
7	news-out.mixmin.net	165	2	0	163
8	news.fcku.it	78	0	0	78
9	news-out.aioe.org	39	33	0	6
10	news.swapon.de	35	0	0	35
11	newsfeeds.xmission.com	29	10	1	18
12	news.redatomik.org	16	0	0	16
13	nntp.pasdenom.info	13	8	0	5
14	xanadu-bbs.net	6	0	0	6
TOTAL: 14		19376	934	388	18054

Unwanted newsgroups [Top 20]:

Newsgroup	Count
ut.test	143
lada.talk	85
lada.auto	66
it-alt.sport.calcio.juventus	63
it.annunci.varie	56
it.annunci.commerciali	54
it.annunci.immobiliari	54
mozilla.support.firefox	20
alt.windows7.general	19
gmane.linux.alsa.devel	15
mozilla.support.seamonkey	15
oesterreich.tratsch	13
alt.computer.workshop	13
mpc.lists.nanog	11
alt.english.usage	11
lada.commerce	10
mozilla.dev.security.policy	9
mozilla.dev.platform	9
mozilla.general	9
alt.philosophy	9
TOTAL: 132	934

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	14574
EMP (phn path)	1732
EMP (phl)	580
EMP (phn nph)	126
Too many newsgroups	84
Binary Payload	42
Scoring filter (8)	26
Scoring filter (11)	21
User-issued cancel	17
Scoring filter (12)	16
Scoring filter (14)	16
HTML Multipart	16
Scoring filter (13)	15
Scoring filter (16)	11
Scoring filter (9)	10
Scoring filter (10)	9
Too many newsgroups (meow)	2
HTML post	1
Scoring filter (19)	1
Scoring filter (23)	1
TOTAL: 26	17306

NoCeM on Spool:

Id	Good	Bad	Unique	Total
bleachbot@httrack.com	61	0	67	67
TOTAL: 1	61	0	67	67

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Article posted in the future
	csiph-out.feeder.erje.net	96
	TOTAL: 1	96
Huge articles
	csiph-out.news.weretis.net	26
	news-out.mixmin.net	14
	feeder.eternal-september.org	11
	news.freedyn.net	7
	newsfeeds.xmission.com	6
	newsfeed.fu-berlin.de	2
	news.fcku.it	1
	news.redatomik.org	1
	TOTAL: 8	68
Including strange strings
	newsfeed.fu-berlin.de	373
	csiph-out.feeder.erje.net	96
	feeder.eternal-september.org	37
	news.swapon.de	21
	news.redatomik.org	14
	newsfeeds.xmission.com	12
	csiph-out.news.weretis.net	10
	news-out.aioe.org	5
	newsfeed.neva.ru	4
	news-out.mixmin.net	4
	TOTAL: 12	581
No colon-space in header
	csiph-out.feeder.erje.net	2
	TOTAL: 1	2
TOTAL: 4		747

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Miss	Spool	%Took	Elapsed
1	news.bbs.geek.nz	38795	7010	16181	98	0	4	18%	23:52:59
2	news.freedyn.net	24474	743	22825	1	0	0	3%	23:56:24
3	xanadu-bbs	27027	705	23089	23	0	78	2%	23:59:56
4	fu-berlin.de	22560	560	22000	0	0	0	2%	23:59:52
5	usenet.pasdenom.info	27342	538	22184	1140	1	1263	1%	23:59:56
6	erje	15824	304	14747	39	0	0	1%	23:55:57
7	xmission	27142	139	22395	4	0	5	0%	23:59:56
8	aioe	21456	59	19742	10	0	0	0%	23:50:02
9	news.redatomik.org	22500	37	21550	8	0	0	0%	23:57:16
10	eternal-september	21331	13	19267	0	0	0	0%	23:59:47
11	news.mixmin.net	22665	11	21674	0	0	0	0%	23:59:56
12	weretis.net	19051	11	18224	0	0	0	0%	23:50:02
13	news.swapon.de	2296	7	2199	3	0	0	0%	23:54:30
14	neva.ru	23086	5	21479	11	0	0	0%	23:59:16
15	news.fcku.it	2500	1	2425	0	0	0	0%	22:54:40
16	au2pb	0	0	0	0	0	23342	0%	23:58:43
17	bwh	0	0	0	0	0	23269	0%	23:50:10
TOTAL: 17		318049	10143	269981	1337	1	47961	3%	405:59:22

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	news.bbs.geek.nz	18.4 MB	453.7 KB	18.8 MB	0.2 KB/s	2.7 KB	23:52:59
2	news.freedyn.net	5.9 MB	1.8 KB	6.0 MB	0.1 KB/s	8.2 KB	23:56:24
3	xanadu-bbs	5.7 MB	58.5 KB	5.8 MB	0.1 KB/s	8.2 KB	23:59:56
4	fu-berlin.de	5.4 MB	0.0 KB	5.4 MB	0.1 KB/s	9.8 KB	23:59:52
5	usenet.pasdenom.info	1.6 MB	6.5 MB	8.1 MB	0.1 KB/s	4.9 KB	23:59:56
6	erje	923.9 KB	194.7 KB	1.1 MB	0.0 KB/s	3.3 KB	23:55:57
7	xmission	298.2 KB	5.9 KB	304.1 KB	0.0 KB/s	2.1 KB	23:59:56
8	aioe	133.3 KB	29.1 KB	162.4 KB	0.0 KB/s	2.4 KB	23:50:02
9	news.redatomik.org	83.6 KB	41.9 KB	125.4 KB	0.0 KB/s	2.8 KB	23:57:16
10	news.mixmin.net	23.5 KB	0.0 KB	23.5 KB	0.0 KB/s	2.1 KB	23:59:56
11	eternal-september	19.0 KB	0.0 KB	19.0 KB	0.0 KB/s	1.5 KB	23:59:47
12	weretis.net	16.7 KB	0.0 KB	16.7 KB	0.0 KB/s	1.5 KB	23:50:02
13	news.swapon.de	8.2 KB	3.9 KB	12.1 KB	0.0 KB/s	1.2 KB	23:54:30
14	neva.ru	6.3 KB	26.5 KB	32.8 KB	0.0 KB/s	2.0 KB	23:59:16
15	news.fcku.it	1.0 KB	0.0 KB	1.0 KB	0.0 KB/s	1.0 KB	22:54:40
16	au2pb	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:58:43
17	bwh	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	23:50:10
TOTAL: 17		38.5 MB	7.3 MB	45.8 MB	0.0 KB/s	4.1 KB	405:59:22

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	194-73-239-109.cust.centrio.cz	13	28	50.7 KB	7	0	0	03:51:22
2	dhcp-089-099-203-254.chello.nl	33	20	26.3 KB	5	0	0	07:48:08
3	1.126.48.5	1	11	16.5 KB	1	0	0	00:03:20
4	tempe0.bbox.io	24	10	12.1 KB	4	1	1	06:54:18
5	68-185-181-64.dhcp.mdsn.wi.charter.com	22	10	12.1 KB	10	9	7	06:12:20
6	cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	1	8	35.1 KB	3	0	0	00:01:52
TOTAL: 6		94	87	152.9 KB	30	10	8	78:44:56

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Rej	Elapsed
1	*.cust.centrio.cz	13	28	50.7 KB	7	0	0	03:51:22
2	*.chello.nl	33	20	26.3 KB	5	0	0	07:48:08
3	unresolved	110	11	16.5 KB	1	0	0	49:53:41
4	*.bbox.io	24	10	12.1 KB	4	1	1	06:54:18
5	*.dhcp.mdsn.wi.charter.com	22	10	12.1 KB	10	9	7	06:12:20
6	*.19-1.cable.virginm.net	1	8	35.1 KB	3	0	0	00:01:52
7	*.24.19.98.dynamic.ip.windstream.net	2	0	0.0 KB	0	0	0	04:03:12
TOTAL: 7		205	87	152.9 KB	30	10	8	78:44:56

NNRP auth users [Top 20]:

User	Conn
ctomczyk	10
ohlandl	7
moussa	1
kev009	1
TOTAL: 4	19

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
216.239.174.218	7.476	1.605	0.000	49:27:36
dhcp-089-099-203-254.chello.nl	2.800	0.474	0.000	07:48:08
tempe0.bbox.io	2.026	0.426	0.008	06:54:18
68-185-181-64.dhcp.mdsn.wi.charter.com	2.032	0.333	0.050	06:12:20
h240.24.19.98.dynamic.ip.windstream.net	0.217	0.305	0.000	04:03:12
194-73-239-109.cust.centrio.cz	1.242	0.235	0.037	03:51:22
5.51.176.30	0.760	0.608	0.000	00:22:39
1.126.48.5	0.091	0.015	0.003	00:03:20
cpc8-smal14-2-0-cust979.19-1.cable.virginm.net	0.103	0.048	0.000	00:01:52
118.193.90.132	0.207	0.032	0.000	00:00:04
TOTAL: 10	16.954	4.081	0.098	78:44:56

Curious NNRP server explorers [Top 20]:

System	Conn
216.239.174.218	100
5.51.176.30	6
118.193.90.132	3
h240.24.19.98.dynamic.ip.windstream.net	2
TOTAL: 4	111

NNRP unrecognized commands (by host):

System	Conn
118.193.90.132	2
TOTAL: 1	2

NNRP unrecognized commands (by command):

Command	Count
^V^C^A^A"^A	1
À/À+À'À#À^SÀ\x09	1
TOTAL: 2	2

NNRP client timeouts [Top 20]:

System	Conn	Peer
216.239.174.218	97	0
tempe0.bbox.io	11	0
194-73-239-109.cust.centrio.cz	7	0
68-185-181-64.dhcp.mdsn.wi.charter.com	5	0
118.193.90.132	2	3
TOTAL: 5	122	3

Newsgroup request counts (by category):

Category		Count	Pct
1	comp	87	100.0%
TOTAL: 1		87	100.0%

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

Newsgroup		Count
1	comp.sys.ibm.ps2.hardware	54
2	comp.lang.javascript	28
3	comp.lang.pl1	3
4	comp.sys.raspberry-pi	2
TOTAL: 4		87

Daily Usenet report for csiph.com

Feb 14 04:15:00 -- Feb 15 04:15:00