Daily Usenet Report

Nov 13 00:01:01 -- Nov 15 00:01:01

Unknown entries from news log file:

First 50 / 52 lines (96.2%)

Nov 13 00:01:43 wibble innd: message repeated 2 times: [ ctlinnd command s]
Nov 13 00:13:10 wibble innd: tradspool: could not open /news/spool/articles/sci/math/1888: File exists
Nov 13 01:53:27 wibble innd: tradspool: could not symlink /news/spool/articles/misc/news/internet/discuss/482 to /news/spool/articles/alt/audio/equipment/1: File exists
Nov 13 01:53:56 wibble innd: tradspool: could not open /news/spool/articles/ucd/swap/books/1: File exists
Nov 13 01:54:10 wibble innd: tradspool: could not symlink /news/spool/articles/soc/culture/irish/17 to /news/spool/articles/alt/fan/countries/canada/1: File exists
Nov 13 01:54:31 wibble innd: tradspool: could not symlink /news/spool/articles/soc/retirement/147 to /news/spool/articles/alt/architecture/1: File exists
Nov 13 01:54:40 wibble innd: tradspool: could not open /news/spool/articles/de/rec/musik/machen/1: File exists
Nov 13 01:54:42 wibble innd: tradspool: could not symlink /news/spool/articles/soc/culture/irish/20 to /news/spool/articles/alt/fan/countries/canada/2: File exists
Nov 13 01:54:48 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/1: File exists
Nov 13 01:54:48 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/2: File exists
Nov 13 01:54:48 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/3: File exists
Nov 13 01:55:00 wibble innd: tradspool: could not open /news/spool/articles/talk/religion/bahai/1: File exists
Nov 13 01:55:10 wibble innd: tradspool: could not open /news/spool/articles/comp/lang/clipper/visual-objects/1: File exists
Nov 13 01:55:12 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/1: File exists
Nov 13 01:55:13 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/2: File exists
Nov 13 01:56:33 wibble innd: tradspool: could not open /news/spool/articles/talk/religion/bahai/2: File exists
Nov 13 01:58:43 wibble innd: tradspool: could not symlink /news/spool/articles/misc/news/internet/discuss/494 to /news/spool/articles/alt/audio/equipment/2: File exists
Nov 13 01:58:59 wibble innd: tradspool: could not symlink /news/spool/articles/soc/retirement/149 to /news/spool/articles/alt/architecture/2: File exists
Nov 13 01:59:02 wibble innd: tradspool: could not open /news/spool/articles/de/rec/musik/machen/2: File exists
Nov 13 01:59:05 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/4: File exists
Nov 13 01:59:05 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/5: File exists
Nov 13 01:59:05 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/6: File exists
Nov 13 01:59:08 wibble innd: tradspool: could not open /news/spool/articles/talk/religion/bahai/3: File exists
Nov 13 01:59:11 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/3: File exists
Nov 13 01:59:11 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/4: File exists
Nov 13 02:00:56 wibble innd: tradspool: could not symlink /news/spool/articles/misc/news/internet/discuss/495 to /news/spool/articles/alt/audio/equipment/3: File exists
Nov 13 02:01:39 wibble innd: tradspool: could not open /news/spool/articles/de/rec/musik/machen/3: File exists
Nov 13 02:01:43 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/7: File exists
Nov 13 02:01:43 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/ufo/8: File exists
Nov 13 02:01:52 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/5: File exists
Nov 13 02:01:53 wibble innd: tradspool: could not open /news/spool/articles/at/verkehr/bahn/6: File exists
Nov 13 03:33:03 wibble innd: tradspool: could not open /news/spool/articles/uk/comp/os/linux/1: File exists
Nov 13 03:33:04 wibble innd: tradspool: could not open /news/spool/articles/uk/comp/os/linux/2: File exists
Nov 13 03:33:08 wibble innd: tradspool: could not open /news/spool/articles/uk/comp/os/linux/3: File exists
Nov 13 05:41:55 wibble innd: tradspool: could not open /news/spool/articles/misc/misc/1: File exists
Nov 13 05:41:56 wibble innd: tradspool: could not open /news/spool/articles/misc/misc/2: File exists
Nov 13 05:53:40 wibble innd: tradspool: could not open /news/spool/articles/sci/astro/1: File exists
Nov 13 05:53:41 wibble innd: tradspool: could not open /news/spool/articles/sci/astro/2: File exists
Nov 13 05:53:45 wibble innd: tradspool: could not open /news/spool/articles/sci/astro/3: File exists
Nov 13 06:42:46 wibble innd: tradspool: could not open /news/spool/articles/sci/astro/4: File exists
Nov 13 07:51:12 wibble innd: tradspool: could not open /news/spool/articles/alt/religion/christian-identity/1: File exists
Nov 13 07:51:13 wibble innd: tradspool: could not open /news/spool/articles/alt/religion/christian-identity/2: File exists
Nov 13 10:58:32 wibble innd: tradspool: could not symlink /news/spool/articles/de/soc/senioren/59 to /news/spool/articles/de/soc/politik/texte/1: File exists
Nov 13 10:58:33 wibble innd: tradspool: could not symlink /news/spool/articles/de/soc/senioren/60 to /news/spool/articles/de/soc/politik/texte/2: File exists
Nov 13 10:58:37 wibble innd: tradspool: could not symlink /news/spool/articles/de/soc/senioren/61 to /news/spool/articles/de/soc/politik/texte/3: File exists
Nov 13 11:20:10 wibble innd: tradspool: could not open /news/spool/articles/it/scienza/chimica/1: File exists
Nov 13 11:20:10 wibble innd: tradspool: could not open /news/spool/articles/it/scienza/chimica/2: File exists
Nov 13 11:20:15 wibble innd: tradspool: could not open /news/spool/articles/it/scienza/chimica/3: File exists
Nov 13 13:34:39 wibble innd: tradspool: could not open /news/spool/articles/rec/sport/football/australian/1: File exists
Nov 13 22:01:02 wibble innd: tradspool: could not open /news/spool/articles/fido7/ru/golded/1: File exists

Log entries by program:

Program nameLines%LinesSize%Size
inn 30501 86.4%4.0 MB 86.1%
innd 3011 8.5%463.5 KB 9.7%
innfeed 1418 4.0%178.8 KB 3.7%
nnrpd 367 1.0%26.2 KB 0.5%
controlchan 3 0.0%0.2 KB 0.0%
rnews 3 0.0%0.3 KB 0.0%
TOTAL: 6 35303 100.0%4.7 MB100.0%

History cache:

ReasonCount%Count
Positive hits 52972 41.4%
Negative hits 43664 34.2%
Do not exist 28896 22.6%
Cache misses 2296 1.8%
TOTAL: 4 127828 100.0%

INND timer:

Code regionTimePctInvokedMin(ms)Avg(ms)Max(ms)
article cancel00:00:00.128 0.0%84 0.000 1.524 23.000
article cleanup00:00:00.136 0.0%29733 0.000 0.005 0.070
article logging00:00:00.403 0.0%30339 0.000 0.013 0.061
article parse00:00:00.311 0.0%74220 0.000 0.004 0.025
article write00:00:07.974 0.0%28347 0.000 0.281 41.589
artlog/artcncl00:00:00.000 0.0%84 0.000 0.000 0.000
artlog/artwrite00:00:00.000 0.0%51 0.000 0.000 0.000
data move00:00:00.076 0.0%156475 0.000 0.000 0.006
hisgrep/artcncl00:00:00.000 0.0%38 0.000 0.000 0.000
hishave/artcncl00:00:00.000 0.0%84 0.000 0.000 0.000
hissync/artwrite00:00:00.000 0.0%2 0.000 0.000 0.000
history grep00:00:00.000 0.0%0 0.000 0.000 0.000
history lookup00:00:00.280 0.0%127969 0.000 0.002 0.026
history sync00:00:00.018 0.0%751 0.000 0.024 0.667
history write00:00:00.615 0.0%28881 0.000 0.021 0.095
hiswrite/artcncl00:00:00.001 0.0%46 0.000 0.022 0.059
idle46:31:28.700100.0%155221 41.183 1079.034150193.000
nntp read00:00:00.971 0.0%155030 0.000 0.006 0.025
overview write00:00:05.453 0.0%28296 0.000 0.193 3.286
perl filter00:00:18.061 0.0%28932 0.373 0.624 1.727
python filter00:00:00.477 0.0%28932 0.000 0.016 0.071
site send00:00:00.492 0.0%56592 0.000 0.009 0.041
TOTAL: 46:32:14.94446:32:04.096100.0%----

INNfeed timer:

Code regionTimePctInvokedMin(ms)Avg(ms)Max(ms)
article new00:00:00.042 0.0%28891 0.000 0.001 0.034
article prepare00:00:00.000 0.0%540 0.000 0.000 0.000
article read00:00:00.057 0.0%135 0.000 0.422 24.000
backlog stats00:00:00.047 0.0%176842 0.000 0.000 0.005
callbacks00:00:00.000 0.0%0 0.000 0.000 0.000
data read00:00:00.643 0.0%98343 0.000 0.007 0.027
data write00:00:01.024 0.0%72846 0.000 0.014 0.061
idle46:42:51.589100.0%176842 48.899 950.971 23141.385
status file00:00:00.146 0.0%287 0.000 0.509 82.000
TOTAL: 46:42:55.95046:42:53.548100.0%----

nnrpd timer:

Code regionTimePctInvokedMin(ms)Avg(ms)Max(ms)
idle37:01:41.802100.0%286946462.810 46462.810 46462.810
newnews00:00:00.000 0.0%0 0.000 0.000 0.000
nntpwrite00:00:00.104 0.0%6276 0.017 0.017 0.017
readart00:00:00.204 0.0%309 0.660 0.660 0.660
TOTAL: 37:01:42.19837:01:42.110100.0%----

Control commands to INND:

CommandNumber
flush 4
flushlogs 2
go 1
logmode 2
lowmark 1
mode 286
name 2
pause 1
paused 1
reload 4
renumber 1
shutdown 6
throttle 4
TOTAL: 13 315

Incoming Feeds (INN):

ServerConnectsOfferedTakenRefusedReject%AccptElapsed
1endofthelinebbs-out.news.weretis.net 18 56528 23205 31930 1393 41%89:49:06
2news.bbs.nz 5 17605 4823 12738 44 27%25:11:17
3localhost 47 0 0 0 0 0%00:00:00
TOTAL: 3 70 74133 28028 44668 1437 37%115:00:23
Articles received by server

Incoming Volume (INN):

ServerAcceptVolDupVolRejVolTotalVol%AccVol/Art
1endofthelinebbs-out.news.weretis.net82.4 MB2.8 MB5.0 MB90.3 MB 91%3.8 KB
2news.bbs.nz19.5 MB56.9 KB220.4 KB19.7 MB 98%4.2 KB
3localhost0.0 KB0.0 KB0.0 KB0.0 KB 0%0
TOTAL: 3101.9 MB2.9 MB5.2 MB110.0 MB 92%3.8 KB
Incoming Volume received by server

Incoming articles:

DateArticles%ArtsArt/secSize%SizeKB/sec
Nov 13 01:01:01 - 01:59:59 4745 16.8% 1.3419.0 MB 18.5% 5.50
Nov 13 02:00:00 - 02:59:59 425 1.5% 0.121.5 MB 1.5% 0.44
Nov 13 03:00:00 - 03:59:59 531 1.9% 0.151.6 MB 1.6% 0.46
Nov 13 04:00:00 - 04:59:59 594 2.1% 0.172.3 MB 2.2% 0.66
Nov 13 05:00:00 - 05:59:59 591 2.1% 0.161.8 MB 1.7% 0.51
Nov 13 06:00:00 - 06:59:59 612 2.2% 0.171.9 MB 1.9% 0.55
Nov 13 07:00:00 - 07:59:59 609 2.2% 0.172.1 MB 2.0% 0.59
Nov 13 08:00:00 - 08:59:59 759 2.7% 0.213.1 MB 3.0% 0.87
Nov 13 09:00:00 - 09:59:59 643 2.3% 0.182.3 MB 2.3% 0.66
Nov 13 10:00:00 - 10:59:59 650 2.3% 0.181.8 MB 1.8% 0.51
Nov 13 11:00:00 - 11:59:59 666 2.4% 0.182.0 MB 2.0% 0.58
Nov 13 12:00:00 - 12:59:59 633 2.2% 0.182.2 MB 2.2% 0.64
Nov 13 13:00:00 - 13:59:59 557 2.0% 0.152.6 MB 2.5% 0.73
Nov 13 14:00:00 - 14:59:59 642 2.3% 0.182.0 MB 1.9% 0.55
Nov 13 15:00:00 - 15:59:59 562 2.0% 0.162.1 MB 2.0% 0.59
Nov 13 16:00:00 - 16:59:59 604 2.1% 0.171.5 MB 1.4% 0.42
Nov 13 17:00:00 - 17:59:59 465 1.6% 0.131.9 MB 1.9% 0.55
Nov 13 18:00:00 - 18:59:59 368 1.3% 0.102.1 MB 2.0% 0.59
Nov 13 19:00:00 - 19:59:59 302 1.1% 0.08955.3 KB 0.9% 0.27
Nov 13 20:00:00 - 20:59:59 283 1.0% 0.081.1 MB 1.1% 0.32
Nov 13 21:00:00 - 21:59:59 259 0.9% 0.071.7 MB 1.6% 0.47
Nov 13 22:00:00 - 22:59:59 258 0.9% 0.072.0 MB 1.9% 0.56
Nov 13 23:00:00 - 23:59:59 61 0.2% 0.02183.1 KB 0.2% 0.05
Nov 14 00:00:00 - 00:59:59 417 1.5% 0.121.7 MB 1.7% 0.49
Nov 14 01:00:00 - 01:59:59 378 1.3% 0.101.6 MB 1.5% 0.45
Nov 14 02:00:00 - 02:59:59 389 1.4% 0.111.6 MB 1.5% 0.45
Nov 14 03:00:00 - 03:59:59 518 1.8% 0.141.6 MB 1.5% 0.45
Nov 14 04:00:00 - 04:59:59 588 2.1% 0.161.7 MB 1.6% 0.47
Nov 14 05:00:00 - 05:59:59 536 1.9% 0.151.7 MB 1.6% 0.48
Nov 14 06:00:00 - 06:59:59 526 1.9% 0.151.8 MB 1.8% 0.53
Nov 14 07:00:00 - 07:59:59 579 2.0% 0.161.9 MB 1.8% 0.53
Nov 14 08:00:00 - 08:59:59 621 2.2% 0.172.5 MB 2.4% 0.70
Nov 14 09:00:00 - 09:59:59 623 2.2% 0.171.6 MB 1.6% 0.46
Nov 14 10:00:00 - 10:59:59 608 2.1% 0.172.3 MB 2.2% 0.66
Nov 14 11:00:00 - 11:59:59 824 2.9% 0.232.3 MB 2.3% 0.66
Nov 14 12:00:00 - 12:59:59 738 2.6% 0.202.5 MB 2.4% 0.70
Nov 14 13:00:00 - 13:59:59 726 2.6% 0.202.0 MB 1.9% 0.56
Nov 14 14:00:00 - 14:59:59 700 2.5% 0.191.9 MB 1.8% 0.53
Nov 14 15:00:00 - 15:59:59 665 2.3% 0.182.2 MB 2.2% 0.63
Nov 14 16:00:00 - 16:59:59 653 2.3% 0.182.2 MB 2.2% 0.63
Nov 14 17:00:00 - 17:59:59 516 1.8% 0.141.6 MB 1.5% 0.45
Nov 14 18:00:00 - 18:59:59 451 1.6% 0.131.9 MB 1.9% 0.55
Nov 14 19:00:00 - 19:59:59 382 1.3% 0.111.7 MB 1.6% 0.48
Nov 14 20:00:00 - 20:59:59 290 1.0% 0.081.7 MB 1.7% 0.49
Nov 14 21:00:00 - 21:59:59 226 0.8% 0.061.3 MB 1.3% 0.37
Nov 14 22:00:00 - 22:59:59 245 0.9% 0.07909.4 KB 0.9% 0.25
Nov 14 23:00:00 - 23:59:59 300 1.1% 0.081021.4 KB 1.0% 0.28
Nov 15 00:00:00 - 00:01:01 5 0.0% 0.0853.2 KB 0.1% 0.87
TOTAL: 47:00:00 28323 100.0% 0.17102.9 MB 100.0% 0.62
Incoming articles
Incoming articles (size)

Sites sending bad articles:

ServerTotalGroupDistDuplicUnappTooOldSiteLineOther
1endofthelinebbs-out.news.weretis.net 2007 2 0 779 0 0 0 0 1226
2news.bbs.nz 87 0 0 22 0 0 0 0 65
TOTAL: 2 2094 2 0 801 0 0 0 0 1291

Unwanted newsgroups [Top 20]:

NewsgroupCount
alt.philosophy 2
TOTAL: 1 2

INND Perl filter [Top 20]:

ReasonCount
EMP (md5) 207
User-issued spam cancel 159
Too many newsgroups 99
EMP (phn path) 64
User-issued cancel 35
HTML Multipart 13
EMP (phl) 5
HTML post 1
TOTAL: 8 583

Miscellaneous innd statistics [Top 10]:

EventServerNumber
Including strange strings
endofthelinebbs-out.news.weretis.net 614
news.bbs.nz 42
TOTAL: 2 656
TOTAL: 1 656

Outgoing Feeds (innfeed) by Articles:

ServerOfferedTakenRefusedRejectMissSpool%TookElapsed
1news.bbs.nz 45455 102 23192 27 0 565 0%45:16:21
2news.weretis.net 28428 6 28317 0 0 8 0%45:16:11
TOTAL: 2 73883 108 51509 27 0 573 0%90:32:32
Outgoing feeds (innfeed) by Articles

Outgoing Feeds (innfeed) by Volume:

ServerAcceptVolRejectVolTotalVolVolume/secVol/ArtElapsed
1news.bbs.nz301.6 KB599.5 KB901.0 KB0.0 KB/s7.0 KB45:16:21
2news.weretis.net12.9 KB0.0 KB12.9 KB0.0 KB/s2.1 KB45:16:11
TOTAL: 2314.4 KB599.5 KB913.9 KB0.0 KB/s6.8 KB90:32:32
Outgoing feeds (innfeed) by Volume

Rnews connections rejected:

ReasonConn
What server? 2
400 File exists writing SMstore file -- throttling 1
TOTAL: 2 3

NNRP total resource statistics [Top 20]:

SystemUser(ms)System(ms)Idle(ms)Elapsed
wibble 0.163 0.085 0.00037:01:42
TOTAL: 1 0.163 0.085 0.00037:01:42

Newsgroup request counts (by category):

CategoryCountPct
1soc 230 94.3%
2comp 8 3.3%
3alt 3 1.2%
4news 2 0.8%
5dfw 1 0.4%
TOTAL: 5 244100.0%

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

NewsgroupCount
1soc.genealogy.medieval 228
2comp.sys.acorn.apps 5
3comp.sys.acorn.hardware 3
4alt.bbs.synchronet 3
5soc.genealogy.britain 2
6news.software.nntp 2
7dfw.politics 1
TOTAL: 7 244