[Koha] Slow Koha OPAC login process

[Michael Kuhn]

Hi Jonathan

> I do not understand why %time is 0, should not be, especially if the
> process takes 30s
> Try to get the most complete output with a long query, then a complete
> output with a normal query. Maybe we will see the differences between both.
> You should write a script not to have to retrieve the pid manually,
> something using `ps aux | grep opac-user.pl | tr -s ' ' | cut -d' ' -f2`

Here's another attempt:

1. I made a login attempt.

2. As soon as I saw the query that was taking 99% of the CPU I executed 
the following command in another terminal:

strace -c -p $(ps aux | grep -v grep | grep opac-user.pl | tr -s ' ' | 
cut -d' ' -f2)

When the login finally succeeded I ended strace with CTRL+C. This is the 
output:

Process 64958 attached
^CProcess 64958 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
   0.00    0.000000           0         5           read
   0.00    0.000000           0         8           write
   0.00    0.000000           0         2           close
   0.00    0.000000           0         1           stat
   0.00    0.000000           0         2           fstat
   0.00    0.000000           0         3           lseek
   0.00    0.000000           0         2           mmap
   0.00    0.000000           0       534           brk
   0.00    0.000000           0        66         2 rt_sigaction
   0.00    0.000000           0       136           rt_sigprocmask
   0.00    0.000000           0         1         1 ioctl
   0.00    0.000000           0         1           select
   0.00    0.000000           0         1           getsockopt
   0.00    0.000000           0         1           kill
   0.00    0.000000           0         1           fcntl
   0.00    0.000000           0         1           chdir
   0.00    0.000000           0         1           prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                   766         3 total

Does this help?

 > Try to get the most complete output with a long query, then a complete
 > output with a normal query. Maybe we will see the differences between
 > both.

It is not possible to execute strace for a "normal" login attempt like 
this because usually an attempt to log into the Koha OPAC is very quick, 
so it is not possible to first click the "Login" button and then execute 
strace in the terminal because meanwhile the login has already succeeded 
and the above command will find no PID...

Is it maybe possible to measure the execution time within the sections 
of the Perl script "opac-user.pl"?

Somehow the whole thing seems to me like some kind of network problem 
(DNS? latency? timeout?) but I wouldn't know how to find out since I 
don't really understand what "opac-user.pl" does.

Regards, Michael