Now that I've got faster hardware and have had a chance to feed over 184
million articles to a new server, I notice a steep decline in performance from
the beginning of the process to the end. When looking at the news.daily output
it appears the majority of the time is spent dealing with the history file. I
would expect article/overview writing or perl filtering to take more time, but
perhaps there is more to dealing with the history file than I
understand.<div><div>Is this kind of curve in performance degradation expected
as the history file grows?</div><div></div><div>Timer output (note I didn't
run news.daily until many days after injection stopped, accounting for the
huge idle time):</div><div></div><div>INND timer:</div><div>Code region
Time Pct Invoked Min(ms) Avg(ms) Max(ms)</div><div>article
cancel 00:05:22.727 0.0% 205040 0.021 1.574
7.677</div><div>article cleanup 00:05:44.900 0.0% 183854425 0.002
0.002 0.002</div><div>article logging 00:11:56.897 0.1% 184142520
0.003 0.004 0.005</div><div>article parse 00:30:34.354 0.2%
265195021 0.005 0.007 0.011</div><div>article write 00:43:24.939
0.3% 183809673 0.010 0.014 0.024</div><div>data move
00:01:08.029 0.0% 95351907 0.000 0.001
0.002</div><div>hisgrep/artcncl 00:04:05.556 0.0% 205040 0.007
1.198 4.204</div><div>history grep 00:00:00.000 0.0% 0
0.000 0.000 0.000</div><div>history lookup 49:09:14.755 21.9%
183854425 0.001 0.962 2.154</div><div>history sync 00:00:01.261
0.0% 2681 0.000 0.470 121.000</div><div>history write
41:34:50.164 18.5% 183854156 0.012 0.814 1.747</div><div>idle
120:16:16.894 53.6% 22762294 0.003 19.022
600095.000</div><div>nntp read 00:12:29.088 0.1% 83339892 0.004
0.009 0.012</div><div>overview write 02:45:18.889 1.2% 183809673
0.026 0.054 0.101</div><div>perl filter 07:57:01.509 3.5%
183854156 0.124 0.156 0.251</div><div>python filter 00:06:03.073
0.0% 183854156 0.000 0.002 0.014</div><div>site send
00:00:00.000 0.0% 0 0.000 0.000
0.000</div><div></div><div>TOTAL: 224:33:0 223:43:33.035 99.6% -
- - -</div><div></div><div>Performance shown by the hourly
breakdown matches what I see with other metrics such as bandwidth, disk I/O,
etc. There is a steady decline in all of those numbers as time went on. Note I
have article size logging turned off, was trying trim down as much logging as
possible.</div><div></div><div>Incoming articles:</div><div>Date
Articles %Arts Art/sec Size %Size KB/sec</div><div>Jul 16
10:03:43 - 10:59:59 6608118 3.6% 1956.80 0.0 KB 0.0%
0.00</div><div>Jul 16 11:00:00 - 11:59:59 13467714 7.3% 3741.03 0.0 KB
0.0% 0.00</div><div>Jul 16 12:00:00 - 12:59:59 8000940 4.3% 2222.48
0.0 KB 0.0% 0.00</div><div>Jul 16 13:00:00 - 13:59:59 5748819 3.1%
1596.89 0.0 KB 0.0% 0.00</div><div>Jul 16 14:00:00 - 14:59:59 5122241
2.8% 1422.84 0.0 KB 0.0% 0.00</div><div>Jul 16 15:00:00 - 15:59:59
4287868 2.3% 1191.07 0.0 KB 0.0% 0.00</div><div>Jul 16 16:00:00 -
16:59:59 4034400 2.2% 1120.67 0.0 KB 0.0% 0.00</div><div>Jul 16
17:00:00 - 17:59:59 3548680 1.9% 985.74 0.0 KB 0.0%
0.00</div><div>Jul 16 18:00:00 - 18:59:59 3238737 1.8% 899.65 0.0 KB
0.0% 0.00</div><div>Jul 16 19:00:00 - 19:59:59 3179352 1.7% 883.15
0.0 KB 0.0% 0.00</div><div>Jul 16 20:00:00 - 20:59:59 2861511 1.6%
794.86 0.0 KB 0.0% 0.00</div><div>Jul 16 21:00:00 - 21:59:59 2557273
1.4% 710.35 0.0 KB 0.0% 0.00</div><div>Jul 16 22:00:00 - 22:59:59
2476205 1.3% 687.83 0.0 KB 0.0% 0.00</div><div>Jul 16 23:00:00 -
23:59:59 2470653 1.3% 686.29 0.0 KB 0.0% 0.00</div><div>Jul 17
00:00:00 - 00:59:59 2377684 1.3% 660.47 0.0 KB 0.0%
0.00</div><div>Jul 17 01:00:00 - 01:59:59 2214251 1.2% 615.07 0.0 KB
0.0% 0.00</div><div>Jul 17 02:00:00 - 02:59:59 2160533 1.2% 600.15
0.0 KB 0.0% 0.00</div><div>Jul 17 03:00:00 - 03:59:59 2138072 1.2%
593.91 0.0 KB 0.0% 0.00</div><div>Jul 17 04:00:00 - 04:59:59 2064017
1.1% 573.34 0.0 KB 0.0% 0.00</div><div>Jul 17 05:00:00 - 05:59:59
1975211 1.1% 548.67 0.0 KB 0.0% 0.00</div><div>Jul 17 06:00:00 -
06:59:59 1902269 1.0% 528.41 0.0 KB 0.0% 0.00</div><div>Jul 17
07:00:00 - 07:59:59 1859862 1.0% 516.63 0.0 KB 0.0%
0.00</div><div>Jul 17 08:00:00 - 08:59:59 1826617 1.0% 507.39 0.0 KB
0.0% 0.00</div><div>Jul 17 09:00:00 - 09:59:59 1803042 1.0% 500.85
0.0 KB 0.0% 0.00</div><div>Jul 17 10:00:00 - 10:59:59 1779735 1.0%
494.37 0.0 KB 0.0% 0.00</div><div>Jul 17 11:00:00 - 11:59:59 1724235
0.9% 478.95 0.0 KB 0.0% 0.00</div><div>Jul 17 12:00:00 - 12:59:59
1694753 0.9% 470.76 0.0 KB 0.0% 0.00</div><div>Jul 17 13:00:00 -
13:59:59 1687997 0.9% 468.89 0.0 KB 0.0% 0.00</div><div>Jul 17
14:00:00 - 14:59:59 1689864 0.9% 469.41 0.0 KB 0.0%
0.00</div><div>Jul 17 15:00:00 - 15:59:59 1667083 0.9% 463.08 0.0 KB
0.0% 0.00</div><div>Jul 17 16:00:00 - 16:59:59 1614929 0.9% 448.59
0.0 KB 0.0% 0.00</div><div>Jul 17 17:00:00 - 17:59:59 1551492 0.8%
430.97 0.0 KB 0.0% 0.00</div><div>Jul 17 18:00:00 - 18:59:59 1510100
0.8% 419.47 0.0 KB 0.0% 0.00</div><div>Jul 17 19:00:00 - 19:59:59
1516064 0.8% 421.13 0.0 KB 0.0% 0.00</div><div>Jul 17 20:00:00 -
20:59:59 1504238 0.8% 417.84 0.0 KB 0.0% 0.00</div><div>Jul 17
21:00:00 - 21:59:59 1511102 0.8% 419.75 0.0 KB 0.0%
0.00</div><div>Jul 17 22:00:00 - 22:59:59 1498772 0.8% 416.33 0.0 KB
0.0% 0.00</div><div>Jul 17 23:00:00 - 23:59:59 1459980 0.8% 405.55
0.0 KB 0.0% 0.00</div><div>Jul 18 00:00:00 - 00:59:59 1414708 0.8%
392.97 0.0 KB 0.0% 0.00</div><div>Jul 18 01:00:00 - 01:59:59 1404954
0.8% 390.26 0.0 KB 0.0% 0.00</div><div>Jul 18 02:00:00 - 02:59:59
1376430 0.7% 382.34 0.0 KB 0.0% 0.00</div><div>Jul 18 03:00:00 -
03:59:59 1378259 0.7% 382.85 0.0 KB 0.0% 0.00</div><div>Jul 18
04:00:00 - 04:59:59 1390281 0.8% 386.19 0.0 KB 0.0%
0.00</div><div>Jul 18 05:00:00 - 05:59:59 1386335 0.8% 385.09 0.0 KB
0.0% 0.00</div><div>Jul 18 06:00:00 - 06:59:59 1355294 0.7% 376.47
0.0 KB 0.0% 0.00</div><div>Jul 18 07:00:00 - 07:59:59 1327220 0.7%
368.67 0.0 KB 0.0% 0.00</div><div>Jul 18 08:00:00 - 08:59:59 1296572
0.7% 360.16 0.0 KB 0.0% 0.00</div><div>Jul 18 09:00:00 - 09:59:59
1276394 0.7% 354.55 0.0 KB 0.0% 0.00</div><div>Jul 18 10:00:00 -
10:59:59 1280991 0.7% 355.83 0.0 KB 0.0% 0.00</div><div>Jul 18
11:00:00 - 11:59:59 1276734 0.7% 354.65 0.0 KB 0.0%
0.00</div><div>Jul 18 12:00:00 - 12:59:59 1330133 0.7% 369.48 0.0 KB
0.0% 0.00</div><div>Jul 18 13:00:00 - 13:59:59 1321197 0.7% 367.00
0.0 KB 0.0% 0.00</div><div>Jul 18 14:00:00 - 14:59:59 1270985 0.7%
353.05 0.0 KB 0.0% 0.00</div><div>Jul 18 15:00:00 - 15:59:59 1251052
0.7% 347.51 0.0 KB 0.0% 0.00</div><div>Jul 18 16:00:00 - 16:59:59
1238624 0.7% 344.06 0.0 KB 0.0% 0.00</div><div>Jul 18 17:00:00 -
17:59:59 1227250 0.7% 340.90 0.0 KB 0.0% 0.00</div><div>Jul 18
18:00:00 - 18:59:59 1203798 0.7% 334.39 0.0 KB 0.0%
0.00</div><div>Jul 18 19:00:00 - 19:59:59 1225960 0.7% 340.54 0.0 KB
0.0% 0.00</div><div>Jul 18 20:00:00 - 20:59:59 1221275 0.7% 339.24
0.0 KB 0.0% 0.00</div><div>Jul 18 21:00:00 - 21:59:59 1199617 0.7%
333.23 0.0 KB 0.0% 0.00</div><div>Jul 18 22:00:00 - 22:59:59 1178009
0.6% 327.22 0.0 KB 0.0% 0.00</div><div>Jul 18 23:00:00 - 23:59:59
1154628 0.6% 320.73 0.0 KB 0.0% 0.00</div><div>Jul 19 00:00:00 -
00:59:59 1145227 0.6% 318.12 0.0 KB 0.0% 0.00</div><div>Jul 19
01:00:00 - 01:59:59 1111125 0.6% 308.65 0.0 KB 0.0%
0.00</div><div>Jul 19 02:00:00 - 02:59:59 1095739 0.6% 304.37 0.0 KB
0.0% 0.00</div><div>Jul 19 03:00:00 - 03:59:59 1093542 0.6% 303.76
0.0 KB 0.0% 0.00</div><div>Jul 19 04:00:00 - 04:59:59 1089209 0.6%
302.56 0.0 KB 0.0% 0.00</div><div>Jul 19 05:00:00 - 05:59:59 1090842
0.6% 303.01 0.0 KB 0.0% 0.00</div><div>Jul 19 06:00:00 - 06:59:59
1074421 0.6% 298.45 0.0 KB 0.0% 0.00</div><div>Jul 19 07:00:00 -
07:59:59 1054212 0.6% 292.84 0.0 KB 0.0% 0.00</div><div>Jul 19
08:00:00 - 08:59:59 1044447 0.6% 290.12 0.0 KB 0.0%
0.00</div><div>Jul 19 09:00:00 - 09:59:59 931031 0.5% 258.62 0.0 KB
0.0% 0.00</div><div>Jul 19 10:00:00 - 10:59:59 1079244 0.6% 299.79
0.0 KB 0.0% 0.00</div><div>Jul 19 11:00:00 - 11:59:59 1069259 0.6%
297.02 0.0 KB 0.0% 0.00</div><div>Jul 19 12:00:00 - 12:59:59 1067895
0.6% 296.64 0.0 KB 0.0% 0.00</div><div>Jul 19 13:00:00 - 13:59:59
1056197 0.6% 293.39 0.0 KB 0.0% 0.00</div><div>Jul 19 14:00:00 -
14:59:59 1064508 0.6% 295.70 0.0 KB 0.0% 0.00</div><div>Jul 19
15:00:00 - 15:59:59 1053532 0.6% 292.65 0.0 KB 0.0%
0.00</div><div>Jul 19 16:00:00 - 16:59:59 1035573 0.6% 287.66 0.0 KB
0.0% 0.00</div><div>Jul 19 17:00:00 - 17:59:59 1017242 0.6% 282.57
0.0 KB 0.0% 0.00</div><div>Jul 19 18:00:00 - 18:59:59 1019435 0.6%
283.18 0.0 KB 0.0% 0.00</div><div>Jul 19 19:00:00 - 19:59:59 1013209
0.5% 281.45 0.0 KB 0.0% 0.00</div><div>Jul 19 20:00:00 - 20:59:59
1003259 0.5% 278.68 0.0 KB 0.0% 0.00</div><div>Jul 19 21:00:00 -
21:59:59 998980 0.5% 277.49 0.0 KB 0.0% 0.00</div><div>Jul 19
22:00:00 - 22:59:59 999129 0.5% 277.54 0.0 KB 0.0%
0.00</div><div>Jul 19 23:00:00 - 23:59:59 1005058 0.5% 279.18 0.0 KB
0.0% 0.00</div><div>Jul 20 00:00:00 - 00:59:59 1004154 0.5% 278.93
0.0 KB 0.0% 0.00</div><div>Jul 20 01:00:00 - 01:59:59 983326 0.5%
273.15 0.0 KB 0.0% 0.00</div><div>Jul 20 02:00:00 - 02:59:59 984133
0.5% 273.37 0.0 KB 0.0% 0.00</div><div>Jul 20 03:00:00 - 03:59:59
956548 0.5% 265.71 0.0 KB 0.0% 0.00</div><div>Jul 20 04:00:00 -
04:59:59 955865 0.5% 265.52 0.0 KB 0.0% 0.00</div><div>Jul 20
05:00:00 - 05:59:59 949230 0.5% 263.68 0.0 KB 0.0%
0.00</div><div>Jul 20 06:00:00 - 06:59:59 938727 0.5% 260.76 0.0 KB
0.0% 0.00</div><div>Jul 20 07:00:00 - 07:59:59 947608 0.5% 263.22
0.0 KB 0.0% 0.00</div><div>Jul 20 08:00:00 - 08:59:59 955909 0.5%
265.53 0.0 KB 0.0% 0.00</div><div>Jul 20 09:00:00 - 09:59:59 951293
0.5% 264.25 0.0 KB 0.0% 0.00</div><div>Jul 20 10:00:00 - 10:59:59
939124 0.5% 260.87 0.0 KB 0.0% 0.00</div><div>Jul 20 11:00:00 -
11:59:59 945338 0.5% 262.59 0.0 KB 0.0% 0.00</div><div>Jul 20
12:00:00 - 12:59:59 913587 0.5% 253.77 0.0 KB 0.0%
0.00</div><div>Jul 20 13:00:00 - 13:59:59 926263 0.5% 257.30 0.0 KB
0.0% 0.00</div><div>Jul 20 14:00:00 - 14:59:59 930761 0.5% 258.54
0.0 KB 0.0% 0.00</div><div>Jul 20 15:00:00 - 15:59:59 908011 0.5%
252.23 0.0 KB 0.0% 0.00</div><div>Jul 20 16:00:00 - 16:59:59 863137
0.5% 239.76 0.0 KB 0.0% 0.00</div><div>Jul 20 17:00:00 - 17:59:59
851113 0.5% 236.42 0.0 KB 0.0% 0.00</div><div>Jul 20 18:00:00 -
18:59:59 843252 0.5% 234.24 0.0 KB 0.0% 0.00</div><div>Jul 20
19:00:00 - 19:25:57 218494 0.1% 140.33 0.0 KB 0.0%
0.00</div></div>