Daily Usenet report: Oct 28 04:15:02

Unknown entries from news log file:

First 12 / 12 lines (100.0%)

Oct 28 07:56:43 newsfeed nnrpd[6428]: SERVER perl filter not defined
Oct 28 07:57:24 newsfeed nnrpd[6434]: SERVER perl filter not defined
Oct 28 08:07:16 newsfeed nnrpd[6813]: SERVER perl filter not defined
Oct 28 08:10:18 newsfeed nnrpd[6892]: SERVER perl filter not defined
Oct 28 08:27:53 newsfeed nnrpd[7520]: SERVER perl filter not defined
Oct 28 10:11:39 newsfeed nnrpd[11182]: SERVER perl filter not defined
Oct 28 11:22:59 newsfeed nnrpd[13680]: SERVER perl filter not defined
Oct 28 11:42:07 newsfeed nnrpd[14382]: SERVER perl filter not defined
Oct 28 12:29:27 newsfeed nnrpd[16096]: SERVER perl filter not defined
Oct 28 13:07:13 newsfeed nnrpd[17493]: SERVER perl filter not defined
Oct 28 15:24:57 newsfeed nnrpd[22313]: SERVER perl filter not defined
Oct 28 19:15:54 newsfeed nnrpd[30535]: SERVER perl filter not defined

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	3249583	98.7%	373.3 MB	98.4%
innd	34089	1.0%	5.0 MB	1.3%
nnrpd	4923	0.1%	510.4 KB	0.1%
innfeed	4777	0.1%	656.8 KB	0.2%
TOTAL: 4	3293372	100.0%	379.4 MB	100.0%

History cache:

Reason	Count	%Count
Do not exist	3243608	96.8%
Negative hits	93364	2.8%
Positive hits	13143	0.4%
Cache misses	109	0.0%
TOTAL: 4	3350224	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:03.199	0.0%	155	0.000	20.639	1238.000
article cleanup	00:00:51.697	0.1%	3249150	0.008	0.016	0.034
article logging	00:01:58.782	0.1%	3249803	0.019	0.037	1.266
article parse	01:23:06.663	5.8%	170677191	0.016	0.029	0.065
article write	00:30:21.243	2.1%	3235000	0.309	0.563	4.145
artlog/artcncl	00:00:00.003	0.0%	155	0.000	0.019	0.500
data move	00:03:38.984	0.3%	189260886	0.001	0.001	0.016
hisgrep/artcncl	00:00:00.196	0.0%	138	0.000	1.420	19.000
hishave/artcncl	00:00:00.025	0.0%	155	0.000	0.161	1.000
history grep	00:00:00.000	0.0%	0	0.000	0.000	0.000
history lookup	00:28:38.565	2.0%	3352698	0.116	0.513	7.404
history sync	00:00:00.015	0.0%	290	0.000	0.052	1.000
history write	00:41:09.502	2.9%	3245882	0.223	0.761	9.664
hiswrite/artcncl	00:00:00.013	0.0%	17	0.000	0.765	8.000
idle	12:35:45.538	52.5%	98071569	0.319	0.462	2.062
nntp read	01:08:25.585	4.8%	167895190	0.016	0.024	0.039
overview write	00:00:20.312	0.0%	3235000	0.001	0.006	0.013
perl filter	06:16:31.539	26.1%	3245882	5.022	6.960	9.839
python filter	00:00:00.000	0.0%	0	0.000	0.000	0.000
site send	00:05:34.935	0.4%	6505099	0.036	0.051	0.085
TOTAL: 24:00:10.991	23:16:26.796	97.0%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.161	0.0%	44066	0.000	0.004	0.250
article prepare	00:00:00.015	0.0%	56536	0.000	0.000	0.018
article read	00:00:09.509	0.0%	13533	0.000	0.703	263.000
backlog stats	00:00:00.198	0.0%	222162	0.000	0.001	0.075
callbacks	00:00:00.001	0.0%	197	0.000	0.005	0.012
data read	00:00:01.679	0.0%	113489	0.000	0.015	0.500
data write	00:00:10.739	0.0%	107635	0.000	0.100	0.462
idle	23:59:29.653	100.0%	222162	19.378	388.769	12039.600
status file	00:00:00.832	0.0%	1034	0.000	0.805	7.000
TOTAL: 23:59:59.545	23:59:52.787	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	00:32:09.112	99.1%	3229	0.000	597.433	600141.667
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.418	0.0%	7245	0.000	0.058	5.295
readart	00:00:00.109	0.0%	141	0.000	0.773	10.143
TOTAL: 00:32:26.011	00:32:09.639	99.2%	-	-	-	-

Control commands to INND:

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

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	newsfeed.pionier.net.pl	971	3235283	3224384	7005	3894	99%	438:36:19
2	news.nask.pl	2	22976	10111	2650	10215	44%	24:00:19
3	localhost	13	12	12	0	0	100%	00:00:00
4	news.icm.edu.pl	41	202	11	191	0	5%	13:32:17
TOTAL: 4		1027	3258473	3234518	9846	14109	99%	476:08:55

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	newsfeed.pionier.net.pl	913.4 GB	68.1 MB	169.6 MB	913.6 GB	99%	296.8 KB
2	news.nask.pl	56.5 MB	1.2 MB	148.7 MB	206.4 MB	27%	10.4 KB
3	news.icm.edu.pl	307.0 KB	0.0 KB	0.0 KB	307.0 KB	100%	27.9 KB
4	localhost	22.7 KB	0.0 KB	0.0 KB	22.7 KB	100%	1.9 KB
TOTAL: 4		913.4 GB	69.4 MB	318.3 MB	913.8 GB	99%	295.0 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Oct 28 04:15:02 - 04:59:59	106286	3.3%	39.39	26.3 GB	2.9%	10213.80
Oct 28 05:00:00 - 05:59:59	164954	5.1%	45.82	41.1 GB	4.5%	11978.37
Oct 28 06:00:00 - 06:59:59	166432	5.1%	46.23	41.3 GB	4.5%	12031.73
Oct 28 07:00:00 - 07:59:59	165599	5.1%	46.00	41.6 GB	4.6%	12125.63
Oct 28 08:00:00 - 08:59:59	155291	4.8%	43.14	40.8 GB	4.5%	11888.01
Oct 28 09:00:00 - 09:59:59	149738	4.6%	41.59	40.6 GB	4.5%	11836.52
Oct 28 10:00:00 - 10:59:59	144954	4.5%	40.27	38.9 GB	4.3%	11317.30
Oct 28 11:00:00 - 11:59:59	149582	4.6%	41.55	40.8 GB	4.5%	11871.80
Oct 28 12:00:00 - 12:59:59	150654	4.7%	41.85	40.0 GB	4.4%	11662.52
Oct 28 13:00:00 - 13:59:59	150555	4.7%	41.82	40.6 GB	4.4%	11828.24
Oct 28 14:00:00 - 14:59:59	152450	4.7%	42.35	41.3 GB	4.5%	12031.57
Oct 28 15:00:00 - 15:59:59	153595	4.7%	42.67	39.9 GB	4.4%	11633.00
Oct 28 16:00:00 - 16:59:59	135639	4.2%	37.68	38.1 GB	4.2%	11103.10
Oct 28 17:00:00 - 17:59:59	124494	3.8%	34.58	37.5 GB	4.1%	10926.62
Oct 28 18:00:00 - 18:59:59	128404	4.0%	35.67	39.1 GB	4.3%	11396.92
Oct 28 19:00:00 - 19:59:59	123075	3.8%	34.19	36.6 GB	4.0%	10666.27
Oct 28 20:00:00 - 20:59:59	130985	4.0%	36.38	36.5 GB	4.0%	10636.99
Oct 28 21:00:00 - 21:59:59	98879	3.1%	27.47	31.7 GB	3.5%	9233.64
Oct 28 22:00:00 - 22:59:59	105039	3.2%	29.18	32.9 GB	3.6%	9595.37
Oct 28 23:00:00 - 23:59:59	118143	3.7%	32.82	36.1 GB	4.0%	10503.20
Oct 29 00:00:00 - 00:59:59	95117	2.9%	26.42	31.5 GB	3.4%	9162.66
Oct 29 01:00:00 - 01:59:59	124333	3.8%	34.54	41.4 GB	4.5%	12045.17
Oct 29 02:00:00 - 02:59:59	104365	3.2%	28.99	34.1 GB	3.7%	9939.42
Oct 29 03:00:00 - 03:59:59	112313	3.5%	31.20	35.2 GB	3.9%	10251.90
Oct 29 04:00:00 - 04:15:03	23750	0.7%	26.30	8.7 GB	1.0%	10121.53
TOTAL: 24:00:01	3234626	100.0%	37.44	912.8 GB	100.0%	11077.35

Sites sending bad articles:

Server		Total	Group	Duplic	Unapp	Other
1	news.nask.pl	10468	5	296	3	10164
2	newsfeed.pionier.net.pl	4332	203	2970	0	1159
3	news.icm.edu.pl	2	0	0	0	2
TOTAL: 3		14802	208	3266	3	11325

Unwanted newsgroups [Top 20]:

Newsgroup	Count
uk.railway	157
it.tlc.cellulari.android	15
it.comp.os.win.windows10	11
comp.mobile.ipad	7
uk.net.providers.gradwell	6
nl.comp.os.linux.techniek	5
it.comp.os.win.windows7	4
comp.mobile.android	1
it.comp.os.win.windows8	1
uk.rec.cycling.moderated	1
TOTAL: 10	208

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

Groups	Count
christnet.philosophy	1
christnet.theology	1
bit.listserv.catholic	1
TOTAL: 3	3

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	9447
Binary in non-binary group	1030
EMP (phl)	66
Scoring filter (8)	52
Scoring filter (9)	29
HTML post	12
Too many newsgroups	11
Scoring filter (10)	11
Scoring filter (11)	7
Scoring filter (14)	2
Scoring filter (12)	2
Scoring filter (13)	1
EMP (fsl)	1
Too many newsgroups (low_xpost)	1
TOTAL: 14	10672

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Miss	Spool	%Took	Elapsed
1	panorama	13754	642	10129	996	377	32048	4%	23:58:14
2	icm	40545	288	22303	11750	0	0	0%	24:07:27
3	poznan	14347	133	9805	20	0	0	0%	23:59:32
4	nask	6373	38	4651	2	0	0	0%	24:05:03
5	okapi	0	0	0	0	0	2232	0%	24:00:01
TOTAL: 5		75019	1101	46888	12768	377	34280	1%	120:10:17

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Volume/sec	Vol/Art	Elapsed
1	panorama	3.0 MB	196.0 MB	199.0 MB	2.4 KB/s	124.4 KB	23:58:14
2	icm	2.9 MB	2.8 GB	2.9 GB	34.4 KB/s	248.4 KB	24:07:27
3	poznan	1023.9 KB	111.0 KB	1.1 MB	0.0 KB/s	7.4 KB	23:59:32
4	nask	203.1 KB	13.7 KB	216.7 KB	0.0 KB/s	5.4 KB	24:05:03
5	okapi	0.0 KB	0.0 KB	0.0 KB	0.0 KB/s	0	24:00:01
TOTAL: 5		7.1 MB	3.0 GB	3.0 GB	7.4 KB/s	230.4 KB	120:10:17

Backlog files shrunk by innfeed:

Server	Size
panorama	2.4 MB
TOTAL: 1	2.4 MB

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Post	Elapsed
1	web.man.lodz.pl	288	134	122.2 KB	59	0	00:00:27
2	cmu56.neoplus.adsl.tpnet.pl	2	7	11.2 KB	1	0	00:31:52
3	isvcs01.man.lodz.pl	12	0	0.0 KB	0	12	00:00:00
TOTAL: 3		302	141	133.3 KB	60	12	00:32:25

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Post	Elapsed
1	*.man.lodz.pl	684	134	122.2 KB	59	12	00:00:33
2	*.neoplus.adsl.tpnet.pl	2	7	11.2 KB	1	0	00:31:52
TOTAL: 2		686	141	133.3 KB	60	12	00:32:25

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Elapsed
cmu56.neoplus.adsl.tpnet.pl	0.025	0.065	00:31:52
web.man.lodz.pl	1.099	5.981	00:00:27
mon.man.lodz.pl	0.992	5.668	00:00:03
david.man.lodz.pl	0.299	1.647	00:00:01
isvcs01.man.lodz.pl	0.090	0.243	00:00:00
TOTAL: 5	2.505	13.604	00:32:25

Curious NNRP server explorers [Top 20]:

System	Conn
mon.man.lodz.pl	288
david.man.lodz.pl	96
TOTAL: 2	384

NNRP client timeouts [Top 20]:

System	Conn	Peer
cmu56.neoplus.adsl.tpnet.pl	1	0
TOTAL: 1	1	0

Newsgroup request counts (by category):

Category		Count	Pct
1	pl	134	95.0%
2	lodman	7	5.0%
TOTAL: 2		141	100.0%

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

Newsgroup		Count
1	pl.comp.pecet	88
2	pl.comp.os.ms-windows.winnt	46
3	lodman.info	7
TOTAL: 3		141

Daily Usenet report

Oct 28 04:15:02 -- Oct 29 04:15:03