Daily Usenet report: Jun 15 04:15:05

Unknown entries from news log file:

First 4 / 4 lines (100.0%)

Jun 15 11:11:05 newsfeed controlchan[3835]: control_checkgroups, ^.*$ !ka.lists #20130615 usenet@karlsruhe.org usenet@karlsruhe.org @0304425546303500000007894E4900000065@, , , utf-8, news.task.gda.pl, mail, 1
Jun 15 11:11:05 newsfeed controlchan[3835]: control_checkgroups, ^.*$ !ka.lists #20130615 usenet@karlsruhe.org usenet@karlsruhe.org @0304425546303500000007894E4900000065@, ^.*$, , utf-8, news.task.gda.pl, drop, -1
Jun 15 17:00:10 newsfeed pgpverify[27052]: pgpverify: verification failed
Jun 15 17:03:17 newsfeed nnrpd[27066]: SERVER perl filter not defined

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	2308130	98.2%	261.0 MB	97.8%
innd	25840	1.1%	4.0 MB	1.5%
nnrpd	8532	0.4%	891.9 KB	0.3%
innfeed	6775	0.3%	1.0 MB	0.4%
controlchan	5	0.0%	0.8 KB	0.0%
pgpverify	1	0.0%	0.1 KB	0.0%
TOTAL: 6	2349283	100.0%	266.9 MB	100.0%

History cache:

Reason	Count	%Count
Do not exist	2298326	94.1%
Negative hits	79491	3.3%
Positive hits	60967	2.5%
Cache misses	3953	0.2%
TOTAL: 4	2442737	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:18:06.462	1.3%	26186	0.000	41.490	484.000
article cleanup	00:00:29.574	0.0%	2281874	0.004	0.013	0.155
article logging	00:01:19.037	0.1%	2282031	0.014	0.035	0.750
article parse	01:09:06.568	4.8%	56886038	0.031	0.073	0.235
article write	00:30:27.072	2.1%	2264869	0.407	0.807	6.410
artlog/artcncl	00:00:00.757	0.0%	25741	0.000	0.029	7.917
artlog/artparse	00:00:00.000	0.0%	5	0.000	0.000	0.000
data move	00:02:15.820	0.2%	68739014	0.001	0.002	0.014
hisgrep/artcncl	00:01:24.500	0.1%	3517	0.000	24.026	880.000
hishave/artcncl	00:05:23.252	0.4%	26186	0.000	12.344	278.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	06:03:34.510	25.3%	2417146	0.014	9.025	22.098
history sync	00:00:00.012	0.0%	291	0.000	0.041	1.000
history write	06:55:11.168	28.8%	2276026	0.151	10.945	48.048
hiswrite/artcncl	00:05:05.343	0.4%	22669	0.000	13.470	75.298
idle	02:06:36.961	8.8%	17384773	0.164	0.437	15.581
nntp read	00:33:04.975	2.3%	54905410	0.022	0.036	0.082
overview write	00:00:15.020	0.0%	2264869	0.000	0.007	0.097
perl filter	05:56:08.527	24.7%	2276021	6.373	9.389	18.074
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:07:13.845	0.5%	4585400	0.009	0.095	0.773
TOTAL: 23:59:40.654	23:55:43.403	99.7%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.235	0.0%	55973	0.000	0.004	0.154
article prepare	00:00:00.031	0.0%	90324	0.000	0.000	0.250
article read	00:00:35.765	0.0%	22411	0.000	1.596	346.800
backlog stats	00:00:00.362	0.0%	388068	0.000	0.001	0.242
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:03.347	0.0%	220508	0.000	0.015	3.087
data write	00:00:16.345	0.0%	213626	0.000	0.077	45.000
idle	23:58:57.054	99.9%	388068	0.000	222.479	14069.000
status file	00:00:05.248	0.0%	224	0.500	23.429	284.000
TOTAL: 24:00:10.917	23:59:58.387	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
hisgrep	00:00:55.282	0.0%	5305	9.356	10.421	11.312
idle	41:45:17.125	99.9%	71382	0.000	2105.813	162397.250
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:05.224	0.0%	144682	0.000	0.036	2.000
readart	00:00:05.487	0.0%	449	0.000	12.220	310.000
TOTAL: 41:47:21.042	41:46:23.118	100.0%	-	-	-	-

Control commands to INND:

Command	Number
L	1
flush	24
flushlogs	2
go	2
logmode	2
mode	149
name	2
pause	2
paused	2
reload	2
reserve	2
TOTAL: 11	190

Control Channel:

Sender	newgroup	rmgroup	Other	Bad PGP	DoIt	OK
group-admin@isc.org	0	0	0	1	0	0
TOTAL	0	0	0	1	0	0

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	newsfeed.pionier.net.pl	228	2267937	2251310	1921	14706	99%	545:57:28
2	news.nask.pl	3	17196	7175	8612	1409	41%	23:43:58
3	news.task.gda.pl	11	47873	5946	41159	768	12%	42:28:29
4	news.icm.edu.pl	36	433	11	329	93	2%	20:40:37
5	localhost	2	1	1	0	0	100%	00:00:02
TOTAL: 5		280	2333440	2264443	52021	16976	97%	632:50:34

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	newsfeed.pionier.net.pl	745.8 GB	191.2 MB	1.7 GB	747.7 GB	99%	346.0 KB
2	news.nask.pl	233.2 MB	20.5 MB	21.0 MB	274.6 MB	84%	32.8 KB
3	news.task.gda.pl	10.9 MB	120.8 KB	2.0 MB	13.0 MB	83%	2.0 KB
4	news.icm.edu.pl	215.5 KB	146.7 KB	2.9 MB	3.3 MB	6%	32.2 KB
5	localhost	1.8 KB	0.0 KB	0.0 KB	1.8 KB	100%	1.8 KB
TOTAL: 5		746.0 GB	212.0 MB	1.7 GB	748.0 GB	99%	343.8 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Jun 15 04:15:05 - 04:59:59	48678	2.1%	18.06	15.6 GB	2.1%	6061.84
Jun 15 05:00:00 - 05:59:59	94349	4.2%	26.21	30.2 GB	4.0%	8796.86
Jun 15 06:00:00 - 06:59:59	92550	4.1%	25.71	29.7 GB	4.0%	8649.83
Jun 15 07:00:00 - 07:59:59	82030	3.6%	22.79	27.2 GB	3.6%	7933.29
Jun 15 08:00:00 - 08:59:59	97216	4.3%	27.00	32.8 GB	4.4%	9541.46
Jun 15 09:00:00 - 09:59:59	99914	4.4%	27.75	30.9 GB	4.1%	9010.97
Jun 15 10:00:00 - 10:59:59	102510	4.5%	28.48	31.7 GB	4.2%	9227.34
Jun 15 11:00:00 - 11:59:59	102686	4.5%	28.52	32.6 GB	4.4%	9489.91
Jun 15 12:00:00 - 12:59:59	92847	4.1%	25.79	30.2 GB	4.0%	8794.83
Jun 15 13:00:00 - 13:59:59	92681	4.1%	25.74	30.8 GB	4.1%	8960.17
Jun 15 14:00:00 - 14:59:59	102854	4.5%	28.57	33.6 GB	4.5%	9787.61
Jun 15 15:00:00 - 15:59:59	100761	4.4%	27.99	34.9 GB	4.7%	10179.47
Jun 15 16:00:00 - 16:59:59	99898	4.4%	27.75	35.5 GB	4.8%	10325.60
Jun 15 17:00:00 - 17:59:59	110184	4.9%	30.61	32.9 GB	4.4%	9589.52
Jun 15 18:00:00 - 18:59:59	98333	4.3%	27.31	34.6 GB	4.6%	10090.79
Jun 15 19:00:00 - 19:59:59	92323	4.1%	25.65	34.0 GB	4.6%	9917.52
Jun 15 20:00:00 - 20:59:59	112204	5.0%	31.17	32.6 GB	4.4%	9500.63
Jun 15 21:00:00 - 21:59:59	110584	4.9%	30.72	34.5 GB	4.6%	10041.81
Jun 15 22:00:00 - 22:59:59	82295	3.6%	22.86	28.2 GB	3.8%	8224.73
Jun 15 23:00:00 - 23:59:59	97272	4.3%	27.02	28.5 GB	3.8%	8309.53
Jun 16 00:00:00 - 00:59:59	90813	4.0%	25.23	28.5 GB	3.8%	8303.17
Jun 16 01:00:00 - 01:59:59	87130	3.8%	24.20	32.9 GB	4.4%	9579.83
Jun 16 02:00:00 - 02:59:59	89205	3.9%	24.78	31.2 GB	4.2%	9085.61
Jun 16 03:00:00 - 03:59:59	69140	3.1%	19.21	26.3 GB	3.5%	7652.73
Jun 16 04:00:00 - 04:15:04	16758	0.7%	18.54	6.3 GB	0.8%	7261.92
TOTAL: 23:59:59	2265215	100.0%	26.22	746.2 GB	100.0%	9056.55

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	newsfeed.pionier.net.pl	14848	212	4513	3	10120
2	news.nask.pl	1423	139	1246	0	38
3	news.task.gda.pl	804	536	89	1	178
4	news.icm.edu.pl	93	0	6	0	87
TOTAL: 4		17168	887	5854	4	10423

Unwanted newsgroups [Top 20]:

Newsgroup	Count
alt.sex.telephones	126
uk.railway	95
mailing.freebsd.ports-bugs	76
mailing.freebsd.svn-ports-all	51
mailing.freebsd.svn-ports-head	51
mailing.freebsd.svn-src-all	33
mailing.freebsd.svn-src-head	33
fa.freebsd.cvs-all	30
mailing.openbsd.source-changes	29
mailing.openbsd.ports-changes	29
uk.rec.cycling.moderated	25
alt.windows7.general	24
it.tlc.cellulari.android	21
mozilla.dev.tree-management	21
comp.sys.raspberry-pi	18
alt.politics.scorched-earth	17
mailing.freebsd.current	15
mailing.unix.dovecot	15
mailing.gcc.gcc-cvs	14
mailing.postfix.users	13
TOTAL: 60	887

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

Groups	Count
pl.sci.historia	3
christnet.writers	1
TOTAL: 2	4

INND Perl filter [Top 20]:

Reason	Count
Binary in non-binary group	9861
EMP (fsl)	157
EMP (md5)	91
HTML post	81
Attached HTML file	60
Scoring filter (10)	7
Cancel in forbidden group	4
TOTAL: 7	10261

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	icm	64831	7554	33163	11115	297	11%	24:09:33
2	panorama	56370	2856	51348	892	0	5%	23:52:25
3	task	1555	147	798	9	7	9%	20:39:45
4	poznan	13550	28	11861	33	0	0%	23:58:35
5	nask	14839	6	12617	1	0	0%	24:00:03
6	okapi	0	0	0	0	2027	0%	24:00:00
TOTAL: 6		151145	10591	109787	12050	2331	7%	140:40:21

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	icm	1.2 GB	3.8 GB	5.0 GB	60.8 KB/s	283.5 KB	24:09:33
2	panorama	14.9 MB	8.7 MB	23.5 MB	0.3 KB/s	6.4 KB	23:52:25
3	task	349.7 KB	16.3 KB	366.1 KB	0.0 KB/s	2.3 KB	20:39:45
4	poznan	210.2 KB	86.9 KB	297.1 KB	0.0 KB/s	4.9 KB	23:58:35
5	nask	10.7 KB	406.8 KB	417.5 KB	0.0 KB/s	59.6 KB	24:00:03
6	okapi	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	24:00:00
TOTAL: 6		1.2 GB	3.9 GB	5.1 GB	10.5 KB/s	234.9 KB	140:40:21

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Elapsed
1	vegas.cm.p.lodz.pl	288	288	573.8 KB	288	0	00:00:16
2	212.191.78.190	157	125	219.0 KB	22	1	24:13:08
3	web.man.lodz.pl	288	36	41.0 KB	18	0	00:00:26
TOTAL: 3		733	449	833.7 KB	328	1	41:47:20

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Elapsed
1	*.cm.p.lodz.pl	288	288	573.8 KB	288	0	00:00:16
2	unresolved	157	125	219.0 KB	22	1	24:13:08
3	*.man.lodz.pl	672	36	41.0 KB	18	0	00:00:42
4	*.181.14.62.static.jazztel.es	10	0	0.0 KB	0	0	17:32:42
5	*.toya.net.pl	35	0	0.0 KB	0	0	00:00:30
TOTAL: 5		1162	449	833.7 KB	328	1	41:47:20

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Elapsed
212.191.78.190	0.892	9.900	24:13:08
144.181.14.62.static.jazztel.es	8.536	20.132	17:32:42
staticline41435.toya.net.pl	0.224	3.180	00:00:30
web.man.lodz.pl	2.236	28.540	00:00:26
vegas.cm.p.lodz.pl	1.576	19.424	00:00:16
f-oper-v100.man.lodz.pl	1.572	20.540	00:00:08
david.man.lodz.pl	0.304	3.396	00:00:06
TOTAL: 7	15.340	105.112	41:47:20

Curious NNRP server explorers [Top 20]:

System	Conn
f-oper-v100.man.lodz.pl	288
david.man.lodz.pl	96
staticline41435.toya.net.pl	35
144.181.14.62.static.jazztel.es	10
TOTAL: 4	429

NNRP client timeouts [Top 20]:

System	Conn	Peer
144.181.14.62.static.jazztel.es	3	0
TOTAL: 1	3	0

Newsgroup request counts (by category):

Category		Count	Pct
1	lodman	288	64.1%
2	pl	161	35.9%
TOTAL: 2		449	100.0%

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

Newsgroup		Count
1	lodman.info	288
2	pl.misc.kolej	40
3	pl.regionalne.warszawa	37
4	pl.rec.rowery	29
5	pl.comp.os.ms-windows.winnt	24
6	pl.comp.pecet	12
7	pl.regionalne.lodz	10
8	pl.soc.prawo	4
9	pl.praca.dyskusje	4
10	pl.rec.gory	1
TOTAL: 10		449

Daily Usenet report

Jun 15 04:15:05 -- Jun 16 04:15:04