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 <m...@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 > _______________________________________________ Koha mailing list http://koha-community.org Koha@lists.katipo.co.nz https://lists.katipo.co.nz/mailman/listinfo/koha