php eating cpu

I am running suse 10.0 and have noticed recently that after a couple of days after rebooting the system php starts eating my cpu and everthing become slow.
here is the output of TOP
Any ideas?

top - 22:53:32 up 2 days, 15:02, 3 users, load average: 2.32, 2.24, 1.75
Tasks: 125 total, 3 running, 122 sleeping, 0 stopped, 0 zombie
Cpu(s): 94.0% us, 6.0% sy, 0.0% ni, 0.0% id, 0.0% wa, 0.0% hi, 0.0% si
Mem: 1993620k total, 1559912k used, 433708k free, 205264k buffers
Swap: 3156720k total, 0k used, 3156720k free, 669076k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6948 root 25 0 27828 7192 3264 R 97.7 0.4 1341:12 php
6864 root 15 0 56444 34m 3120 S 1.7 1.8 5:54.38 X
12362 steve 16 0 5484 1208 852 R 0.3 0.1 0:01.94 top
1 root 16 0 740 280 236 S 0.0 0.0 0:00.78 init
2 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
3 root 10 -5 0 0 0 S 0.0 0.0 0:00.08 events/0
4 root 10 -5 0 0 0 S 0.0 0.0 0:00.02 khelper
5 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kthread
9 root 20 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid
562 root 10 -5 0 0 0 S 0.0 0.0 0:00.02 kblockd/0
599 root 20 0 0 0 0 S 0.0 0.0 0:00.00 pdflush
600 root 15 0 0 0 0 S 0.0 0.0 0:00.04 pdflush
602 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 aio/0
601 root 25 0 0 0 0 S 0.0 0.0 0:00.00 kswapd0
1196 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 kseriod
1356 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 ata/0
1370 root 20 0 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
1371 root 21 0 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_1
1409 root 15 0 0 0 0 S 0.0 0.0 0:00.31 kjournald
2369 root 15 0 0 0 0 S 0.0 0.0 0:00.00 kjournald
2547 root 13 -4 7128 1072 652 S 0.0 0.1 0:00.90 udevd
2897 root 20 0 0 0 0 S 0.0 0.0 0:00.00 shpchpd_event
3039 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 khubd
3432 messageb 16 0 15156 1748 1428 S 0.0 0.1 0:00.32 dbus-daemon
3472 root 16 0 8120 980 732 S 0.0 0.0 0:00.35 syslog-ng
3498 root 16 0 2840 780 436 S 0.0 0.0 0:00.00 klogd
4594 root 18 0 7912 1456 1128 S 0.0 0.1 0:00.01 mysqld_safe
4618 root 16 0 10040 828 676 S 0.0 0.0 0:00.02 resmgrd
4817 mysql 16 0 119m 22m 4132 S 0.0 1.1 6:11.59 mysqld
4832 root 16 0 5824 740 612 S 0.0 0.0 0:00.00 dhcpcd
5067 nobody 15 0 4660 552 444 S 0.0 0.0 0:00.02 portmap
5145 root 15 0 2568 516 428 S 0.0 0.0 0:00.00 courierlogger
5146 root 16 0 12176 688 536 S 0.0 0.0 0:00.00 authdaemond
5150 root 16 0 9056 872 712 S 0.0 0.0 0:00.00 kdm
5162 root 15 0 2572 584 488 S 0.0 0.0 0:00.00 acpid
5182 root 17 0 19904 1492 1160 S 0.0 0.1 0:00.00 saslauthd
5213 root 16 0 16692 884 680 S 0.0 0.0 0:00.05 authdaemond
5214 root 16 0 16692 884 680 S 0.0 0.0 0:00.01 authdaemond
5215 root 16 0 16692 884 680 S 0.0 0.0 0:00.03 authdaemond
5216 root 16 0 16692 884 680 S 0.0 0.0 0:00.02 authdaemond
5217 root 16 0 16692 884 680 S 0.0 0.0 0:00.02 authdaemond
5221 root 18 0 2564 440 368 S 0.0 0.0 0:00.00 courierlogger

and apache error log


[Sat Jun 16 22:15:02 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:15:17 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:15:17 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:17:40 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:17:40 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:17:41 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:17:41 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:18:58 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:18:58 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:20:19 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:20:19 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:26:48 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:26:48 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:31:29 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:31:29 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:32:11 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:32:11 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:37:51 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:37:51 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:48:34 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:48:34 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:48:38 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:48:38 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:55:15 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:55:15 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:56:35 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:56:35 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:56:48 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:56:48 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:57:19 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:57:19 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:57:28 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 22:57:28 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 23:03:01 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 23:03:01 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 23:03:09 2007] [notice] caught SIGTERM, shutting down
[Sat Jun 16 23:05:29 2007] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec2)
[Sat Jun 16 23:05:32 2007] [notice] Apache/2.0.54 (Linux/SUSE) configured -- resuming normal operations
[Sat Jun 16 23:12:07 2007] [error] an unknown filter was not added: PHP
[Sat Jun 16 23:12:07 2007] [error] an unknown filter was not added: PHP

shajazzi

 

Not sure what is causing the high CPU load for you (for sure it's not the error from your apache log)
A fix for the "an unknown filter was not added: PHP" error can be found here: http://www.howtoforge.com/forums/showthread.php?t=4770

 

OK,
i have followed your link and done as suggested and everything seemed ok for a while, however i am still getting 90% plus of my cpu eaten by PHP.
I notice that the proccesss starts at midnight, so i checked crontab and this seems fine this the output.

30 00 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/ftp_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/cleanup.php &> /dev/null
0 4 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/webalizer.php &> /dev/null
0,30 * * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/check_services.php &> /dev/null
15 3,15 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/quota_msg.php &> /dev/null
40 00 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/traffic.php &> /dev/null
05 02 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/backup.php &> /dev/null
0 4 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/awstats.php &> /dev/null
0,15,30,45 * * * * /root/zoneupdate.sh &> /dev/null

any ideas please?

shajazzi

 

Check if they are sending spam through php on your server. That caused a very high load on my server a few days ago.

 

Thanks Jorem,
I have checked my mail logs and all seems fine.

Jun 21 20:09:16 mybox postfix/cleanup[19132]: B368052C21E: message-id=<[email protected]>
Jun 21 20:09:16 mybox postfix/qmgr[15296]: B368052C21E: from=<[email protected]>, size=379, nrcpt=1 (queue active)
Jun 21 20:09:16 mybox postfix/local[19149]: B368052C21E: to=<[email protected]>, relay=local, delay=0, status=sent (delivered to command: /usr/bin/procmail -f-)
Jun 21 20:09:16 mybox postfix/qmgr[15296]: B368052C21E: removed
Jun 21 20:09:52 mybox postfix/local[19078]: 378FA52C1AF: to=<[email protected]>, orig_to=<[email protected]>, relay=local, delay=36, status=sent (delivered to command: /usr/bin/procmail -f-)
Jun 21 20:09:52 mybox postfix/qmgr[15296]: 378FA52C1AF: removed
Jun 21 20:12:36 mybox postfix/anvil[19075]: statistics: max connection rate 1/60s for (smtp:87.69.108.193) at Jun 21 20:07:28
Jun 21 20:12:36 mybox postfix/anvil[19075]: statistics: max connection count 1 for (smtp:87.69.108.193) at Jun 21 20:07:28
Jun 21 20:12:36 mybox postfix/anvil[19075]: statistics: max cache size 1 at Jun 21 20:07:28
Jun 21 20:35:55 mybox postfix/smtpd[19877]: connect from adsl-71-137-201-18.dsl.scrm01.pacbell.net[71.137.201.18]
Jun 21 20:35:57 mybox postfix/smtpd[19877]: warning: support for restriction "check_relay_domains" will be removed from Postfix; use "reject_unauth_destination" instead
Jun 21 20:35:57 mybox postfix/smtpd[19877]: 202EF52C1AB: client=adsl-71-137-201-18.dsl.scrm01.pacbell.net[71.137.201.18]
Jun 21 20:35:57 mybox postfix/cleanup[19887]: 202EF52C1AB: message-id=<000301c7b43b$0f882800$0100007f@ooigws>
Jun 21 20:35:58 mybox postfix/qmgr[15296]: 202EF52C1AB: from=<[email protected]>, size=20154, nrcpt=1 (queue active)
Jun 21 20:35:58 mybox postfix/smtpd[19877]: disconnect from adsl-71-137-201-18.dsl.scrm01.pacbell.net[71.137.201.18]
Jun 21 20:35:58 mybox postfix/pickup[19316]: D158C52C21E: uid=10003 from=<web3_admin>
Jun 21 20:35:58 mybox postfix/cleanup[19887]: D158C52C21E: message-id=<[email protected]>
Jun 21 20:35:58 mybox postfix/qmgr[15296]: D158C52C21E: from=<[email protected]>, size=380, nrcpt=1 (queue active)
Jun 21 20:35:58 mybox postfix/local[19905]: D158C52C21E: to=<[email protected]>, relay=local, delay=0, status=sent (delivered to command: /usr/bin/procmail -f-)
Jun 21 20:35:58 mybox postfix/qmgr[15296]: D158C52C21E: removed
Jun 21 20:36:48 mybox postfix/local[19888]: 202EF52C1AB: to=<[email protected]>, orig_to=<[email protected]>, relay=local, delay=52, status=sent (delivered to command: /usr/bin/procmail -f-)
Jun 21 20:36:48 mybox postfix/qmgr[15296]: 202EF52C1AB: removed

But this is because i rebooted the system after my CPU was being eaten by PHP.
I will wait until midnight tonigt, check all the logs and shut down all the processes one by one to try to find the problem.

shajazzi

 

Things have been quiet for a few days until today
I shut down some processes to see if it would make any difference but php is still eating my cpu

mybox:~ # /etc/init.d/apache2 stop
Shutting down httpd2 (waiting for all children to terminate) done
mybox:~ # /etc/init.d/mysql stop
Shutting down service MySQL done
mybox:~ # /etc/init.d/ispconfig_server stop
Shutting down ISPConfig system...
/root/ispconfig/httpd/bin/apachectl stop: httpd stopped
ISPConfig system stopped!
mybox:~ # /etc/init.d/named stop
Shutting down name server BIND done
mybox:~ # /etc/init.d/postfix stop
Shutting down mail service (Postfix) done
mybox:~ # /etc/init.d/proftpd stop
Shutting down ProFTPD Server: done
mybox:~ # /etc/init.d/cron stop
Shutting down CRON daemon done
mybox:~ #

this is what i have found in my apache error log

sh: /id: No such file or directory
sh: /id: No such file or directory
sh: /id: No such file or directory
sh: /uname: No such file or directory
sh: /echo: No such file or directory
sh: /id: No such file or directory
sh: /uname: No such file or directory
sh: /echo: No such file or directory
sh: /id: No such file or directory
[Fri Jun 22 23:08:21 2007] [error] [client 193.109.122.24] request failed: error reading the headers
sh: /uname: No such file or directory
sh: /id: No such file or directory
sh: /echo: No such file or directory
sh: /uname: No such file or directory
sh: /id: No such file or directory
sh: /echo: No such file or directory
sh: /uname: No such file or directory
sh: /id: No such file or directory
sh: /echo: No such file or directory
[Sat Jun 23 08:30:10 2007] [notice] Graceful restart requested, doing restart
[Sat Jun 23 08:30:10 2007] [warn] The Alias directive in /etc/apache2/default-server.conf at line 51 will probably never match because it overlaps an earlier Alias.
[Sat Jun 23 08:30:11 2007] [notice] Apache/2.0.54 (Linux/SUSE) configured -- resuming normal operations
[Sat Jun 23 08:30:11 2007] [warn] long lost child came home! (pid 2900)
[Sat Jun 23 09:28:06 2007] [notice] Graceful restart requested, doing restart
[Sat Jun 23 09:28:06 2007] [warn] The Alias directive in /etc/apache2/default-server.conf at line 51 will probably never match because it overlaps an earlier Alias.
[Sat Jun 23 09:28:06 2007] [notice] Apache/2.0.54 (Linux/SUSE) configured -- resuming normal operations
[Sat Jun 23 09:28:06 2007] [warn] long lost child came home! (pid 28169)
[Sat Jun 23 09:36:39 2007] [notice] caught SIGTERM, shutting down
[Sat Jun 23 09:38:47 2007] [notice] suEXEC mechanism enabled (wrapper: /usr/sbin/suexec2)
[Sat Jun 23 09:38:49 2007] [notice] Apache/2.0.54 (Linux/SUSE) configured -- resuming normal operations
[Sun Jun 24 06:21:09 2007] [error] [client 38.99.44.103] File does not exist: /var/www/sharedip/robots.txt
[Sun Jun 24 06:21:13 2007] [error] [client 38.99.44.103] File does not exist: /var/www/sharedip/robots.txt
[Sun Jun 24 08:16:29 2007] [notice] caught SIGTERM, shutting down


any ideas? please

shajazzi

 

I have no idea what's eating up your CPU...

 

I think i may have found what is causing the problem.
I have been keeping an eye on cron and the problem always starts at 23.59 hrs, so i removed the following entries from cron for a few days and all was OK until i replaced them.

59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/ftp_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/cleanup.php &> /dev/null
I think it could be a problem with ispconfig php but i don`t know what
Any ideas?

shajazzi

 

http daily log is 41.1 KB, daily mail log is 116.5 KB and couldn`t find a daily ftp log. I also noticed that my web.log for sites is not being updated therefore no upto date stats .

shajazzi

 

Hi Till,
I tried those commands and nothing seems to happen

shajazzi

 

But were the FTP and mail stats updated?

 

The mail stats where updated but nothing in the web logs.
I deleted all web and mail logs, also awstats and all stats from all sites.
Replaced the following in cron, just to see if this was causing any problem in that my logs maybe too large.

59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/ftp_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/cleanup.php &> /dev/null

Then reinstalled awstats and all was ok for a couple of days.
Then tonight at 23.59 php started eating my cpu again. I stopped it with this command `pkill php` and all is ok and everything seems to work OK without a reboot.
I seem to have so many problems with SUSE, if i cannot fix this problem without a complete reinstall i am switching to debian

shajazzi

 

That would be a good move!

 

OK,
I have changed to Debian and all is well.
I have found the problem, it seems that my server was being hit with a lot of mail at 23.59 hrs so i changed the lines in cron from

59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/ftp_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/cleanup.php &> /dev/null

to

57 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/ftp_logs.php &> /dev/null
57 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php &> /dev/null
57 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/cleanup.php &> /dev/null

All has been working OK for the last 2 weeks. It seem that spam is hitting my mail boxes at 23.59 hrs every evening causing heavy php useage and my server seems to get stuck in a stagnant loop.

shajazzi