From: Dobrica Pavlinusic
Date: Tue, 25 Jul 2006 12:24:24 +0200

On Mon, Jul 24, 2006 at 10:44:29PM +0200, Josip Rodin wrote:

On Wed, Jul 19, 2006 at 08:49:07PM +0200, Josip Rodin wrote:
> Instalirao sam eAccelerator i funkcionira, ali svejedno vidim tu pauzu od
> par sekundi prije loadanja svake stranice, i nakon sto je ucacheirao :(
> Mislim da je sad manja pauza (tri, a prije bi bilo pet sekundi), ali
> svejedno postoji.
Nakon nekoliko dana se opet jednako ponasa. Status je na:
https://intwww-strix.carnet.hr/~joy/foo.php
Sad sam mu poduplao shared_buffers i sort_mem, na 8K svaki. Opet malo
reloadao tako da se eAccelerator ukljuci propisno, ali sve je isto.
Koji mu je vrag? Je li sad CPU-bound ili sta? Prema top(1) outputu izgleda
da najvise radi PostgreSQL.

Uključio sam SQL i module profile, u
/data/carnet-int-www/strix/etc/intwww.conf.php:

$_SQL_debug = true;
$_log_modtime = true;

i prosurfao malo. Onda sam pokrenuo profile:

dpavlin@tau:/data/carnet-int-www/strix/utils/profile$ ./profile-modtime.pl
module                    s:avg        total    nr   lid    cat
mod_userlog            1034.040    25851.005    25  1867   5148
mod_docman              139.231      417.692     3  1909   5102
mod_sitemap             121.114      242.227     2   593   5148
mod_kmap_browse          71.340      142.681     2   598   5147
mod_calendar             70.698     1767.459    25   601   5148
mod_navigation           42.765     1069.128    25     6   5148
mod_news                 38.600      115.801     3   622      1
mod_multistatic_c        17.893      268.390    15    96   5122
mod_hnav_bottom          11.292      282.300    25    12   5148
mod_links2                7.439       22.318     3   602   5113
mod_banner                6.699      167.476    25    14   5148
mod_hnav_top              6.657      166.435    25    11   5148
mod_navpos                5.879      146.984    25    15   5148
mod_mycn_redirect         5.523        5.523     1  1446   5102
mod_dict_global           5.123       10.247     2  2169   5147
mod_subscribe_kat         3.928       98.197    25  1936   5148
mod_rss                   3.096       27.868     9  2178      1
mod_iframe                2.606        5.212     2  1717   5932
mod_dictionary            2.383        4.766     2   596   5147
mod_static3               1.756        5.269     3  1703      1
mod_secerror              1.509        4.527     3    16     10

dpavlin@tau:/data/carnet-int-www/strix/utils/profile$ ./profile-sql.pl
module                    s:avg        total    nr   lid    cat
mod_userlog              74.049    26065.076   352  1867   5148
mod_kmap_browse           8.847      159.251    18   598   5147
mod_docman                2.426      354.245   146  1909   5102
-                         2.329       11.645     5     -      1
mod_sitemap               1.935      174.150    90   593   5148
mod_navigation            1.911     1106.249   579     6   5148
mod_hnav_top              1.903      380.615   200    11   5148
mod_hnav_bottom           1.879      495.974   264    12   5148
mod_news                  1.606      303.457   189   622      1
mod_calendar              1.599     2978.299  1863   601   5148
mod_navpos                1.598      359.644   225    15   5148
mod_mycn_redirect         1.556       14.004     9  1446   5102
mod_subscribe_kat         1.555      317.278   204  1936   5148
layout                    1.516     1414.340   933     -   5148
mod_dict_global           1.510       27.174    18  2169   5147
mod_iframe                1.480       23.676    16  1717   5932
mod_multistatic_c         1.476      396.914   269    96   5122
mod_banner                1.467      356.581   243    14   5148
mod_secerror              1.385       37.399    27    16     10
mod_dictionary            1.376       22.016    16   596   5147
mod_login                 1.355      245.276   181     8   5148

Našao sam krvica, mod_userlog koji je u prosjeku spor (prva tablica je
prosjek izvršenja modula (više od sekundu) a druga prosjek jednog SQL
query-ja

Onda sam iskreirao nekoliko indeksa (varam pa znam zašto je userlog
spor :-)

intwww=> create index userlog_kid_idx on userlog(kid);
CREATE INDEX
intwww=> create index userlog_timestamp_idx on userlog(timestamp);
CREATE INDEX
intwww=> create index userlog_uid_idx on userlog(uid);
CREATE INDEX
intwww=> VACUUM ANALYZE userlog;
VACUUM

i (nakon što sam pokrenuo skriptu napisanu za resetiranje logova jer
nema sudo na /var/strix :-)

dpavlin@tau:/data/carnet-int-www/strix/utils/profile$ ./profile-modtime.pl
module                    s:avg        total    nr   lid    cat
mod_docman              130.923      392.769     3  1909   5102
mod_kmap_browse          69.483       69.483     1   598   5147
mod_navigation           45.702      502.726    11     6   5148
mod_userlog              23.495      258.442    11  1867   5148
mod_multistatic_c        17.307      138.453     8    96   5122
mod_hnav_bottom          11.986      131.845    11    12   5148
mod_links2                8.595       17.190     2   602   5113
mod_calendar              8.563       94.190    11   601   5148
mod_hnav_top              6.965       76.612    11    11   5148
mod_sitemap               6.740        6.740     1   593   5148
mod_navpos                5.706       62.763    11    15   5148
mod_banner                5.520       60.717    11    14   5148
mod_dict_global           5.080        5.080     1  2169   5147
mod_mycn_redirect         4.736        4.736     1  1446   5102
mod_subscribe_kat         3.898       42.881    11  1936   5148
mod_dictionary            2.148        2.148     1   596   5147
mod_admin_qlinks          0.397        4.365    11     9   5148
mod_login                 0.179        1.968    11     8   5148
mod_search3               0.117        1.288    11     7   5148
mod_date                  0.104        1.139    11    13   5148

Victory. Jel' brži?