Use `strace -c -p PID` and paste the whole output please (hastebin or similar)
On Tue, 18 Apr 2017 at 10:23 Michael Kuhn <[email protected]> wrote: > Hi Marc and Jonatahn > > Marc wrote: > > > What version of Koha is it? > > We're running a new host with Debian GNU/Linux 8 and Koha 16.11.04. > > > Do you have errors or messages in the log files? > > You can monitor them using tail. At first place I would have a look at > > opac-error.log and plack-error.log, > > something like: tail -f opac-error.log > > No, they are no errors or messages. As soon as the login attempt in the > Koha OPAC is made the, the following process taking 99% of the CPU can > be seen with "top" or "ps -ef": > > phsh-ko+ 62293 26131 30 14:39 ? 00:00:22 > /usr/share/koha/opac/cgi-bin/opac/opac-user.pl > > When the login finally succeeds (after maybe 30 seconds) the following > is written in the file "plack.log": > > 178.238.175.156 - - [18/Apr/2017:14:40:28 +0200] "POST > /opac/opac-user.pl HTTP/1.1" 200 26320 > "http://bibliothek.phsh.ch/cgi-bin/koha/opac-main.pl?logout.x=1"; > "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:52.0) Gecko/20100101 > Firefox/52.0" > > But nothing is written to the file "opac-error.log". > > Jonathan wrote: > > > In production I am not aware of something you could do (well there is > > strace if you are patient and quick :D) > > In test you could use a code profiler or tell mysql to log slow > > queries. > > But the code profiler will be hazardous if it does not happens 100% > > of the time and htop would have told you if mysql was the culprit. > > I activated the Mysql slow query log during runtime, using the following > commands: > > mysql> set global log_slow_queries = 1; > mysql> set global slow_query_log_file = '/tmp/slow.txt'; > > Then I made another login attempt in the Koha OPAC. The file > "/tmp/slow.txt" is created but it doesn't list any slow query, so I > think the problem is not in the query itself: > > # more /tmp/slow.txt > /usr/sbin/mysqld, Version: 5.5.54-0+deb8u1 ((Debian)). started with: > Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock > Time Id Command Argument > > Then I made some attempt to use strace, but I'm not sure how to really > use it and especially how to interpret the output... So what i've tried is: > > 1. I made a login attempt > > 2. As soon as I saw the query was taking 99% of the CPU i picked the PID > (here: 62503) from the output of "top" and executed the following command: > > # strace -p 62503 > > The output then looked like the folloing (full output at the end of this > email): > > Process 62503 attached > > followed by many many lines like the following: > > brk(0xb63b000) = 0xb63b000 > brk(0xb65c000) = 0xb65c000 > brk(0xb67d000) = 0xb67d000 > > Then after about 30 seconds it says: > [SKIP] > > At this point the login attempt finally succeeds. Actually I have no > idea what this means - can you please help? > > 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 <+41%2061%20261%2055%2061> · E [email protected] · > W www.adminkuhn.ch > _______________________________________________ > Koha mailing list http://koha-community.org > [email protected] > https://lists.katipo.co.nz/mailman/listinfo/koha > _______________________________________________ Koha mailing list http://koha-community.org [email protected] https://lists.katipo.co.nz/mailman/listinfo/koha
