Entendendo os Eventos de Espera “Log File Sync e Log File Parallel Write”
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 nestes 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. Este 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:
- Relatórios AWR de um prazo pontual de coleta.
- Arquivos de Trace do LGWR. Estes arquivos podem mostrar muitos eventos de espera em ‘log file parallel wait’
Onde ocorrem os Eventos de Espera ‘log file sync’?
Eventos de espera em ‘log file sync’ pode 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 deste evento é o tempo total de gravação nos arquivos em disco.
Analisando este 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:
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.
Recomendações
- Verifique os filesystems onde estão os os Arquivos de Redo Logs, e verifique a possbilidade 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 que os discos temthroughput suficiente para concorrência destes processos, ou mude os Redo Logs de Filesystem.
- Verifique se o parâmetro LOG_BUFFER não está muito grande. Quanto
2 – Verificar os Traces do Log Writer (LGWR)
Mesmo que o tempo média 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. Este é um threshold alto, porém é uma maneira de identificar problemas de I/O. As mensagens são semalhantes à:
Recomendações
- Verifique o que mais está sendo executado neste momento para identificar gaps de gravação do LGWR.
3 – Verificar se o tamanho dos Redo Logs é Suficiente
Uma operação ‘log file sync’ é executada toda vez que ocorre um switch dos logfiles para garantir que toda a informação nos redos foram gravadas antes de 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:
No exemplo acima pode-se verificar switchs a cada 2 à 4 minutos, o que é 5x mais frequente do que o recomendável.
- Outra opção é verificar a média de Log Switchs através de relatório AWR:
No exemplo acima ocorrem 29.98 log switchs a cada hora, o que significa cerca de 2 log switchs por minuto. Este é um valor muito acima do recomendado (15 à 20 switchs por minuto).
Recomendações
- Aumentar o tamanho dos arquivos Redo Logs.
3 – Número excessivo de COMMITs pela Aplicação
Neste caso a pergunta que se deve fazer é: “A aplicação está realizando muitos COMMITs?”
Caso sim, pode 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 este 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’:
No exemplo acima pode-se identificar 5.76 ‘user calls’ por commit o que é considerado 5x maior que o recomendado (1).
Recomendações:
- Se existirem vários commits na aplicação em um intervalo de tempo curto, ou ainda pequenas chamadas de commits, recomenda-se executar um bloco de alterações maior antes da execução de um commit. Esta ateração deve ser feita através da aplicação.
- Ativação do Asynchronous Commit.
Fontes
- How to Minimise Waits for ‘Log File Sync’? [MOS ID 857576.1]
- Troubleshooting: log file sync’ Waits [MOS ID 1376916.1]
Abraço
