Você termina a sua aplicação, altamente complexa e cheia de objetos, funções, e todo tipo de coisa. Coloca em produção, e logo os usuários começam a reclamar que o "sistema está lento", que as páginas demoram a carregar, e por aí vai. Quantas vezes já passamos por situações parecidas?

A grande grande pergunta: O que está fazendo a minha aplicação demorar tanto? Quais partes do código estão consumindo mais recursos?

E dependendo da complexidade da sua aplicação, responder a essa pergunta e conseguir otimizar o seu sistema pode ser uma tarefa bastante árdua sem o uso de um Profiler.

Um profiler nada mais é que um pequeno utilitário acoplado ao sistema, que fica monitorando o tempo gasto em cada trecho de código, de forma que o programador possa saber exatamente quanto tempo cada parte do seu código está consumindo.

Eu venho usando a classe Benchmark do PEAR, e ela tem ajudado bastante a melhorar o desempenho das aplicações.

Com o pacote instalado, podemos inicializar o nosso profiler:

PHP
require 'Benchmark/Profiler.php';
 
$profiler = new Benchmark_Profiler();
$profiler->start();
www.revistaphp.com.br

Pronto, já temos o nosso profiler instanciado e rodando. Para mostrar as estatísticas coletadas, basta incluírmos o seguinte código ao fim do script:

PHP
$profiler->stop();
$profiler->display();
www.revistaphp.com.br

Pronto. Com o profiler iniciado no início do script, e parado ao fim do script, já temos as estatísticas de quanto tempo o script levou para executar:

Já sabemos que nosso script demorou aproximadamente 0.0000209 segundos para rodar. Porém, só essa informação não é de muita utilidade, certo? Afinal, podemos saber quanto tempo o nosso script leva para rodar contando no relógio. Até aí, nada de novo.

O grande barato do Profiler é a possibilidade de se criar "seções". Uma seção seria um trecho de código, de qualquer tamanho, em que se deseja saber o tempo que ele leva para executar. Em um script com muitas funções, chamadas recursivas, essa técnica nos permite saber exatamente onde se encontra o problema.

Por exemplo, digamos que tenhamos o seguinte script:

PHP
start();
 
function funcao1() {
    sleep(1);
    funcao2();
}
 
function funcao2() {
    sleep(2);
}
 
for ($i=0;$i<3;$i++) {
    funcao1();
}
 
$profiler->stop();
$profiler->display();
?>
www.revistaphp.com.br

Temos aqui 2 funções, que para simplificar o exemplo, não fazem nada além de chamar sleep() para perder tempo. Além disso, funcao2() é chamada de dentro da funcao1(). Finalmente, o corpo do script chama funcao1() 3 vezes.

Em um script simples como este, é fácil saber onde o tempo está sendo gasto só olhando. Mas em um script com dezenas ou centenas de funções (ou métodos), que se chamam muitas vezes durante o tempo de execução, é muito fácil de se perder, e muito mais difícil de saber aonde o tempo está sendo gasto.

Para melhorar o exemplo acima, podemos definir 2 seções, uma para cada função. Dizemos ao profiler que o script entrou na seção usando o método enterSection(), e que saiu com o método leaveSection(). Assim, com uma pequena modificações na função, ficamos assim:

PHP
function funcao1() {
    global $profiler;
    $profiler->enterSection("funcao1");
    sleep(1);
    funcao2();
    $profiler->leaveSection("funcao1");
}
 
function funcao2() {
    global $profiler;
    $profiler->enterSection("funcao2");
    sleep(2);
    $profiler->leaveSection("funcao2");
}
www.revistaphp.com.br

Precisamos usar a palavra-chave global porque $profiler não é visível de dentro das funções. Temos então 2 seções, uma para cada função. O profiler agora irá nos dizer quanto tempo está sendo gasto em cada uma das funções (que são as seções):

Pronto! Apenas para esclarecer, a primeira coluna diz o tempo total que o script gastou na seção, a segunda coluna diz o tempo gasto na seção menos o tempo gasto em chamadas a outras seções, a terceira coluna diz o número de vezes que a seção foi executada, a quarta coluna o percentual do tempo gasto nela, a quinta diz quem ela chamou, e a sexta diz por quem ela foi chamada.

Apenas para diferenciar entre a primeira e a segunda coluna, vemos que no escopo global, a primeira coluna ficou aproximadamente 9 segundos, e a segunda coluna quase 0. Ou seja, 9 segundos foi o tempo que o escopo global demorou pra executar, mas 0 segundos foram gastos exclusivamente nele (nesse caso, todos os 9 segundos foram gastos em funcao1() e funcao2()).

Então, olhando para a pequena tabela de baixo para cima, podemos ver claramente o fluxo do programa, e o tempo que ele gastou nas seções:

Pra começar, já sabemos que o script levou em torno de 9 segundos para ser executado. No escopo global, ele chamou funcao1() 3 vezes. Notamos tambem que ele ficou muito pouco tempo exclusivamente no escopo global (tambem pudera: ele só tem um laço for e mais nada). De funcao1(), vemos que ele chama funcao2() 3 vezes tambem, e que funcao1() foi chamada do escopo global 3 vezes, como já sabíamos. O tempo gasto exclusivamente em funcao1() foi aproximadamente 3 segundos, logo a função deve estar levando em média 1 segundo a cada chamada. E finalmente, temos funcao2(), que levou 6 segundos para ser executada, e que foi chamada 3 vezes por funcao1(). Logo, está gastando em média 2 segundos por chamada.

É claro que o exemplo dado é trivial, mas em sistemas complexos com centenas de objetos e métodos que passam mensagens entre si o tempo todo, o uso de um profiler como esse facilita muito na hora de saber o porque da página demorar tanto tempo para carregar.

Em tempo, essas são apenas algumas funções que essa excelente classe do PEAR provê. Para mais detalhes, veja diretamente na documentação.