Log para Doctrine2 e ZF2

Bom dia pessoal!

Perguntaram num forum sobre como logar as alterações nas entidades usando Doctrine2 e Zend Framework 2. Ano passado eu criei uma série de módulos para usar nos meus projetos e me ajudar a me familiarizar com o ZF2, que na época ainda estava em beta, e um deles foi justamente logar todos os sqls feitos e todas as alterações nas entidades (inserir, alterar e remover).

Então hoje vou falar um pouco sobre isso.

Classe Abstrata

Como vamos usar 2 logs neste post, no meu caso uso 4 mas com outras finalidades, vamos criar uma classe abstrata com as funções em comum:

<?php
/**
 * Classe abstrata para Logs
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
namespace LosLog\Log;

use Zend\Log\Writer\Stream;
use Zend\Log\Logger;

/**
 * Classe abstrata para Logs
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
abstract class AbstractLogger extends Logger
{
    /**
     * Directório onde o log será salvo
     *
     * @var string
     */
    private $_logDir;

    /**
     * Nome do arquivo de log
     *
     * @var string
     */
    private $_logFile;

    /**
     * Construtor
     *
     * Define o logDir e logFile e cria o writter. Se o logDir for nulo
     * irá usar o diretório temporário do sistema
     *
     * @param string $logFile
     * @param string $logDir
     */
    public function __construct($logFile, $logDir = null)
    {
        parent::__construct();

        if (null == $logDir) {
            $logDir = sys_get_temp_dir();
        }
        $this->setLogDir($logDir);
        $this->setLogFile($logFile);

        $writer = new Stream($logDir . DIRECTORY_SEPARATOR . $logFile);
        $this->addWriter($writer);
    }

    /**
     * Retorna o logDir
     *
     * @return string
     */
    public function getLogDir()
    {
        return $this->_logDir;
    }

    /**
     * Define o logDir
     *
     * @param string $logDir
     * @throws \InvalidArgumentException
     */
    public function setLogDir($logDir)
    {
        $logDir = trim($logDir);
        if (!file_exists($logDir) || !is_writable($logDir)) {
            throw new \InvalidArgumentException("Diretório inválido!");
        }

        $this->_logDir = $logDir;
    }
    /**
     * @return the $_logFile
     */
    public function getLogFile()
    {
        return $this->_logFile;
    }

    /**
     * @param string $_logFile
     */
    public function setLogFile($logFile)
    {
        $logFile = trim($logFile);
        if (null === $logFile || '' == $logFile) {
            throw new \InvalidArgumentException("Arquivo inválido!");
        }
        $this->_logFile = $logFile;
    }
}

Não há muito mistério desde código. Apenas criarmos um logger estendendo do Zend\Log e definimos onde ele vai salvar o log e com que nome .

Logando SQL

Para logar todo sql feito no banco de dados, usando Doctrine, primeiro devemos criar uma classe:

<?php
/**
 * Loga todas as operações do doctrine
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
namespace LosLog\Log;

use LosLog\Log\AbstractLogger;
use Doctrine\DBAL\Logging\SQLLogger as LogInterface;

/**
 * Loga todas as operações do doctrine
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
class SqlLogger extends AbstractLogger implements LogInterface
{
    /*
     * Executada sempre antes que um SQL for executado
     *
     * @see \Doctrine\DBAL\Logging\SQLLogger::startQuery()
     */
    public function startQuery ($sql, array $params = null, array $types = null)
    {
        $msg = 'SQL: ' . $sql;
        if ($params) {
            $msg .= PHP_EOL . "\tPARAMS: " . json_encode($params);
        }
        if ($types) {
            $msg .= PHP_EOL . "\tTIPOS: " . json_encode($types);
        }
        $this->debug($msg);
    }

    /*
     * (non-PHPdoc)
     * @see \Doctrine\DBAL\Logging\SQLLogger::stopQuery()
     */
    public function stopQuery ()
    {}
}

Uma observação importante é que para nosso log funcionar, nossa classe deve implementar a interface Doctrine\DBAL\Logging\SQLLogger (linha 19).

A função startQuery é chamada automaticamente pelo Doctrine sempre antes de executar qualquer sql no banco de dados.

Com nossa função pronta, podemos passar a chamá-la. Vamos acrescentarmos algumas linhas na função onBootstrap do arquivo Module.php (pode ser o Application ou qualquer outro):

...
use Doctrine\DBAL\Logging\LoggerChain;
use LosLog\Log\SqlLogger;
...

class Module implements AutoloaderProviderInterface, LocatorRegisteredInterface
{
    /**
     * Module bootstrap
     */
    public function onBootstrap ($e)
    {
        ...

        $sm = $e->getApplication()->getServiceManager();
        $em = $sm->get('Doctrine\ORM\EntityManager');
        $myLogger = new SqlLogger("sql.log","data/logs");

        if (null !== $em->getConfiguration()->getSQLLogger()) {
            $logger = new LoggerChain();
            $logger->addLogger($myLogger);
            $logger->addLogger($em->getConfiguration()->getSQLLogger());
            $em->getConfiguration()->setSQLLogger($logger);
        } else {
            $em->getConfiguration()->setSQLLogger($myLogger);
        }
    }
    ...
}

Primeiramente, não esqueça de adicionar os 2 uses no seu arquivo (linhas 3 e 4) e alterar a linha 4 para o caminho do seu SQLLogger.

Aqui criamos o nosso logger e o acrescentamos à corrente de logs do Doctrine, ou definimos uma caso esteja vazia.

Pronto, simples e rápido.

Um SELECT será salvo assim:

2013-07-29T06:44:02-03:00 DEBUG (7): SQL: SELECT t0.nome AS nome1, t0.sobrenome AS sobrenome2, t0.permissao AS permissao3, t0.email AS email4, t0.login AS login5, t0.senha AS senha6, t0.id AS id7, t0.cadastrado AS cadastrado8, t0.atualizado AS atualizado9 FROM usuario t0 WHERE t0.id = ?
	PARAMS: [1]
	TYPES: ["integer"]

Ou no caso de um insert:

2013-07-29T07:43:41-02:00 DEBUG (7): SQL: "START TRANSACTION"
2013-07-29T07:43:41-02:00 DEBUG (7): SQL: INSERT INTO cliente (nome, cadastrado) VALUES (?, ?)
        PARAMS: {"1":"clienteTeste","2":{"date":"2013-07-29 07:43:41","timezone_type":3,"timezone":"America\/Sao_Paulo"}}
        TYPES: {"1":"string","2":"datetime"}
2013-07-29T07:43:41-02:00 DEBUG (7): SQL: "COMMIT"

Update:

2013-11-29T08:00:17-02:00 DEBUG (7): SQL: "START TRANSACTION"
2013-11-29T08:00:17-02:00 DEBUG (7): SQL: UPDATE usuario SET validado = ?, validacao = ? WHERE id = ?
        PARAMS: ["sim","",1]
        TYPES: ["string","string","integer"]
2013-07-29T08:00:17-02:00 DEBUG (7): SQL: "COMMIT"

Delete:

2013-07-29T07:32:38-02:00 DEBUG (7): SQL: "START TRANSACTION"
2013-07-29T07:32:38-02:00 DEBUG (7): SQL: DELETE FROM capitulo WHERE id = ?
        PARAMS: [4]
2013-07-29T07:32:38-02:00 DEBUG (7): SQL: "COMMIT"

 Logando Entidades

Outra função útil são as alterações nas entidades do projeto. Já podemos saber todas as alterações através do banco de dados, mas é muito baixo nível. Se uma entidade é dividida em várias tabelas por exemplo, fica complicado analisar as alterações.

O Doctrine nos oferece outro recurso para tratar as entidades e não somente o sql. Aí entra o sistema de eventos do Doctrine.

Assim como no ZF2, o Doctrine possui um sistema de eventos que e disparado sempre que algumas condições são alcançadas e podemos capturar estes eventos, para fazer ajustes antes de salvar ou, no nosso caso, criar um log.

Vamos ao código:

<?php
/**
 * Loga todas as alteraçòes nas entidades
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
namespace LosLog\Log;
use Doctrine\Common\EventSubscriber;

/**
 * Loga todas as alteraçòes nas entidades
 *
 * @package    LosLos\Log
 * @author     Leandro Silva <leandro@leandrosilva.info>
 */
class EntityLogger extends AbstractLogger implements EventSubscriber
{
    /*
     * (non-PHPdoc) @see \Doctrine\Common\EventSubscriber::getSubscribedEvents()
     */
    public function getSubscribedEvents ()
    {
        return array(
            'onFlush'
        );
    }

    /**
     * Loga as alteraçòes das entidades
     *
     * @param \Doctrine\ORM\Event\OnFlushEventArgs $eventArgs
     */
    public function onFlush (\Doctrine\ORM\Event\OnFlushEventArgs $eventArgs)
    {
        $em = $eventArgs->getEntityManager();
        $uow = $em->getUnitOfWork();

        foreach ($uow->getScheduledEntityInsertions() as $entity) {
            $this->debug('Inserindo entidade ' . get_class($entity) . '. Campos: ' .
                             json_encode($uow->getEntityChangeSet($entity)));
        }

        foreach ($uow->getScheduledEntityUpdates() as $entity) {
            $add = '';
            if (method_exists($entity, '__toString')) {
                $add = ' '. $entity->__toString();
            } elseif (method_exists($entity, 'getId')) {
                $add = ' com id '. $entity->getId();
            }

            $this->debug('Alterando entidade ' . get_class($entity) . $add .'. Data: ' .
                             json_encode($uow->getEntityChangeSet($entity)));
        }

        foreach ($uow->getScheduledEntityDeletions() as $entity) {
            $add = '';
            if (method_exists($entity, '__toString')) {
                $add = ' '. $entity->__toString();
            } elseif (method_exists($entity, 'getId')) {
                $add = ' com id '. $entity->getId();
            }

            $this->debug('Removendo entidade ' . get_class($entity) . $add . '.');
        }
    }
}

Devemos implementar a interface Doctrine\Common\EventSubscriber e definir quais eventos vamos “escutar” (linha 25). No nosso caso, vamos escutar o evento “onFlush” que acontece imediatamente antes de salvar no banco de dados.

Um detalhe importante de usar o onFlush é que como acontece antes de salvar no banco, se der algum erro você terá logado da mesma maneira. Eu preferi salvar no onFlush ao invés de outros eventos, como postFlush, postUpdate, postRemove e postPersist, pois se der algum erro eu preciso saber exatamente onde deu o erro, o que tentei salvar que gerou o erro? Sabendo qual a entidade e os dados facilita muito.

Usar o log no onFlush não é recomendado para fins de auditoria (usuário alterou registro X), justamente porque o dado ainda não foi salvo no banco.

Para quem já trabalha com Doctrine2 sabe que as operações vão sendo “acumuladas” com persist e remove e apenas executadas quando o “flush” é chamado. No “onFlush” todas as entidades alteradas estão disponíveis através das funções:

  • getScheduledEntityInsertions() = Entidades marcadas para serem inseridas.
  • getScheduledEntityUpdates() = Entidades que sofreram alteração.
  • getScheduledEntityDeletions() = Entidades marcadas para serem excluídas.

Para ativar o logger acrescente as linhas abaixo, por exemplo, no “config/autoload/local.php”:

'doctrine' => array(
    'eventmanager' => array(
        'orm_default' => array(
            'subscribers' => array(
                'LosLog\Log\EntityLogger'
            )
        )
    )
)

E como fica nosso log?

Inserindo:

2013-07-29T07:43:41-02:00 DEBUG (7): Inserindo entidade Cliente\Entity\Cliente. Campos: {"nome":[null,"clienteTeste"],"cadastrado":[null,{"date":"2012-11-26 07:43:41","timezone_type":3,"timezone":"America\/Sao_Paulo"}]}

Alterando:

2013-07-29T07:13:24-02:00 DEBUG (7): Alterando entidade Usuario\Entity\Usuario com id 1. Data: {"validado":["nao","sim"],"validacao":["4321",""]}

Excluindo:

2013-07-29T07:32:38-02:00 DEBUG (7): Removendo entidade Usuario\Entity\Usuario leandro.

Usando a função getEntityChangeSet, temos apenas os campos alterados, o que facilita vermos o que realmente foi alterado. No caso do insert o valor do campo antes será sempre “null”.

Referência:

http://docs.doctrine-project.org/projects/doctrine-orm/en/latest/reference/events.html

Até a próxima!

Leandro Silva

2 comentários sobre “Log para Doctrine2 e ZF2

Deixe uma resposta

This site uses Akismet to reduce spam. Learn how your comment data is processed.