Erro ao executar múltiplos scripts simultaneamente através do exec()

Bom dia a todos!

Estou enfrentado um problema com a execução de múltiplos comandos simultâneos através do exec().

Tenho o PHP 5.3.5 instalado em um servidor Ubuntu com Apache e MySQL.

Minha crontab dispara a todo minuto a execução de um script PHP:

* * * * * /usr/bin/php /var/www/envia.php

Dentro desse script, eu tenho que executar outro script 4 vezes simultaneamente sem esperar retorno, pois ele é autossuficiente e é colocado em background, segue a parte do código que o faz:

"exec ("/usr/bin/php /var/www/telnet.php int=1 ID=$ID[1] >/dev/null 2>&1 & /usr/bin/php /var/www/telnet.php int=2 ID=$ID[2] >/dev/null 2>&1 & /usr/bin/php /var/www/telnet.php int=3 ID=$ID[3] >/dev/null 2>&1 & /usr/bin/php /var/www/telnet.php int=4 ID=$ID[4] >/dev/null 2>&1 &");

// Loga no BD
$res = mysql_query("INSERT INTO LOG ...");

mysql_close($conexao); // Desconecta do BD

exit;
?>"

A função exec() está funcionando corretamente, pois o registro no BD está sendo inserido no horário correto (pouco depois do início da execução do envia.php: 2012-02-02 11:52:01).

O script telnet.php é executado 4 vezes, porém entre a primeira execução e as próximas existe uma demora de 20 segundos.

Esse demora é visualizada nos registros inseridos no banco (através do telnet.php):
1 - 2012-02-02 11:52:02
2 - 2012-02-02 11:52:22
3 - 2012-02-02 11:52:22
4 - 2012-02-02 11:52:22

O mais estranho, é que os 3 próximos são executados simultaneamente, só existe essa demora entre o primeiro e o segundo.

Alguém já passou por esse problema e tem como me ajudar?

Esta inserção no LOG é feita no arquivo telnet.php?
Se sim, pode ser simplesmente o tempo para abrir o canal ou "acordar" o processo origem/destino.

Marcos, obrigado pela resposta.

O LOG é populado pelo envia.php . Os outros Timesptamps postados são da tabela populada pelo telnet.php.



Marcos Regis Escreveu:
-------------------------------------------------------
> Esta inserção no LOG é feita no arquivo
> telnet.php?
> Se sim, pode ser simplesmente o tempo para abrir o
> canal ou "acordar" o processo origem/destino.

Sua resposta não ficou clara o suficiente.
LOG e Timestamps da tabela são a mesma coisa?

Faça com que cada processo gere seu próprio LOG de início e fim de execução e verifique onde exatamente está havendo delay.

Vamos lá Marcos:

São duas tabelas diferentes: enviados e LOG.

A tabela LOG é populada pelo envia.php conforme código do meu primeiro Post:

"// Loga no BD
$res = mysql_query("INSERT INTO LOG ..."); "

A tabela enviados é populada pelo telnet.php, da qual eu tirei os Timestamps do meu segundo Post:
"1 - 2012-02-02 11:52:02
2 - 2012-02-02 11:52:22
3 - 2012-02-02 11:52:22
4 - 2012-02-02 11:52:22"

Eu consegui gerar os logs de início e fim de cada execução e descobri que o problema está na execução dos scripts de 2 a 4 conforme segue:
"
2012-02-02 15:28:02 1.191816 telnet 1
2012-02-02 15:28:22 20.921480 telnet 4
2012-02-02 15:28:22 20.916361 telnet 3
2012-02-02 15:28:22 20.918279 telnet 2
"

Como é perceptível acima, os scripts telnet 2 a 4 demoraram mais de 20 segundos para serem executados, enquanto o telnet 1 demorou apenas 1, lembrando que todos foram disparados ao mesmo tempo.

Já encontramos a causa do problema, agora só falta a solução.

Marcos Regis Escreveu:
-------------------------------------------------------
> Sua resposta não ficou clara o suficiente.
> LOG e Timestamps da tabela são a mesma coisa?
>
> Faça com que cada processo gere seu próprio LOG
> de início e fim de execução e verifique onde
> exatamente está havendo delay.

Consegui resolver!

O problema estava na conexão fsockopen chamada pelo telnet.php que estava sem timeout configurado, assumindo assim o tempo padrão de 20 segundos.

Ao alterar para:
"
fsockopen($ip,$port, $errno, $errstr, 5)
"

O tempo diminuiu para 5 segundos, se eu alterar para 0, ele acompanha.

Marcos, muito obrigado pela ajuda, ela foi essencial para encontrar a causa exata.

Eu imaginei que era algo desse tipo. Normalmente a primeira conexão demora um pouco mais para ser estabelecida devido ao ACK. O importante é que você encontrou a causa e resolveu.
Abraços.