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 <[email protected]> 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 [email protected] · W www.adminkuhn.ch > _______________________________________________ > Koha mailing list http://koha-community.org > [email protected] > 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 _______________________________________________ Koha mailing list http://koha-community.org [email protected] https://lists.katipo.co.nz/mailman/listinfo/koha
