Version 11.2.0.3 , Windows 2008R2
Столкнулись с ситуацией повышенного log file sync wait.
Конечно написанное приложение далеко от идеала, и в БД очень много коммитов. Но раньше такой ситуации по ожиданиям не возникало, а код остался нетронутым.
Деградации в производительности дискового хранилища и сети не были найдены, всё железо стабильно продолжало работать. В алертлоге ничего путного тоже нет, только:
«Thu Mar 30 15:20:19 2017
Thread 1 cannot allocate new log, sequence 4824
Private strand flush not complete»
Который в принципе можно игнорировать.
Ввиду того, что Standard edition, нужно было поставить statspack, и к сожалению состояние работы системы до возрастания ожидания не мониторилось.
Посмотрим среднее значение ожидания:
Оно же у нас и в «Top 5 Timed Events»
| Event | Waits | Time (s) | Avg wait (ms) |
| log file sync | 12,625,283 | 172,525 | 14 |
Сравним со средним значение, что тратится на запись на диск:
| Event | Waits | Time (s) | Avg wait (ms) |
| log file parallel write | 16,518,450 | 9,700 | 1 |
Окей, 1 мс мы записываем, а остальные 14 мы что делаем? Обычно основа ожидания для «log file sync» это долгая запись на диск, а здесь всё записалось довольно быстро — в пределах нормы.
Вывод: Это не проблемы ввода/вывода.
Заглянув в трейс файл LGWR, обнаружил среди стандартных сообщений:
«*** 2017-03-29 03:19:38.301
kcrfw_update_adaptive_sync_mode: post->poll long#=1 sync#=1 sync=88317 poll=31980 rw=15990 rw+=17966 ack=0 min_sleep=15237
*** 2017-03-29 03:19:38.301
Log file sync switching to polling
Current scheduling delay is 1 usec
Current approximate redo synch write rate is 0 per sec»
Вот здесь самое интересное.
Начиная с 11gR2 LGWR может работать в двух режимах — «Post/wait» и «Polling».
Post/wait — традиционный метод, когда log writer явно оповещает все ждущие процессы, что коммит завершён.
Преимущества режима post/wait в том, что сессии практически сразу узнают, когда redo был сброшен на диск.
Polling — Foreground процессы (те которые обслуживают пользовательские сессии) засыпают на «некоторое время», а затем опрашивают, был ли завершён коммит.
Преимущества этого метода заключается в освобождении LGWR от оповещения множества ждущих завершения коммита процессов, тем самым снимая высокое использование CPU для LGWR.
Изначально, LGWR использует post/wait и согласно внутреннему алгоритму оценивает, будет ли лучше использовать pooling. Под высокой нагрузкой polling может выполняться лучше потому, что выполнение post/wait обычно плохо масштабируется. Если нагрузка на систему низкая, тогда post/wait выполняется лучше и обеспечивает лучшее время отклика, чем при использовании polling. Oracle полагается на внутреннюю статистику для определения метода, который должен использоваться. Ввиду того, что переключение между «Post/wait» и «Polling» влечёт за собой накладные расходы, существует защитный механизм, который гарантирует, что переключения не будут происходить слишком часто.
Все переключения записываются в файл трассировки LGWR с временной меткой и строкой «Log file sync switching to …».
Можно посмотреть статистику по pooling в v$sysstat:
SQL> select name,value from v$sysstat where name in ('redo synch poll writes','redo synch polls');
| NAME | VALUE |
| redo synch poll writes | 76138986 |
| redo synch polls | 71409810 |
Мы видим, что использовался polling. Эта статистика также отражается в отчётах statspack и AWR.
В подавляющем большинстве случаев адаптивная синхронизация лог файла улучшает общую производительность (в части синхронизации лог файла).
Начиная с 11gR2 был введён параметр «_use_adaptive_log_file_sync», который контролирует будет ли включено адаптивное автоматическое переключение между post/wait и polling. В 11.2.0.1 и 11.2.0.2 значение по умолчанию у этого параметра = «false». С 11.2.0.3, его значение «true».
После выполнения:
ALTER SYSTEM SET "_use_adaptive_log_file_sync"= FALSE scope=both;
посмотрим снова в отчёт statspack’а
| Event | Waits | Time (s) | Avg wait (ms) |
| log file sync | 132,558 | 54 | 0 |
В 11:55 было изменено значение параметра, визуально выглядит так:
Как уже говорилось, при polling — Foreground процессы засыпают на «некоторое время», и это «некоторое время» вероятно оказывается довольно длительным, в следствии чего значительно растёт ожидание log file sync.
Всем успехов!