php mail() very slow on centos 5.2 with postfix

[marm26]

I am running a centos 5.2 server with postfix and php 5 installed.

I am having problems with php mail(). Mails are sent but it takes about a minute for the page with the mail() function in it to load.

The mails are very short and text only. I had the same script on a different server before (shared hosting) were things just worked perfectly and very fast. I suspect that there is a problem with my server settings. Any ideas???

[falko]

Any errors in Apache's error log (or the web site's error log)?

[marm26]

No nothing in of any interest in apache or web error log.

[falko]

And in the mail log?

[marm26]

ok here is the mail log. Not sure if this helps.

Jan 25 05:27:31 ess000665 freshclam[3343]: Received signal: wake up
Jan 25 05:27:31 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 05:27:31 2009
Jan 25 05:27:51 ess000665 freshclam[3343]: Can't query current.cvd.clamav.net
Jan 25 05:27:51 ess000665 freshclam[3343]: Invalid DNS reply. Falling back to HTTP mode.
Jan 25 05:27:51 ess000665 freshclam[3343]: Reading CVD header (main.cvd):
Jan 25 05:28:51 ess000665 freshclam[3343]: Can't get information about database.clamav.net: Temporary failure in name resolution
Jan 25 05:28:51 ess000665 freshclam[3343]: Can't read main.cvd header from database.clamav.net (IP: )
Jan 25 05:28:51 ess000665 freshclam[3343]: Trying again in 5 secs...
Jan 25 05:28:56 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 05:28:56 2009
Jan 25 05:29:16 ess000665 freshclam[3343]: Can't query current.cvd.clamav.net
Jan 25 05:29:16 ess000665 freshclam[3343]: Invalid DNS reply. Falling back to HTTP mode.
Jan 25 05:29:16 ess000665 freshclam[3343]: Reading CVD header (main.cvd):
Jan 25 05:29:56 ess000665 freshclam[3343]: Can't get information about database.clamav.net: Temporary failure in name resolution
Jan 25 05:29:56 ess000665 freshclam[3343]: Can't read main.cvd header from database.clamav.net (IP: )
Jan 25 05:29:56 ess000665 freshclam[3343]: Trying again in 5 secs...
Jan 25 05:30:01 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 05:30:01 2009
Jan 25 05:30:01 ess000665 freshclam[3343]: main.cvd is up to date (version: 49, sigs: 437972, f-level: 35, builder: sven)
Jan 25 05:30:01 ess000665 freshclam[3343]: daily.cld is up to date (version: 8901, sigs: 61185, f-level: 38, builder: edwin)
Jan 25 05:30:01 ess000665 freshclam[3343]: --------------------------------------
Jan 25 07:27:08 ess000665 postfix/smtpd[9603]: connect from unknown[124.11.132.104]
Jan 25 07:27:08 ess000665 postfix/smtpd[9603]: NOQUEUE: reject: RCPT from unknown[124.11.132.104]: 554 5.7.1 <bibiorm@gmail.com>: Relay access denied; from=<millie520@gmail.com> to=<bibiorm@gmail.com> proto=SMTP helo=<209.139.208.129>
Jan 25 07:27:08 ess000665 postfix/smtpd[9603]: lost connection after RCPT from unknown[124.11.132.104]
Jan 25 07:27:08 ess000665 postfix/smtpd[9603]: disconnect from unknown[124.11.132.104]
Jan 25 07:30:28 ess000665 postfix/anvil[9607]: statistics: max connection rate 1/60s for (smtp:124.11.132.104) at Jan 25 07:27:08
Jan 25 07:30:28 ess000665 postfix/anvil[9607]: statistics: max connection count 1 for (smtp:124.11.132.104) at Jan 25 07:27:08
Jan 25 07:30:28 ess000665 postfix/anvil[9607]: statistics: max cache size 1 at Jan 25 07:27:08
Jan 25 07:54:01 ess000665 freshclam[3343]: Received signal: wake up
Jan 25 07:54:01 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 07:54:01 2009
Jan 25 07:54:21 ess000665 freshclam[3343]: Can't query current.cvd.clamav.net
Jan 25 07:54:21 ess000665 freshclam[3343]: Invalid DNS reply. Falling back to HTTP mode.
Jan 25 07:54:21 ess000665 freshclam[3343]: Reading CVD header (main.cvd):
Jan 25 07:55:01 ess000665 freshclam[3343]: Can't get information about database.clamav.net: Temporary failure in name resolution
Jan 25 07:55:01 ess000665 freshclam[3343]: Can't read main.cvd header from database.clamav.net (IP: )
Jan 25 07:55:01 ess000665 freshclam[3343]: Trying again in 5 secs...
Jan 25 07:55:06 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 07:55:06 2009
Jan 25 07:55:06 ess000665 freshclam[3343]: main.cvd is up to date (version: 49, sigs: 437972, f-level: 35, builder: sven)
Jan 25 07:55:06 ess000665 freshclam[3343]: daily.cld is up to date (version: 8901, sigs: 61185, f-level: 38, builder: edwin)
Jan 25 07:55:06 ess000665 freshclam[3343]: --------------------------------------
Jan 25 10:19:06 ess000665 freshclam[3343]: Received signal: wake up
Jan 25 10:19:06 ess000665 freshclam[3343]: ClamAV update process started at Sun Jan 25 10:19:06 2009
Jan 25 10:19:21 ess000665 freshclam[3343]: main.cvd is up to date (version: 49, sigs: 437972, f-level: 35, builder: sven)
Jan 25 10:19:21 ess000665 freshclam[3343]: daily.cld is up to date (version: 8901, sigs: 61185, f-level: 38, builder: edwin)
Jan 25 10:19:21 ess000665 freshclam[3343]: --------------------------------------
Jan 25 12:43:21 ess000665 freshclam[3343]: Received signal: wake up

[falko]

Can you post an excerpt where you try to send a mail with the PHP mail() function? I don't see anything like that in the excerpt you posted.

[marm26]

I have send several mails with the php mail function that day. If there isnt anything in the mail error log that means it didnt throw an error. I mean the mail also got send. Just the script sending the mail is taking a minute or so to send out the mail.

[marm26]

This is so strange. When i send out one mail message and i didnt send one in a while the script is running forever. But once i send this first mail message, the messages i send out right afterwards are sent in no time. Could it be that my mailing server has to be awakened from his winter sleep first before it starts sending mails. After i stop sending mails it seems to go back to sleep again within a few minutes. This is really not very satisfying. Is there anything i can do about that? what is causing this?

[falko]

You could try to install a PHP opcode cacher like eAccelerator, Xcache, or APC and see if the behaviour changes.

[marm26]

I thought I just let you know that I solved the issue. It was the sendmail path in php ini that caused the script to go incredibly slow.

i changed it to:
sendmail_path = /usr/lib/sendmail.postfix -t -i

No the mails fire real fast. However I am having another problem now. In my maillog file I frequently see messages like this:

Feb 1 19:44:29 server1 postfix/smtp[4591]: 88B9F14A81EE: to=<some-name@gmail.com>, relay=none, delay=20, delays=0.02/0.01/20/0, dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=gmail.com type=MX: Host not found, try again)

Same thing happens with yahoo or hotmail. It doesnt happen with every mail but quite often. Any ideas on this one?