Major problem causes server to crash

Anon

Hi,
we have a big problem now tested on several machines.
We used single processor systems with one hdd up to multiprocessor systems with a raid installed. We used the following configuration:
OS: SuSE LINUX Kernel 2.2.14
DB: PostgreSQL 7.0.2 / PostgreSQL 7.0.0 (32 up to 128 clients)
PHP: PHP4 RC2 / PHP 4.0.0
Apache: 1.3.12 (max. clients 120)

The whole system is doing fine after setup. At moderate use everything seems to be ok but if we are going to increase traffic the servers crashes down completely from time to time. The crashes seems to happen randomly because at one time the server can handle a load average higher than 5,0 with no problems for a longer period of time. Another crash happened with a load average of 0,5. One crash happened after a complete idle time of 8 hours.

We attached a part of the error log below.

[Wed Jul 26 14:41:55 2000] [error] OpenSSL: error:1409E0E5:SSL routines:SSL3_WRITE_BYTES:ssl handshake failure
[Wed Jul 26 14:41:55 2000] [info] [client 149.225.69.56] client stopped connection before rflush completed
[Wed Jul 26 14:45:10 2000] [info] server seems busy, (you may need to increase StartServers, or Min/MaxSpareServers), spawning 8 children, there are 7 id
[Wed Jul 26 14:45:17 2000] [info] [client 193.158.164.30] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:45:17 2000] [info] [client 194.112.117.186] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:45:34 2000] [info] [client 212.37.32.19] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:45:34 2000] [info] [client 193.141.96.42] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:46:39 2000] [info] [client 195.222.195.6] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:46:39 2000] [info] [client 62.104.210.72] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:46:53 2000] [info] [client 193.158.164.30] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:46:56 2000] [info] [client 62.224.110.254] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:47:03 2000] [info] [client 149.225.69.56] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:47:51 2000] [info] [client 195.238.224.181] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:47:57 2000] [error] (32)Broken pipe: accept: (client socket)
[Wed Jul 26 14:48:01 2000] [info] [client 62.226.96.115] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:01 2000] [info] [client 212.222.21.91] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:27 2000] [info] [client 194.45.109.106] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:27 2000] [info] [client 62.180.120.5] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:41 2000] [info] [client 149.225.69.56] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:44 2000] [info] [client 195.211.5.130] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:48 2000] [info] [client 195.222.195.6] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:49 2000] [info] [client 62.104.214.68] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:48:57 2000] [info] [client 62.104.210.72] (32)Broken pipe: client stopped connection before rwrite completed
[Wed Jul 26 14:49:42 2000] [info] [client 194.163.39.226] send timed out
[Wed Jul 26 14:49:45 2000] [info] [client 194.163.39.226] client stopped connection before rvputs completed
zend_API.c(61) : Freeing 0x088A20FC (123 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_variables.c(126) : Actual location (location was relayed)
zend_operators.c(925) : Freeing 0x0886A684 (123 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_operators.c(923) : Freeing 0x086D0AE4 (35 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_hash.c(255) : Freeing 0x084D0274 (41 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 30 times
zend_hash.c(425) : Freeing 0x0848153C (44 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 1 time
zend_hash.c(391) : Freeing 0x086EF4EC (35 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 1 time
./zend_execute.c(1757) : Freeing 0x0872A894 (48 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_variables.c(139) : Actual location (location was relayed)
./zend_execute.c(1136) : Freeing 0x083964E4 (12 bytes), script=/usr/local/httpd/htdocs/dispatch.php
main.c(444) : Freeing 0x087F9EBC (12 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_API.c(59) : Freeing 0x085A0314 (12 bytes), script=/usr/local/httpd/htdocs/dispatch.php
(...)

[Wed Jul 26 15:07:50 2000] Script: '/usr/local/httpd/htdocs/dispatch.php'

zend_opcode.c(171) : Block 0x081A8658 status:
Beginning: Overrun (magic=0x4014A4B8, expected=0x7312F8DC)

End: Unknown

zend_opcode.c(48) : Freeing 0x081A9D4C (8192 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 1 time
zend_compile.c(1532) : Freeing 0x081501BC (9 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_compile.c(73) : Freeing 0x08154DB4 (28 bytes), script=/usr/local/httpd/htdocs/dispatch.php
./zend-scanner.l(1336) : Freeing 0x08154BCC (18 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 24 times
(...)
[Wed Jul 26 15:14:13 2000] [info] [client 62.157.64.159] (25)Inappropriate ioctl for device: client stopped connection before rvputs completed
NOTICE: Message from PostgreSQL backend:
The Postmaster has informed me that some other backend died abnormally and possibly corrupted shared memory.
I have rolled back the current transaction and am going to terminate your database system connection and exit.
Please reconnect to the database system and repeat your query.
NOTICE: Message from PostgreSQL backend:
The Postmaster has informed me that some other backend died abnormally and possibly corrupted shared memory.
I have rolled back the current transaction and am going to terminate your database system connection and exit.
Please reconnect to the database system and repeat your query.
zend_API.c(61) : Freeing 0x08235424 (123 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_variables.c(126) : Actual location (location was relayed)
zend_operators.c(925) : Freeing 0x0823537C (123 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_operators.c(923) : Freeing 0x082351DC (35 bytes), script=/usr/local/httpd/htdocs/dispatch.php
zend_hash.c(255) : Freeing 0x082350E4 (41 bytes), script=/usr/local/httpd/htdocs/dispatch.php
Last leak repeated 30 times

Anon

I would say that it looks like postgres is running out of memory or swap space.

You may want to add a cron job that runs every five minutes and stores the output of 'free' or 'ps aux' and such in a log file you can peruse after the crash. Look for a single postgres instance that is using up tons-o-ram (tm, David Letterman :⁾ before the crash.

How much memory and how much swap space do these boxen have, anyway?

Anon

We used boxes from
256MB with 512MB swap up to
1GB RAM with 1GB swap

The biggest postgres was
SIZE 11MB
RSS 11MB
SHARE 10MB

So if the problem is that postgres is using too much RAM hoe can we avoid it?

Anon

Did you ever discover what was going on here? - only in the last two days have some strange messages showed up in my server-error log files. As far as I can tell I have not modified the script that is listed in connection with the error log lines. So I am concerned about what might be going on here and I definitely dont want unexplained crashes to start happening. Here are the last several lines from my error_log file:
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
url.c(96) : Freeing 0x081841EC (34 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(67) : Freeing 0x08170EEC (32 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(139) : Freeing 0x082C7F94 (12 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(101) : Freeing 0x08274A1C (97 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
./zend_execute.c(1572) : Freeing 0x0827488C (12 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
./zend_execute.c(413) : Freeing 0x08191024 (12 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
zend_operators.c(903) : Freeing 0x08190F04 (149 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(91) : Freeing 0x0825C8CC (5 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
session.c(1241) : Freeing 0x0823CE24 (1 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
session.c(1245) : Freeing 0x0823CDA4 (1 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/finalizec.php
session.c(1249) : Freeing 0x08254724 (1 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
session.c(1250) : Freeing 0x0825378C (8 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
zend_hash.c(185) : Freeing 0x08248B4C (20 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
Last leak repeated 1 time
session.c(1248) : Freeing 0x0824EB8C (2 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
session.c(1239) : Freeing 0x0823F0B4 (5 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
session.c(1240) : Freeing 0x0828B45C (10 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(96) : Freeing 0x0818414C (34 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
url.c(67) : Freeing 0x08170E4C (32 bytes), script=/usr/local/etc/httpd/sites/domain-name.com/htdocs/scriptpagename.php
=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
What is very strange is that these have only started showing in my error_log recently and I cant think of what I would have changed to cause this.
Any ideas?
-Thanks,
Ken

Anon

Never fear. This information is normal. Turn down your log level or compile PHP with --disable-debug to reduce the number.

All it means is the script completed and it has the memory it no longer needs... so it's cleaning it up... Freeing the used memory for use in other scripts.