как я провел лето

Коллеги для тестирования выбрали распоследний AIX 7.1, Oracle 11.2.0.2, установили PSU (стало 11.2.0.2.2).  Хранение данных на ASM.  Немедленно после попытки старта ~3000 сессией kernel time взлетел в потолок, а диски наоборот. Разработчики AIX думали недолго, и исправленный код будет включен в 7.1.0 SP2

Особенно доставил комментарий к  патчу  "the changes are complicated and involve legacy code that has not been touched in 20 years". Проблема оказалась в том, что нагрузочный тул запускал работу всех сессий одновременно, а не давал им работать сразу после входа. Понятно, что ситуация нежизненная, а искусственная. Надо сказать, что почти одновременно был поставлен и патч  Bug 11800170 - ASM IN KSV WAIT AFTER APPLICATION OF 11.2.0.2 GRID PSU, и возможно он также помог.

Немедленно после того как удалось справиться с kernel time, почта доставила вот такой AWR:

 

с исконно русским вопросом - кто виноват и что делать ?  Тема mutex X беспокоит народ очень давно, и кажется что каждый новый пачтсет привносит свои изменения. В нашем случае у меня сложилось убеждение что новый PSU не исключение. Поиск по My Oracle Support навел на Bug 12431716 - Mutex waits may cause higher CPU usage in 11.2.0.2.2 PSU / GI PSU [ID 12431716.8]  и рекомендацией to apply Patch:12431716 on top of the 11.2.0.2.2 PSU. В нашем случае применение патча  - никаких изменений к лучшему.  Внимательное чтение вышеприведенного привело к обнаружению Bug 10411618 - Enhancement to add different "Mutex" wait schemes [ID 10411618.8] и понимаю наличия параметра _mutex_wait_scheme. Проводились эксперименты с установкой этого параметра в 0, и надо отметить, что поведение системы меняется. Поэтому если мы поставили уже PSU, и mutex вдруг появились - можно это попробовать. По молчанию _mutex_wait_scheme = 2, так мы и решили продолжать.

Продолжать кстати оказалось удобно с помощью весьма известного скрипта snapper by Tanel Poder:

SQL> @snapper ash=sql_id+event+wait_class+blocking_session+p2+p3 5 1 all
Sampling SID all with interval 5 seconds, taking 1 snapshots...

-- Session Snapper v3.52 by Tanel Poder @ E2SN ( http://tech.e2sn.com )


------------------------------------------------------------------------------------------------------------------------------------
Active% | SQL_ID          | EVENT                     | WAIT_CLASS      | BLOCKING_SES | P2                   | P3
------------------------------------------------------------------------------------------------------------------------------------
  5175% | 5xqa6qnbagf2b   | ON CPU                    | ON CPU          |              |                      |
  3200% |                 | db file parallel write    | System I/O      |              | 0                    | 2147483647
  2725% | ampvmj3gx3n16   | ON CPU                    | ON CPU          |              |                      |
  1475% | 06bfg06g97f27   | ON CPU                    | ON CPU          |              |                      |
  1050% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency     | 7374         | 60073707569152       | 82
   900% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency     |              | 60073707569152       | 82
   850% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency     | 15371        | 54885387075584       | 82
   700% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency     |              | 54885387075584       | 82
   625% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency     |              | 29781303230464       | 82
   600% |                 | ON CPU                    | ON CPU          |              |                      |



SQL> @snapper ash 5 1 12062
Sampling SID 12062 with interval 5 seconds, taking 1 snapshots...

-- Session Snapper v3.52 by Tanel Poder @ E2SN ( http://tech.e2sn.com )


-----------------------------------------------------------------------
Active% | SQL_ID          | EVENT                     | WAIT_CLASS
-----------------------------------------------------------------------
    68% | gvzx29hj54zfm   | library cache lock        | Concurrency
    32% | gvzx29hj54zfm   | library cache: mutex X    | Concurrency

Wow.  Найден проблемный sql_id ! Не тут то было. Обнаружить этот sql_id в v$sql  не удалось. Это интересный момент кстати, и что это было не очень понятно. Чуть позже разработчик признался, что был ошибочный запрос (в котором была указана несуществующая таблица) и возможно это и было причиной всех бед и это и был наш 'непойманный' sql_id.

А пока я провел несколько  дней  на замечательном блоге Андрея Николаева (РДТЕХ), который  описал возможность  пометить некоторые объекты как горячие в библиотечном  кэше. Обязательно прочитайте, крайне рекомендую. Описанная в блоге Андрея технология была приведена в действие.

Поскольку паника нарастала, делалось несколько изменений сразу, и сказать однозначно, что привело к результату, который вы видите ниже, сложно.

Это была если не победа, то по крайне мере серьезный прогресс. Конечно, это не окончание истории, еще не ответили за свое "kokc descriptor allocation latch",  требуется разбираться с ORA-00600: internal error code, arguments: [pesld02: nlui] (которая признается на metalink как следствие использования Edition Based Redefinition, которые не использовались) но это другая история. 

Вместо заключения: установка PSU на 11.2.0.2 - дело не такое простое как может показаться. Вернее не сама установка, а ее возможные последствия. Если вы решитесь, то сразу вместе с PSU ставьте и указанные тут патчи и все что выйдут к тому времени. Удачи !

Update 1: Убедитесь в том то у вас стоит Patch 10190759: PROCESSES CONSUMING ADDITIONAL MEMORY DUE TO 'USLA HEAP'

Update 2: Коллеги предложили немного другой AWR, за другой диапазон времени, в которой история представляется не такой счастливой как показалось мне:

Так что to be continued по полной программе -(