Daily Usenet report: Aug 27 17:21:34

Unknown entries from news log file:

First 34 / 34 lines (100.0%)

Aug 27 17:53:39 srv-msk1 rnews[34576]: usage error
Aug 27 17:53:43 srv-msk1 rnews[34582]: usage error
Aug 27 17:55:06 srv-msk1 rnews[34688]: cannot read, wanted 1898 got 1260
Aug 27 17:55:26 srv-msk1 rnews[34743]: cannot read, wanted 1898 got 1260
Aug 27 17:55:52 srv-msk1 rnews[34779]: cannot read, wanted 1140 got 558
Aug 27 17:59:36 srv-msk1 rnews[35081]: cannot read, wanted 1898 got 1260
Aug 27 17:59:59 srv-msk1 rnews[35121]: usage error
Aug 27 18:00:13 srv-msk1 rnews[35211]: cannot read, wanted 2774 got 1688
Aug 27 18:06:43 srv-msk1 rnews[35870]: usage error
Aug 27 18:06:47 srv-msk1 rnews[35882]: usage error
Aug 27 18:07:05 srv-msk1 rnews[35909]: usage error
Aug 27 18:07:20 srv-msk1 rnews[35919]: cannot read, wanted 2774 got 1688
Aug 27 18:12:11 srv-msk1 rnews[36286]: cannot read, wanted 2774 got 1688
Aug 27 18:21:21 srv-msk1 rnews[37339]: cant open_remote: Connection refused
Aug 27 18:21:41 srv-msk1 rnews[37366]: cant open_remote: Connection refused
Aug 27 18:30:02 srv-msk1 rnews[38243]: cant open_remote: Connection refused
Aug 27 18:36:05 srv-msk1 rnews[38940]: cant open_remote: Connection refused
Aug 27 18:37:45 srv-msk1 rnews[39044]: cant open_remote: Connection refused
Aug 27 18:40:19 srv-msk1 rnews[39257]: cant open_remote: Connection refused
Aug 27 18:43:00 srv-msk1 rnews[39458]: cant open_remote: Connection refused
Aug 27 18:45:01 srv-msk1 rnews[39647]: cant open_remote: Connection refused
Aug 27 18:51:25 srv-msk1 rnews[40484]: cant open_remote: Connection refused
Aug 27 18:56:02 srv-msk1 innd[41268]: SERVER perl filter not defined
Aug 27 18:56:27 srv-msk1 rnews[41444]: cannot read, wanted 1898 got 1260
Aug 27 18:57:36 srv-msk1 rnews[41538]: cannot read, wanted 1140 got 558
Aug 27 18:57:49 srv-msk1 rnews[41568]: cannot read, wanted 1552 got 998
Aug 27 20:06:32 srv-msk1 nnrpd[47939]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 rejected loadav [innwatch:load] 1756 gt 1500
Aug 27 20:16:32 srv-msk1 nnrpd[48232]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 load 47.30 > 16
Aug 27 20:32:17 srv-msk1 nnrpd[48497]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 load 83.40 > 16
Aug 27 20:43:01 srv-msk1 nnrpd[48859]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 load 75.13 > 16
Aug 27 20:43:56 srv-msk1 nnrpd[49231]: home.kruglikov.info load 31.39 > 16
Aug 27 20:46:32 srv-msk1 nnrpd[49476]: home.kruglikov.info rejected loadav [innwatch:load] 1756 gt 1500
Aug 27 20:47:14 srv-msk1 nnrpd[49533]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 rejected loadav [innwatch:load] 1756 gt 1500
Aug 27 20:52:08 srv-msk1 nnrpd[50060]: 2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5 rejected loadav [innwatch:load] 1756 gt 1500

Log entries by program:

Program name	Lines	%Lines	Size	%Size
inn	96695	70.5%	11.4 MB	68.6%
rnews	39391	28.7%	5.1 MB	30.7%
innd	890	0.6%	105.1 KB	0.6%
nnrpd	160	0.1%	17.8 KB	0.1%
TOTAL: 4	137136	100.0%	16.7 MB	100.0%

History cache:

Reason	Count	%Count
Cache misses	803106	78.1%
Do not exist	96625	9.4%
Negative hits	96625	9.4%
Positive hits	32149	3.1%
TOTAL: 4	1028505	100.0%

INND timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
article cancel	00:00:00.000	0.0%	0	0.000	0.000	0.000
article cleanup	00:00:00.192	0.0%	96620	0.000	0.002	0.019
article logging	00:00:00.522	0.0%	96620	0.000	0.005	0.200
article parse	00:00:00.870	0.0%	193916	0.000	0.004	0.113
article write	00:00:01.238	0.0%	96620	0.000	0.013	0.800
artlog/artparse	00:00:00.000	0.0%	5	0.000	0.000	0.000
data move	00:00:00.164	0.0%	1026929	0.000	0.000	0.007
hishave/artparse	00:00:00.000	0.0%	5	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:35.105	0.2%	1028500	0.000	0.034	0.500
history sync	00:00:00.004	0.0%	55	0.000	0.073	1.000
history write	00:00:05.886	0.0%	96620	0.000	0.061	1.000
hiswrite/artparse	00:00:00.000	0.0%	5	0.000	0.000	0.000
idle	04:32:31.991	94.9%	1029483	0.643	15.884	300503.000
nntp read	00:00:07.525	0.0%	1029241	0.000	0.007	0.072
overview write	00:00:08.754	0.1%	96620	0.090	0.091	1.000
perl filter	00:00:00.013	0.0%	96620	0.000	0.000	0.000
python filter	00:00:02.202	0.0%	1028495	0.000	0.002	0.250
site send	00:00:00.000	0.0%	0	0.000	0.000	0.000
TOTAL: 04:47:04.185	04:33:34.466	95.3%	-	-	-	-

nnrpd timer:

Code region	Time	Pct	Invoked	Min(ms)	Avg(ms)	Max(ms)
idle	02:33:43.648	99.9%	155	39.000	59507.406	119987.200
newnews	00:00:00.000	0.0%	0	0.000	0.000	0.000
nntpwrite	00:00:00.076	0.0%	3468	0.000	0.022	1.000
readart	00:00:00.003	0.0%	59	0.000	0.051	0.055
TOTAL: 02:33:49.607	02:33:43.727	99.9%	-	-	-	-

Control commands to INND:

Command	Number
flush	52
flushlogs	2
go	2
logmode	3
mode	31
name	1
newgroup	1
pause	2
paused	2
renumber	1
rmgroup	1
shutdown	3
throttle	2
TOTAL: 13	103

Newsgroups created:

Group	Mode
fido7.ua.news	y
TOTAL	1

Newsgroups removed:

Group
fido7.ua.news
TOTAL: 1

Incoming Feeds (INN):

Server		Connects	Offered	Taken	Refused	Reject	%Accpt	Elapsed
1	localhost	72	401694	50217	351472	5	12%	00:01:06
2	fidogate.ru	1	0	0	0	0	0%	00:00:00
TOTAL: 2		73	401694	50217	351472	5	12%	00:01:06

Incoming Volume (INN):

Server		AcceptVol	RejVol	TotalVol	%Acc	Vol/Art
1	localhost	89.4 MB	23.7 MB	113.1 MB	79%	2.3 KB
2	fidogate.ru	0.0 KB	0.0 KB	0.0 KB	0%	0
TOTAL: 2		89.4 MB	23.7 MB	113.1 MB	79%	2.3 KB

Incoming articles:

Date	Articles	%Arts	Art/sec	Size	%Size	KB/sec
Aug 27 17:21:34 - 17:59:59	5	0.0%	0.00	9.2 KB	0.0%	0.00
Aug 27 18:00:00 - 18:59:59	94650	97.9%	26.29	143.5 MB	90.0%	40.81
Aug 27 19:00:00 - 19:59:59	66	0.1%	0.02	203.6 KB	0.1%	0.06
Aug 27 20:00:00 - 20:59:59	3	0.0%	0.00	8.6 KB	0.0%	0.00
Aug 27 21:00:00 - 21:59:59	1946	2.0%	0.54	15.7 MB	9.8%	4.46
Aug 27 22:00:00 - 23:00:02	20	0.0%	0.01	64.0 KB	0.0%	0.02
TOTAL: 05:38:28	96690	100.0%	4.76	159.4 MB	100.0%	8.04

Sites sending bad articles:

Server		Total	Group	Dist	Duplic	Unapp	TooOld	Site	Line	Other
1	localhost	5	0	0	0	0	0	0	0	5
TOTAL: 1		5	0	0	0	0	0	0	0	5

Miscellaneous innd statistics [Top 10]:

Event	Server	Number
Huge articles
	localhost	5
	TOTAL: 1	5
TOTAL: 1		5

Rnews connections rejected:

Reason	Conn
400 loadav [innwatch:load] 1756 gt 1500	9
TOTAL: 1	9

Miscellaneous rnews statistics:

Event	Element	Number
Duplicate articles
	--	39352
TOTAL:		39352

NNRP readership statistics:

System		Conn	Arts	Size	Groups	Elapsed
1	2a03:1ac0:6dc3:1ccf:9cc2:5193:8a09:64a2	1	55	89.6 KB	3	00:26:35
2	79-139-142-135.dynamic.spd-mgts.ru	1	4	5.9 KB	1	00:01:07
TOTAL: 2		2	59	95.5 KB	4	02:33:49

NNRP readership statistics (by domain):

System		Conn	Arts	Size	Groups	Elapsed
1	?	16	55	89.6 KB	3	01:44:35
2	*.dynamic.spd-mgts.ru	1	4	5.9 KB	1	00:01:07
3	*.ru	1	0	0.0 KB	0	00:00:00
4	*.monitoring.internet-measurement.com	1	0	0.0 KB	0	00:00:01
5	*.kruglikov.info	7	0	0.0 KB	0	00:48:04
TOTAL: 5		26	59	95.5 KB	4	02:33:49

NNRP auth users [Top 20]:

User	Conn
around	15
TOTAL: 1	15

NNRP total resource statistics [Top 20]:

System	User(ms)	System(ms)	Idle(ms)	Elapsed
2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5	0.079	0.145	0.027	01:17:59
home.kruglikov.info	0.044	0.053	0.022	00:48:04
2a03:1ac0:6dc3:1ccf:9cc2:5193:8a09:64a2	0.014	0.017	0.003	00:26:35
79-139-142-135.dynamic.spd-mgts.ru	0.006	0.010	0.000	00:01:07
terrific.monitoring.internet-measurement.com	0.007	0.003	0.000	00:00:01
?	0.028	0.023	0.000	00:00:00
fidogate.ru	0.003	0.008	0.000	00:00:00
TOTAL: 7	0.181	0.259	0.052	02:33:49

Curious NNRP server explorers [Top 20]:

System	Conn
2a03:1ac0:6dc3:1ccf:b7bf:9ad0:820a:4bb5	15
home.kruglikov.info	7
terrific.monitoring.internet-measurement.com	1
fidogate.ru	1
TOTAL: 4	24

NNRP gethostbyaddr failures [Top 20]:

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

Newsgroup request counts (by hierarchy):

Hierarchy		Count	Pct
1	fido7	59	100.0%
TOTAL: 1		59	100.0%

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

Newsgroup		Count
1	fido7.ua.news	55
2	fido7.ru.mac	4
TOTAL: 2		59

Daily Usenet report

Aug 27 17:21:34 -- Aug 27 23:00:02