There are now 766 calls vs 1599 in your previous paste. I would have expected more, less does not help :) If it is the pl script execution that takes 30s, it should not come from network latencies. On Tue, 18 Apr 2017 at 13:09 Michael Kuhn <mik@adminkuhn.ch> wrote:
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
_______________________________________________ Koha mailing list http://koha-community.org Koha@lists.katipo.co.nz https://lists.katipo.co.nz/mailman/listinfo/koha