Daily Usenet report for news.niel.me: Aug 11 04:15:01

Unknown entries from news log file:

First 50 / 111 lines (45.0%)

Aug 11 13:25:30 rpi-studio nnrpd[29171]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:25:47 rpi-studio nnrpd[29176]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:26:04 rpi-studio nnrpd[29183]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:26:20 rpi-studio nnrpd[29187]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:26:35 rpi-studio nnrpd[29192]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:26:50 rpi-studio nnrpd[29197]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:27:05 rpi-studio nnrpd[29203]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:27:21 rpi-studio nnrpd[29208]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:27:36 rpi-studio nnrpd[29211]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:27:53 rpi-studio nnrpd[29217]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:28:09 rpi-studio nnrpd[29364]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:28:25 rpi-studio nnrpd[29370]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:28:40 rpi-studio nnrpd[29375]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:28:56 rpi-studio nnrpd[29378]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:29:12 rpi-studio nnrpd[29385]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:29:27 rpi-studio nnrpd[29395]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:29:42 rpi-studio nnrpd[29400]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:29:57 rpi-studio nnrpd[29403]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:30:12 rpi-studio nnrpd[29412]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:30:27 rpi-studio nnrpd[29415]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:30:42 rpi-studio nnrpd[29420]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:30:58 rpi-studio nnrpd[29423]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:31:14 rpi-studio nnrpd[29430]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:31:29 rpi-studio nnrpd[29434]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:31:44 rpi-studio nnrpd[29460]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:32:00 rpi-studio nnrpd[29465]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:32:15 rpi-studio nnrpd[29473]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:32:31 rpi-studio nnrpd[29478]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:32:46 rpi-studio nnrpd[29481]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:33:01 rpi-studio nnrpd[29496]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:33:18 rpi-studio nnrpd[29499]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:33:33 rpi-studio nnrpd[29505]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:33:49 rpi-studio nnrpd[29508]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:34:05 rpi-studio nnrpd[29515]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:34:20 rpi-studio nnrpd[29521]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:34:35 rpi-studio nnrpd[29524]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:34:50 rpi-studio nnrpd[29530]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:35:07 rpi-studio nnrpd[29537]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:35:22 rpi-studio nnrpd[29542]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:35:38 rpi-studio nnrpd[29545]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:35:53 rpi-studio nnrpd[29551]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:36:08 rpi-studio nnrpd[29557]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:36:23 rpi-studio nnrpd[29562]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:36:39 rpi-studio nnrpd[29566]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:36:54 rpi-studio nnrpd[29578]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:37:10 rpi-studio nnrpd[29585]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:37:26 rpi-studio nnrpd[29590]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:37:41 rpi-studio nnrpd[29595]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:37:57 rpi-studio nnrpd[29598]: 2a0e:97c0:370::1 noperm ihave without permission
Aug 11 13:38:12 rpi-studio nnrpd[29746]: 2a0e:97c0:370::1 noperm ihave without permission

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	4328	38.1%	837.0 KB	45.5%
innd	2658	23.4%	417.1 KB	22.7%
nnrpd	2513	22.1%	289.8 KB	15.8%
innfeed	1851	16.3%	294.7 KB	16.0%
nocem	1	0.0%	0.1 KB	0.0%
controlchan	1	0.0%	0.0 KB	0.0%
TOTAL: 6	11352	100.0%	1.8 MB	100.0%

History cache:

Reason	Count	%Count
Positive hits	21990	62.2%
Negative hits	9039	25.6%
Do not exist	4249	12.0%
Cache misses	61	0.2%
TOTAL: 4	35339	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
artcncl/perl	00:00:00.013	0.0%	14	0.000	0.929	2.000
article cancel	00:00:00.001	0.0%	16	0.000	0.062	1.000
article cleanup	00:00:00.091	0.0%	4288	0.000	0.021	0.200
article logging	00:00:00.287	0.0%	4296	0.000	0.067	0.233
article parse	00:00:00.736	0.0%	13868	0.000	0.053	0.250
article write	00:00:01.787	0.0%	3552	0.100	0.503	1.000
artlog/artcncl	00:00:00.001	0.0%	16	0.000	0.062	1.000
artlog/artcncl/perl	00:00:00.003	0.0%	14	0.000	0.214	1.000
data move	00:00:00.212	0.0%	38679	0.000	0.005	0.026
hisgrep/artcncl	00:00:00.000	0.0%	15	0.000	0.000	0.000
hisgrep/artcncl/perl	00:00:00.000	0.0%	14	0.000	0.000	0.000
hisgrep/perl	00:00:00.001	0.0%	21	0.000	0.048	0.500
hishave/artcncl	00:00:00.000	0.0%	16	0.000	0.000	0.000
hishave/artcncl/perl	00:00:00.000	0.0%	14	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:00.528	0.0%	35423	0.000	0.015	0.044
history sync	00:00:00.042	0.0%	373	0.000	0.113	0.667
history write	00:00:00.749	0.0%	4264	0.000	0.176	0.500
hiswrite/artcncl	00:00:00.000	0.0%	1	0.000	0.000	0.000
idle	24:00:28.966	100.0%	42119	571.117	2052.018	600042.000
nntp read	00:00:01.097	0.0%	41040	0.000	0.027	0.072
overview write	00:00:01.056	0.0%	3552	0.062	0.297	2.278
perl filter	00:00:16.208	0.0%	4264	2.157	3.801	7.455
python filter	00:00:00.013	0.0%	4264	0.000	0.003	0.056
site send	00:00:01.127	0.0%	7213	0.000	0.156	0.412
TOTAL: 24:01:03.523	24:00:52.918	100.0%	-	-	-	-

INNfeed timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article new	00:00:00.034	0.0%	4729	0.000	0.007	0.125
article prepare	00:00:00.003	0.0%	1260	0.000	0.002	0.083
article read	00:00:00.036	0.0%	185	0.000	0.195	4.000
backlog stats	00:00:00.287	0.0%	52732	0.000	0.005	0.051
callbacks	00:00:00.000	0.0%	0	0.000	0.000	0.000
data read	00:00:00.728	0.0%	31217	0.000	0.023	0.057
data write	00:00:01.344	0.0%	26620	0.000	0.050	0.096
idle	23:58:37.983	100.0%	52732	240.066	1636.918	17198.343
status file	00:00:00.578	0.0%	260	1.000	2.223	7.000
TOTAL: 23:58:45.029	23:58:40.993	100.0%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	00:00:51.325	33.0%	1696	10.600	30.262	1661.000
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.125	0.1%	3730	0.000	0.034	0.667
TOTAL: 00:02:35.640	00:00:51.450	33.1%	-	-	-	-

Control commands to INND:

Command	Number
flush	5
flushlogs	2
go	2
logmode	2
lowmark	1
mode	149
name	2
pause	2
paused	2
reload	2
reserve	2
TOTAL: 11	171

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	feed-out.gegeweb.org	6	1892	972	909	11	51%	23:32:39
2	news.glou.org	4	3187	755	2266	166	23%	20:44:51
3	gegeweb-out.news.tnetconsulting.net	3	5702	677	4954	71	11%	34:59:34
4	news.nntp4.net	2	3759	361	3155	243	9%	20:34:06
5	i2pn.org	5	3497	238	3093	166	6%	20:17:23
6	usenet.pasdenom.info	2	2028	205	1816	7	10%	24:44:00
7	nntp.terraraq.uk	3	3589	146	3429	14	4%	29:52:14
8	news.samoylyk.net	3	1876	49	1823	4	2%	15:10:10
9	localhost	25	0	0	0	0	0%	00:00:00
TOTAL: 9		53	25530	3403	21445	682	13%	189:54:57

Incoming Volume (INN):

Server		AcceptVol	DupVol	RejVol	TotalVol	%Acc	Vol/Art
1	news.glou.org	5.1 MB	0.0 KB	859.9 KB	6.0 MB	85%	6.6 KB
2	feed-out.gegeweb.org	4.4 MB	45.1 KB	46.6 KB	4.5 MB	98%	4.7 KB
3	gegeweb-out.news.tnetconsulting.net	4.2 MB	16.2 KB	333.3 KB	4.5 MB	92%	6.2 KB
4	news.nntp4.net	1.8 MB	12.6 KB	1.1 MB	2.9 MB	60%	4.9 KB
5	i2pn.org	1.0 MB	5.2 KB	616.7 KB	1.6 MB	62%	4.1 KB
6	usenet.pasdenom.info	807.4 KB	0.0 KB	16.1 KB	823.5 KB	98%	3.9 KB
7	nntp.terraraq.uk	800.3 KB	0.0 KB	69.1 KB	869.4 KB	92%	5.4 KB
8	news.samoylyk.net	300.5 KB	0.0 KB	11.3 KB	311.8 KB	96%	5.9 KB
9	localhost	0.0 KB	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 9		18.3 MB	79.0 KB	3.0 MB	21.4 MB	85%	5.4 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Aug 11 04:15:01 - 04:59:59	77	2.2%	0.03	561.7 KB	0.0%	0.21
Aug 11 05:00:00 - 05:59:59	82	2.3%	0.02	240.6 KB	0.0%	0.07
Aug 11 06:00:00 - 06:59:59	87	2.5%	0.02	519.1 KB	7.8%	0.14
Aug 11 07:00:00 - 07:59:59	104	2.9%	0.03	509.1 KB	7.6%	0.14
Aug 11 08:00:00 - 08:59:59	124	3.5%	0.03	736.3 KB	11.1%	0.20
Aug 11 09:00:00 - 09:59:59	125	3.5%	0.03	592.2 KB	8.9%	0.16
Aug 11 10:00:00 - 10:59:59	49	1.4%	0.01	328.3 KB	4.9%	0.09
Aug 11 11:00:00 - 11:59:59	0	0.0%	0.00	0.0 KB	0.0%	0.00
Aug 11 12:00:00 - 12:59:59	0	0.0%	0.00	0.0 KB	0.0%	0.00
Aug 11 13:00:00 - 13:59:59	535	15.1%	0.15	2.5 MB	37.8%	0.70
Aug 11 14:00:00 - 14:59:59	190	5.4%	0.05	763.0 KB	11.5%	0.21
Aug 11 15:00:00 - 15:59:59	133	3.7%	0.04	555.6 KB	8.3%	0.15
Aug 11 16:00:00 - 16:59:59	153	4.3%	0.04	870.6 KB	13.1%	0.24
Aug 11 17:00:00 - 17:59:59	228	6.4%	0.06	2.0 MB	30.9%	0.57
Aug 11 18:00:00 - 18:59:59	199	5.6%	0.06	834.9 KB	12.5%	0.23
Aug 11 19:00:00 - 19:59:59	158	4.5%	0.04	1.1 MB	16.3%	0.30
Aug 11 20:00:00 - 20:59:59	153	4.3%	0.04	1009.9 KB	15.2%	0.28
Aug 11 21:00:00 - 21:59:59	165	4.6%	0.05	716.4 KB	10.8%	0.20
Aug 11 22:00:00 - 22:59:59	170	4.8%	0.05	670.1 KB	10.1%	0.19
Aug 11 23:00:00 - 23:59:59	162	4.6%	0.04	714.0 KB	10.7%	0.20
Aug 12 00:00:00 - 00:59:59	179	5.0%	0.05	1.2 MB	18.0%	0.33
Aug 12 01:00:00 - 01:59:59	222	6.3%	0.06	1.2 MB	18.1%	0.33
Aug 12 02:00:00 - 02:59:59	119	3.4%	0.03	844.2 KB	12.7%	0.23
Aug 12 03:00:00 - 03:59:59	102	2.9%	0.03	404.6 KB	6.1%	0.11
Aug 12 04:00:00 - 04:15:01	34	1.0%	0.04	227.0 KB	3.4%	0.25
TOTAL: 24:00:00	3550	100.0%	0.04	6.5 MB	100.0%	0.08

Sites sending bad articles:

Server		Total	Duplic	Other
1	news.nntp4.net	253	4	249
2	i2pn.org	185	3	182
3	news.glou.org	170	0	170
4	gegeweb-out.news.tnetconsulting.net	82	5	77
5	nntp.terraraq.uk	29	0	29
6	feed-out.gegeweb.org	19	10	9
7	news.samoylyk.net	6	0	6
8	usenet.pasdenom.info	4	2	2
TOTAL: 8		748	24	724

INND Perl filter [Top 20]:

Reason	Count
EMP (md5)	277
Bad path (news.giganews.com.POSTED)	174
EMP (phn nph)	112
EMP (phn path)	77
Too many newsgroups	56
EMP (phl)	8
EMP (phr nph)	7
Cancel of non-existing ID <633a4a64-be21-4c3c-89a4-754a1ca11d7an@googlegroups.com>	1
No Cancel-Key matches Cancel-Lock. target=<64d63c66$0$6104$426a74cc@news.free.fr>	1
Cancel of non-existing ID <kjme6sFofatU1@mid.individual.net>	1
No Cancel-Key matches Cancel-Lock. target=<64d60804$0$7473$426a34cc@news.free.fr>	1
Cancel of non-existing ID <dd0652de-157b-4472-9b38-e7e841fbd7f3n@googlegroups.com>	1
TOTAL: 12	716

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Including strange strings
	feed-out.gegeweb.org	8
	TOTAL: 1	8
TOTAL: 1		8

Outgoing Feeds (innfeed) by Articles:

Server		Offered	Taken	Refused	Reject	Spool	%Took	Elapsed
1	nntp.terraraq.uk	2982	68	2476	12	123	2%	23:59:56
2	news.nntp4.net	3488	60	2968	1	181	1%	23:59:56
3	i2pn.org	4805	56	3171	2	238	1%	23:59:56
4	news.tnetconsulting.net	5148	45	3495	6	238	0%	23:59:56
5	news.samoylyk.net	4927	41	3422	5	233	0%	23:59:56
6	news.gegeweb.org	2656	9	2559	9	0	0%	23:59:56
7	news.aioe.org	0	0	0	0	2591	0%	23:59:55
8	news.pasdenom.info	3224	0	3110	1	171	0%	23:59:56
TOTAL: 8		27230	279	21201	36	3775	1%	191:59:27

Outgoing Feeds (innfeed) by Volume:

Server		AcceptVol	RejectVol	TotalVol	Vol/Art	Elapsed
1	nntp.terraraq.uk	761.7 KB	402.8 KB	1.1 MB	14.6 KB	23:59:56
2	news.nntp4.net	750.9 KB	41.2 KB	792.1 KB	13.0 KB	23:59:56
3	i2pn.org	349.6 KB	25.8 KB	375.4 KB	6.5 KB	23:59:56
4	news.samoylyk.net	284.4 KB	88.6 KB	372.9 KB	8.1 KB	23:59:56
5	news.tnetconsulting.net	236.6 KB	246.8 KB	483.4 KB	9.5 KB	23:59:56
6	news.gegeweb.org	30.4 KB	40.6 KB	71.0 KB	3.9 KB	23:59:56
7	news.aioe.org	0.0 KB	0.0 KB	0.0 KB	0	23:59:55
8	news.pasdenom.info	0.0 KB	1.2 KB	1.2 KB	1.2 KB	23:59:56
TOTAL: 8		2.4 MB	846.9 KB	3.2 MB	10.4 KB	191:59:27

NNRP readership statistics:

System		Conn	Elapsed
1	auspicious.monitoring.internet-measurement.com	1	00:00:02
2	mail.gegeweb.eu	248	00:01:15
3	certain.monitoring.internet-measurement.com	1	00:00:00
4	dazzling.monitoring.internet-measurement.com	1	00:00:00
5	192.241.208.79	1	00:00:01
6	sys.gegeweb.eu	1	00:00:01
7	prod-beryllium-sfo3-139.do.binaryedge.ninja	1	00:00:02
8	2a0e:97c0:370::1	108	00:00:36
9	172-105-246-139.ip.linodeusercontent.com	104	00:00:24
10	2001:41d0:2:abb2::25	1	00:00:01
11	194.165.16.73	1	00:00:01
12	reverent.monitoring.internet-measurement.com	1	00:00:00
13	188.165.224.178	1	00:00:00
14	genius.monitoring.internet-measurement.com	1	00:00:06
TOTAL: 14		471	00:02:34

NNRP readership statistics (by domain):

System		Conn	Elapsed
1	*.do.binaryedge.ninja	1	00:00:02
2	unresolved	3	00:00:02
3	?	109	00:00:38
4	*.ip.linodeusercontent.com	104	00:00:24
5	*.gegeweb.eu	249	00:01:16
6	*.monitoring.internet-measurement.com	5	00:00:10
TOTAL: 6		471	00:02:34

NNRP auth users [Top 20]:

User	Conn
mailman	251
TOTAL: 1	251

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
mail.gegeweb.eu	3.959	3.271	1.372	00:01:15
2a0e:97c0:370::1	2.539	1.872	0.000	00:00:36
172-105-246-139.ip.linodeusercontent.com	2.561	1.329	0.000	00:00:24
genius.monitoring.internet-measurement.com	0.042	0.015	0.000	00:00:06
auspicious.monitoring.internet-measurement.com	0.015	0.010	0.000	00:00:02
prod-beryllium-sfo3-139.do.binaryedge.ninja	0.011	0.014	0.000	00:00:02
2001:41d0:2:abb2::25	0.010	0.016	0.005	00:00:01
sys.gegeweb.eu	0.031	0.019	0.010	00:00:01
192.241.208.79	0.029	0.017	0.000	00:00:01
194.165.16.73	0.040	0.012	0.000	00:00:01
certain.monitoring.internet-measurement.com	0.033	0.025	0.000	00:00:00
dazzling.monitoring.internet-measurement.com	0.040	0.024	0.000	00:00:00
reverent.monitoring.internet-measurement.com	0.039	0.023	0.000	00:00:00
188.165.224.178	0.022	0.031	0.004	00:00:00
TOTAL: 14	9.371	6.678	1.391	00:02:34

NNRP gethostbyaddr failures [Top 20]:

System	Conn
? (can't getpeername)	7
TOTAL: 1	7

NNRP unrecognized commands (by host):

System	Conn
194.165.16.73	1
192.241.208.79	1
TOTAL: 2	2

NNRP unrecognized commands (by command):

Command	Count
MGLNDD_45.13.105.36_119	1
#003	1
TOTAL: 2	2

NNRP client timeouts [Top 20]:

System	Conn	Peer
194.165.16.73	1	1
TOTAL: 1	1	1

Daily Usenet report for news.niel.me

Aug 11 04:15:01 -- Aug 12 04:15:01