2

I am having a problem on my server when the PHP mail() function is being used in a browser, so through Apache.

When the script, lets call it mailtest.php, is being called through a browser, there is a 60 second delay in actually sending the message.

When I call php mailtest.php from the commandline, the mail is sent instantly, no delay.

After a restart of Apache, the delay is gone. However, it returns after a couple of hours.

I did an Strace and here you can see a delay of 30 seconds at the end. 

13076 09:38:02 clone( <unfinished ...>
13076 09:38:32 <... clone resumed> child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xa5f346f8) = 13160

http://pastebin.com/q34peBW7

It's a virtual server btw running Debian.

Any ideas? I'm getting desperate.

vstm
  • 340
  • 3
  • 10
Oscar
  • 21
  • 1
  • 1
    Have you tried running strace with `-f`? This should follow also the child processes (`clone()` and `fork()` create child processes). Maybe that'll shed some light on what's going on during those 30 seconds. – vstm Aug 27 '11 at 08:47
  • I did use the -f option. And once the clone is created, it runs fast. It looks like what Alex said could be the case. It takes 30 seconds to actually create the clone child process.... – Oscar Aug 27 '11 at 10:14
  • That's a real hum-dinger of a problem you've got there. Kudos for doing much better diagnostics than 99.9% of the people who ask questions here. – womble Aug 27 '11 at 22:07
  • I'm witnessing exactly the same problem in a PHP setup: sending e-mails takes 90s (strace shows that 2 intermediary processes are forked before we reach sendmail, so that's 30s per clone() syscall). But I'm not running Apache: I'm using nginx + php-fpm. It's in a LXC container running on an Ubuntu 10.04 LTS server which is an EC2 instance (Xen virtual machine). Other processes on the same machine (and same container) don't have any problem. – jpetazzo Jun 02 '12 at 06:40

1 Answers1

4

clone(...) call is for creating child processes, so it looks like it took 30 seconds to create a new process in your system. Most probably RAM was exhausted and processes used swap extensively. Could you please check this using top and free? You can also monitor disk activity using iostat, probably there were lots of I/O operations.

Alex
  • 7,939
  • 6
  • 38
  • 52
  • Top was showing normal loads (between 0.5 and 2). If it happens again, I'll use iostat – Oscar Aug 27 '11 at 10:07
  • If clone were to take 30 seconds, *all* commands on the machine would be awfully slow (even a simple "ls" would take at least 30 seconds). I believe that the issue has nothing to do with RAM and swap. – jpetazzo Jun 02 '12 at 06:43