Issue with apache/mod_php running rsync via exec()

Question

I am having an issue with a php script running rsync on one of my servers, but only when run through apache/mod_php.

Here is a trimmed down version of the script:

<?php exec("rsync -a /var/www/html/from/ /var/www/html/to"); ?> 

Pretty simple. The purpose of this command is to copy a folder structure (complete with appropriate permissions) to a new folder. But the issue is, this rsync command hangs and won't complete.

Doing a bit of investigating, I noticed that the script would spawn two rsync processes:

> ps aux | grep rsync apache 20752 56.9 0.0 10400 656 ? R 11:29 1:37 rsync -a /var/www/html/from/ /var/www/html/to apache 20753 0.0 0.0 10400 276 ? S 11:29 0:00 rsync -a /var/www/html/from/ /var/www/html/to root 22305 0.0 0.0 61212 764 pts/1 S+ 11:32 0:00 grep rsync 

I noticed that the first process was in the 'running' status. So I did an strace on it, but all I got for output was the following:

> strace -p 20752 <snip> select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) select(1037, [1026 1027 1028 1029], [], NULL, {60, 0}) = 4 (in [1026 1027 1028 1029], left {60, 0}) <snip> 

Here is what I know so far:

1. The php script works fine when run from the cli. I enabled the ability to su apache and run the script > php myscript.php and it works fine. But running http://mydomain.com/myscript.php creates the 2 processes, with one of the first one in continual running state. This leads me to believe it's not a permission issue. As further proof, here is the ls -l output:

   > ls -l /var/www | grep html drwxr-xr-x 79 apache apacheftp 4096 Aug 17 12:07 html > ls -l /var/www/html | grep from drwxrwxr-x 2 apache apache 4096 Aug 22 11:27 from 

   So, apache has permission to write to the directory, and read from the from directory.

2. Running the same script on a different server of same specs works fine. The specs of both servers are:

   Apache version: Apache/2.2.3 PHP version: 5.3.3 rsync version: 2.6.8 protocol version 29 OS: Red Hat Enterprise Linux Server release 5.6 (Tikanga) 

What I don't know is why apache spawns two rsync processes (or why the first rsync spawns a second), and why the first rsync process seems to be stuck on select(1037...)

Can someone shed light on this?

Answer 1

So after modifying my script to run strace directly through the exec() function like so:

/usr/bin/strace -fo /var/www/html/rsynce.log /usr/bin/rsync -a /var/www/html/from/ /var/www/html/to 

and examining the difference in the file generated by running through a browser, and from the command line, I found this line (in the log generated from the browser-run script):

select(1034, [1026 1027 1028 1029], [], NULL, {60, 0}) = -1 EBADF (Bad file descriptor) 

This got me researching file descriptors in apache. In my setup, I run many virtualhosts and each one was defining 3 unique logfiles. So while an apache process was using 1143 file descriptors (via lsof -p pid | wc -l ), only 124 of those were not logs.

I was able to remove the unique logfiles from the virtual host, restarted apache, and the script-run-through-the-browser worked fine.