[Koha] Slow Koha OPAC login process

[Tomas Cohen Arazi]

output_with_http_headers is a function that calls the templates code. I
would bet it is an IO problem.

Please run iotop while reproducing the problem. I would expect to see some
iowait. Do you have template_cache_dir set? Is it on a fast hard drive? You
could try mounting a tmpfs filesystem in there and compare results.

Also for debugging you should better use plack's tools instead:

enable 'Debug', panels => [ qw(DBITrace Memory Timer) ];

In plack.psgi and even the NTYProf panel. Maybe we need to improve the docs
for this.

El mié., 10 de may. de 2017 6:25 AM, Michael Kuhn <mik at adminkuhn.ch>
escribió:

> Hi
>
> Yesterday Mark Alexander wrote:
>
> > Excerpts from Michael Kuhn's message of 2017-05-09 19:57:51 +0200:
> >> With my poor Perl knowledge I have now measured the execution time of
> >> the various parts of script "opac-user.pl". As I found out everything
> is
> >> always very fast (using less than 1 second execution time) except the
> >> very last function in this script which looks as follows:
> >>
> >> output_with_http_headers $cgi, $cookie, $template->output,
> $content_type;
> >
> > I am not familiar with this code, but I took a quick look at it just
> > now.  If I were trying to debug this problem, I would measure the
> > execution time of the last statement in output_with_http_headers:
> >
> >     print $query->header($options), $data;
> >
> > If I understand correctly, this print is going to send a big blob of
> > HTML (preceded by a header) via Apache to the client.  If Apache is
> > timing out for some reason, perhaps that would cause a big delay in
> > this print statement.
>
> It doesn't seem to be the function itself that takes the time.
>
> I have now changed the scripts "output-user.pl" and "Output.pm" as
> follows so they will give me the time at certain moments:
>
> 1. Print time at the very beginning of script "output-user.pl"
>
> 2. Print time just before calling function
> "output_html_with_http_headers" in script "output-user.pl"
>
> 3. Print time at the very beginning of script "Output.pm"
>
> 4. Print time at the very beginning in function
> "output_html_with_http_headers" in script "Output.pm"
>
> 5. Print time at the end in function "output_html_with_http_headers" in
> script "Output.pm"
>
> 6. Print time after calling function "output_html_with_http_headers" in
> script "output-user.pl"
>
> I would have expected the output in this order, but in fact I get the
> following sequence:
>
> 3. 09:18:44 START (Output.pm called by plack.psgi)
> 1. 09:18:44 START opac-user.pl / 1494407924.86717
> 2. 09:18:45 START opac-user.pl (right before function) / 1494407925.45211
> * 4. 09:19:17 START function (in Output.pm) called by opac-user.pl
> * 5. 09:19:17 END   function (in Output.pm) called by opac-user.pl
> *    TIME  function: 0.0027921199798584
> 6. 09:19:17 END   opac-user.pl / 1494407957.18462
>     TIME : 32.3174500465393
>
> If I disable Plack I get the following sequence (no output for 3.):
>
> 1. 09:20:48 START opac-user.pl / 1494408048.50046
> 2. 09:20:48 START opac-user.pl (right before function) / 1494408048.74332
> * 4. 09:21:20 START function (in Output.pm) called by opac-user.pl
> * 5. 09:21:20 END   function (in Output.pm) called by opac-user.pl
> *    TIME  function: 0.00142717361450195
> 6. 09:21:20 END   opac-user.pl / 1494408080.4559
>     TIME : 31.9554369449615
>
> However everything works very fast and fine in script "opac-user.pl"
> until the function "output_html_with_http_headers" is called. Then it
> takes about 32 seconds until the function
> "output_html_with_http_headers" actually starts its work, the function
> itself then works very fast again.
>
> Does anybody have an idea what could cause this very annoying delay
> before the function is actually starting its work?
>
> I'm not sure if there is a connection but when I restart Koha using
> "service koha-common" it is sometimes very fast and sometimes it takes
> about 30 seconds too.
>
> Best wishes: Michael
> --
> Geschäftsführer · Diplombibliothekar BBS, Informatiker eidg. Fachausweis
> Admin Kuhn GmbH · Pappelstrasse 20 · 4123 Allschwil · Schweiz
> T 0041 (0)61 261 55 61 · E mik at adminkuhn.ch · W www.adminkuhn.ch
> _______________________________________________
> Koha mailing list  http://koha-community.org
> Koha at lists.katipo.co.nz
> https://lists.katipo.co.nz/mailman/listinfo/koha
>
-- 
Tomás Cohen Arazi
Theke Solutions (https://theke.io <http://theke.io/>)
✆ +54 9351 3513384
GPG: B2F3C15F