Usamos cookies para medir audiência e melhorar sua experiência. Você pode aceitar ou recusar a qualquer momento. Veja sobre o iMasters.
Em ambientes OLTP, um dos maiores problemas de performance é o excesso de eventos de espera para Gravações em Online Redo Log Files. Toda vez que o Oracle Database aguarda por gravações nesses arquivos pode-se observar os eventos "Log File Sync" e "Log File Parallel Write".
O que é o evento de espera 'log file sync'?
Quando uma sessão de um usuário ou aplicação executa um commit, as informações de Redo armazenadas em memória (LOG_BUFFER) são descarregadas nos Online Redo Log Files para tornar as alterações executadas permanentes no banco de dados. Esse processo é executado pelo LOG WRITER (LGWR). Quando o processo LGWR termina essa gravação, um aviso é enviado para a sessão informando que o processo de commit está 100% completo.
O tempo entre a sessão de usuário/aplicação solicitar ao LGWR a gravação dos redos da memória (LOG_BUFFER) para os Online Redo Log Files e o LGWR informar a sessão que o processo foi concluído é onde ocorre o evento 'log file sync'.
Como identificar o evento 'log file sync'?
Para analisar e identificar o evento 'log file sync', pode-se utilizar as informações de:
Onde ocorrem os eventos de espera 'log file sync'?
Eventos de espera em 'log file sync' podem acontecer em qualquer etapa entre a sessão de usuário/aplicação solicitar ao LGWR a gravação dos redos da memória (LOG_BUFFER) para os Online Redo Log Files e o LGWR informar a sessão que o processo foi concluído.
Performance do LGWR
A principal questão é "existe algum problema de performance para gravação nos Online Redo Logs"?
Os passos abaixo podem ajudar a encontrar problemas de performance no Log Writer (LGWR):
1. Comparando tempo médio de espera em 'log file sync' com tempo médio de espera em 'log file parallel write'
O evento de espera 'log file parallel write' ocorre enquanto o LGWR está gravando as informações de redo nos Online Redo Log Files. O tempo total desse evento é o tempo total de gravação nos arquivos em disco.
Analisando esse evento em conjunto com o evento 'log file sync', pode-se identificar o tempo total e consumo de I/O para conclusão de um ciclo commit .
Analisando as informações em um relatório AWR:
/applications/core/interface/imageproxy/imageproxy.php?img=http://conteudo.imasters.com.br/24876/48248.png&key=25206c4128494ae94c477980d3edbfa9068f3359357089447ba0ab8a6acf72ed" alt="48248.png" />
No exemplo acima, pode-se identificar um alto consumo de tempo e I/O (ms) para ambos eventos 'log file sync' e 'log file parallel write'. A proporção de tempo entre 'log file sync' e 'log file parallel write' sugere um problema de I/O (aguardando a gravação do redo da memoria para disco).
Se o tempo gasto no evento de espera 'log file parallel write' for superior a 20ms, a probabilidade de um problema de I/O é grande.
- Verifique nos filesystems onde estão os os arquivos de Redo Logs e verifique a possibilidade de otimizar a performance de I/O através do S.O;
- Não utilize RAID 5 para os filesystems/Discos onde estão localizados os Redo Logs;
- Verifique se não existem outros processos que podem estar gravando informações nos mesmos discos, onde estão localizados os Redo Logs. Certifique-se de que os discos têm throughput suficiente para concorrência desses processos, ou mude os Redo Logs de Filesystem;2. Verificar os Traces do Log Writer (LGWR)
Mesmo que o tempo médio de espera do evento 'log file parallel write' esteja normal, podem existir picos onde a escrita dos Redo Logs esteja alta e influenciem no então o evento 'log file sync'.
A partir da versão 10.2.0.4, são geradas mensagens de alerta em arquivos trace do LGWR quando um processo de escrita do LGWR demora mais que 500ms. Esse é um threshold alto, porém é uma maneira de identificar problemas de I/O. As mensagens são semalhantes a:
/applications/core/interface/imageproxy/imageproxy.php?img=http://conteudo.imasters.com.br/24876/48249.png&key=db48f2f5723df893915a4f7cd4a124864006b55a047f4a704f59583ce0797400" alt="48249.png" />
Uma operação 'log file sync' é executada toda vez que ocorre um switch dos logfiles para garantir que toda a informação nos Redos foi gravada antes que o próximo log seja iniciado. Como padrão, a recomendação é que um log switch ocorra a cada 15 ou 20 minutos. Se os log switchs ocorrerem em tempo menor, com mais frequência, então mais eventos de espera 'log file sync' irão ocorrer, o que significa um maior tempo de espera entre as sessões.
Pode-se verificar o alert.log para verificar o switch de logfiles:
/applications/core/interface/imageproxy/imageproxy.php?img=http://conteudo.imasters.com.br/24876/48250.png&key=cae7e52fbe5b9aa24d3a8396d256a8b5cfb9ae3cc55ea1e9195ad24a60cdcfe5" alt="48250.png" />
No exemplo acima, pode-se verificar switchs a cada 2 ou 4 minutos, o que é cinco vezes mais frequente do que o recomendável.
Outra opção é verificar a média de Log Switchs através de relatório AWR:
/applications/core/interface/imageproxy/imageproxy.php?img=http://conteudo.imasters.com.br/24876/48251.png&key=407bfe823c916df8d7c6ba70f565a0cf2cc435ada7dc541e5ef4d43022d03042" alt="48251.png" />
No exemplo acima, ocorrem 29.98 log switchs a cada hora, o que significa cerca de dois log switchs por minuto. Esse é um valor muito acima do recomendado (15 à 20 switchs por minuto).
Nesse caso, a pergunta que se deve fazer é: "a aplicação está realizando muitos commits?". Caso sim, podem ocorrer problemas de performance, uma vez que as informações de Redo são descarregadas da memória (LOG_BUFFER) para Redo Logs em disco.
Uma maneira simples de identificar esse cenário é quando a média de espera para o evento 'log file sync' é muito maior que média de espera do evento 'log file parallel write'; isso mostrará que o tempo maior de espera não é para gravação em disco dos Redo Logs. O alto tempo de CPU também pode mostrar a contenção causada por commits excessivos.
Outro cenário ainda é onde a média de espera do evento 'log file sync' é baixa, mas o número de waits é alto. Pode-se comparar a média de 'User commits' com 'User calls':
/applications/core/interface/imageproxy/imageproxy.php?img=http://conteudo.imasters.com.br/24876/48252.png&key=7c2e6c73f1a2d318b282aa3a3faa73347888858f61ba3dfb46d75bbef8a55d53" alt="48252.png" />
No exemplo acima, pode-se identificar 5.76 'user calls' por commit, o que é considerado cinco vezes maior que o recomendado (1).
Fontes:
[http://imasters.com.br/artigo/24876/oracle/entendendo-os-eventos-de-espera-log-file-sync-e-log-file-parallel-write
Carregando comentários...