Feed problem
Russ Allbery
rra at stanford.edu
Thu Oct 19 19:44:23 UTC 2000
Brennon Church <ctsbac at cts.com> writes:
> Okay, here is yesterday's INND timer report:
> article cancel 00:41:52.051 2.9% 133677 5.677 18.792 257.067
> article control 00:41:35.093 2.9% 132858 5.723 18.780 257.133
> article link 00:00:00.000 0.0% 0 0.000 0.000 0.000
> article write 06:13:25.766 25.9% 941894 9.085 23.788 39.102
> history grep 00:09:15.291 0.6% 54927 0.345 10.110 187.208
> history lookup 01:59:58.795 8.3% 6022207 0.274 1.195 6.768
> history sync 00:01:34.792 0.1% 108916 0.000 0.870 41.283
> history write 05:27:47.534 22.8% 1087561 10.378 18.084 55.422
> idle 01:08:03.738 4.7% 24779260 0.081 0.165 1.097
> overview write 00:00:00.000 0.0% 0 0.000 0.000 0.000
> perl filter 05:20:25.811 22.3% 1006476 6.623 19.102 31.227
> site send 00:01:14.328 0.1% 941894 0.021 0.079 0.606
> TOTAL: 23:59:29.006 21:45:13.199 90.7% - - - -
> So it would appear that the three points of concern are article write,
> history write, and perl filter. I've disabled the perl filter for the
> moment. I'm guessing that the article write is also anomalously high.
I wish I knew why people were seeing these anomalously high history write
times, as I'm not seeing this on either of my machines. My test server
(which is a dual-processor SPARC 20 and therefore is currently running
pretty close to flat out) sees:
INND timer:
Code region Time Pct Invoked Min(ms) Avg(ms) Max(ms)
article cancel 00:08:55.116 0.6% 39101 1.928 13.685 28.799
article cleanup 05:31:49.711 23.0% 1069973 9.886 18.608 31.542
article control 00:08:37.715 0.6% 38048 1.895 13.607 28.826
article link 00:00:00.000 0.0% 0 0.000 0.000 0.000
article write 00:42:36.823 3.0% 305107 1.823 8.380 25.887
hisgrep 00:02:05.629 0.1% 21963 0.000 5.720 13.364
history lookup 02:02:15.751 8.5% 7551193 0.031 0.971 2.947
history sync 00:00:37.591 0.0% 108341 0.277 0.347 0.621
history write 01:49:44.088 7.6% 1081708 0.827 6.087 16.183
idle 03:04:15.381 12.8% 6039064 1.000 1.831 7.012
overview write 00:00:00.000 0.0% 0 0.000 0.000 0.000
perl filter 02:31:46.288 10.5% 1054228 5.866 8.638 12.838
python filter 00:00:00.000 0.0% 0 0.000 0.000 0.000
site send 00:14:21.046 1.0% 585582 0.856 1.470 2.336
TOTAL: 24:00:07.414 16:17:05.139 67.8% - - - -
6ms per history write, and my *max* history write time is smaller than
your average. (Still losing lots and lots of time and I'm not sure where
it's going.) newsfeed.stanford.edu, which is a beefier system with much
better disks (headwall is on a SPARC StorageArray) has:
INND timer:
Code region Time Pct Invoked Min(ms) Avg(ms) Max(ms)
article cancel 00:02:15.348 0.2% 38494 0.489 3.516 13.789
article control 00:02:08.628 0.1% 37441 0.462 3.435 13.529
article link 00:00:00.000 0.0% 0 0.000 0.000 0.000
article write 00:19:32.968 1.4% 304117 1.089 3.857 11.286
history grep 00:00:14.559 0.0% 22309 0.015 0.653 2.215
history lookup 00:16:39.519 1.2% 11379463 0.004 0.088 0.350
history sync 00:00:12.106 0.0% 108420 0.078 0.112 0.275
history write 00:16:44.398 1.2% 1082577 0.158 0.928 3.557
idle 17:00:49.699 70.9% 29734315 1.384 2.060 3.356
overview write 00:00:00.000 0.0% 0 0.000 0.000 0.000
perl filter 00:53:43.390 3.7% 1032537 2.128 3.122 4.402
site send 00:19:26.628 1.4% 579839 1.402 2.012 2.570
TOTAL: 24:00:01 19:11:47.243 80.0% - - - -
Is Solaris just handling something significantly better or something?
newsfeed is running INN 2.3.0; headwall is running a current snapshot from
a couple of weeks ago.
--
Russ Allbery (rra at stanford.edu) <http://www.eyrie.org/~eagle/>
More information about the inn-workers
mailing list