ORA-600 raised in ASM I/O path, [ossnet_assign_msgid_1]

Today fought with error in alert log (Database 12.1.0.2.11 on Exadata, image 12.1.2.1.2):

 

ORA-00600: internal error code, arguments: [ossnet_assign_msgid_1], [], [], [], [], [], [], [], [], [], []

ERROR: unrecoverable error ORA-600 raised in ASM I/O path

MOS found nothing direct links about this error.

As of note " 12.1.0.2 Bundle Patches for Engineered Systems and DB In-Memory - List of Fixes in each Bundle (Doc ID 1937782.1) "

this is the bug:

18663279

ORA-600 [OSSNET_ASSIGN_MSGID_1] CAUSED BY TO SMALL VALUE _SMM_AUTO_MIN_IO_SIZE

The solution which helped to us:

alter system set "_smm_auto_max_io_size"=2048 scope=both sid='*';

alter system set "_smm_auto_min_io_size"=2040 scope=both sid='*';

 

ORA-00439: feature not enabled: Server Flash Cache

Порекомендовал я на одной БД воспользоваться преимуществами флеш кеша.
http://docs.oracle.com/cd/E11882_01/server.112/e25494/memory005.htm#BABHEDBH

Заказчик купил карточку, задал параметры

db_flash_cache_file=/ssd/flashfile.dbf
db_flash_cache_size=36g
И перестартовал БД.  В результате получилось:

ORA-00439: feature not enabled: Server Flash Cache

Оказывается - баг:  Bug 12949806 - FLASH CACHE CHECK IS AGAINST ENTERPRISE-RELEASE  !
Сейчас против этого бага Оракл предлагает патч 12949806.
Окончательно бещают исправить в 11.2.0.4.

 

INSERT INTO wrh$_tempstatxs () - is pseudo AWR bug

In addition to my previous AWR bugs post.

The new database in Exadata. No any workload.
This Insert was executed on both nodes of cluster during 3 minutes each (history from bottom to top):

DBControl shows one Insert into WRH$-tempstatxs, which is the part of AWR:

I decided to gather some add statistics - for dictionary and for fixed views as I did it last time, but bad Insert appears soon after my statistics gathering. You see it in both screenshots.

The solution was found by chance - after db restart bad Insert disappeared forever.

ADDM bug

В addm-отчете часто возникает такая пугающая рекомендация:

Finding 1: Virtual Memory Paging
Impact is 5.14 active sessions, 100% of total activity.
-------------------------------------------------------
Significant virtual memory paging was detected on the host operating system.

   Recommendation 1: Host Configuration
   Estimated benefit is 5.14 active sessions, 100% of total activity.
   ------------------------------------------------------------------
   Action
      Host operating system was experiencing significant paging but no
      particular root cause could be detected. Investigate processes that do
      not belong to this instance running on the host that are consuming
      significant amount of virtual memory. Also consider adding more physical
      memory to the host.

Причем,
- особого пейджиинга в ОС не видно
- исправить ситуацию не получается (уменьшение SGA эффекта не дает - сообщение появляется).


Как оказалось, это баг ADDM: ADDM Reports Significant Virtual Memory Paging [ID 1322964.1]

This issue can be seen from 10.2.0.5 to 11.2.0.2

The problem is caused by wrong values in V$OSSTAT as explained in
Bug 10148787 ADDM REPORTS VIRTUAL MEMORY PAGING AFTER APPLYING 10.2.0.5
and unpublished Bug 11712010: VIRTUAL MEMORY PAGING ON 11.2.0.2 DATABASES.
both these bugs are closed as duplicate of unpublished Bug 10220118: NEED TO ALERT WHEN SYSTEM IS CLOSE TO PAGING

В общем, есть патчик, который исправляет данную ситуацию. Завлено, что 11.2.0.3 этот баг исправлен.

pseudo AWR bug

Сегодня обнаружилась интересная картина: AWR перестал делать снапшоты. Т.е. не то чтобы совсем перестал, а просто долго делает снапшот.  Для удобства анализа сделали так:

SQL> select sid from v$mystat where rownum<2;

       SID

----------

       614

SQL> alter session set events '10046 trace name context forever, level 12';

Session altered.

SQL> exec dbms_workload_repository.create_snapshot;

и стали смотреть в трейс файл :

[oracle@ODA01-pub1 trace]$ tail -100f ODA01DB1_ora_12958.trc

WAIT #46931816430624: nam='control file sequential read' ela= 179 file#=0 block#=1 blocks=1 obj#=-1 tim=1324627288235588

WAIT #46931816430624: nam='control file sequential read' ela= 185 file#=0 block#=40 blocks=1 obj#=-1 tim=1324627288235898

WAIT #46931816430624: nam='control file sequential read' ela= 182 file#=0 block#=42 blocks=1 obj#=-1 tim=1324627288236178

WAIT #46931816430624: nam='control file sequential read' ela= 183 file#=0 block#=113 blocks=1 obj#=-1 tim=1324627288236456

WAIT #46931816430624: nam='control file sequential read' ela= 179 file#=0 block#=1 blocks=1 obj#=-1 tim=1324627288236791

WAIT #46931816430624: nam='control file sequential read' ela= 183 file#=0 block#=40 blocks=1 obj#=-1 tim=1324627288237131

WAIT #46931816430624: nam='control file sequential read' ela= 185 file#=0 block#=42 blocks=1 obj#=-1 tim=1324627288237413

WAIT #46931816430624: nam='control file sequential read' ela= 181 file#=0 block#=113 blocks=1 obj#=-1 tim=1324627288237716

WAIT #46931816430624: nam='control file sequential read' ela= 182 file#=0 block#=1 blocks=1 obj#=-1 tim=1324627288238056

WAIT #46931816430624: nam='control file sequential read' ela= 184 file#=0 block#=40 blocks=1 obj#=-1 tim=1324627288238361

WAIT #46931816430624: nam='control file sequential read' ela= 187 file#=0 block#=42 blocks=1 obj#=-1 tim=1324627288238644

WAIT #46931816430624: nam='control file sequential read' ela= 184 file#=0 block#=113 blocks=1 obj#=-1 tim=1324627288238924

WAIT #46931816430624: nam='control file sequential read' ela= 177 file#=0 block#=1 blocks=1 obj#=-1 tim=1324627288239256

WAIT #46931816430624: nam='control file sequential read' ela= 178 file#=0 block#=40 blocks=1 obj#=-1 tim=1324627288239557

WAIT #46931816430624: nam='control file sequential read' ela= 176 file#=0 block#=42 blocks=1 obj#=-1 tim=1324627288239857

WAIT #46931816430624: nam='control file sequential read' ela= 180 file#=0 block#=113 blocks=1 obj#=-1 tim=1324627288240135

В общем, что-то зациклилось...

Металинк предлагает отгадку:  AWR Snapshot Causes Many Control File Sequential Read Waits [ID 941761.1]  ... AWR snapshots are taking a lot of time flushing WRH$_THREAD ...

В доке рекомендовано:

alter system set "_awr_disabled_flush_tables"='wrh$_thread';

Однако эта рекомендация "в лоб" не помогла. События 'control file sequential read' продолжались, и снапшот собирался долго. Поэтому пришлось еще немного покопаться: Смотрим

WAIT #46931816430624: nam='control file sequential read' ela= 260 file#=0 block#=1 blocks=1 obj#=-1 tim=1324626633244332

Событие ожидания относится к курсору  #46931816430624

Ищем в трейсе этот курсор: 

PARSING IN CURSOR #46931816430624 len=881 dep=1 uid=0 oct=2 lid=0 tim=1324626633222179 hv=2600278305 ad='c57822e90' sqlid='6vntx5ydgu691'
insert into wrh$_tempstatxs   (snap_id, dbid, instance_number, file#, creation_change#, phyrds,    phywrts, singleblkrds, readtim, writet
im, singleblkrdtim, phyblkrd,    phyblkwrt, wait_count, time)  select    :snap_id, :dbid, :instance_number,    tf.tfnum, to_number(tf.tfc
rc_scn) creation_change#,    ftio.kcftiopyr, ftio.kcftiopyw, ftio.kcftiosbr,    floor(ftio.kcftioprt / 10000), floor(ftio.kcftiopwt / 100
00),    floor(ftio.kcftiosbt / 10000), ftio.kcftiopbr, ftio.kcftiopbw,    fw.count, fw.time  from    x$kcftio ftio, x$kcctf tf, x$kcbfwai
t fw, x$kccfn fn, x$kccts ts  where    ts.tstsn       = tf.tftsn  and    ftio.kcftiofno = fn.fnfno  and    tf.tfnum       = fn.fnfno  and
    tf.tffnh       = fn.fnnum  and    tf.tfdup       <> 0        and    fn.fntyp  = 7 and    fn.fnnam is not null       and    bitand(tf.
tfsta, 32) <> 32 and    fw.indx+1  = (fn.fnfno + :db_files)
 

Оказывается, он относится к таблице wrh$_tempstatxs.

Поэтому переписываем alter system:

alter system set "_awr_disabled_flush_tables"='wrh$_tempstatxs';    

Во первых: ТОЖЕ НЕ ПОМОГЛО !

Во-вторых: эта команда затерла значение предыдущей: "_awr_disabled_flush_tables"='wrh$_thread'

Возникла мысль - что это за беда, если для каждой таблички WR* надо руками включать специфические свойства? Не является ли причина более общей?



Поэтому дальше сделал так:

exec dbms_stats.gather_fixed_objects_stats;
exec dbms_stats.gather_dictionary_stats;



И - вуаля - результат налицо :


SQL> alter system reset "_awr_disabled_flush_tables" ;
System altered.

SQL> /
alter system reset "_awr_disabled_flush_tables"
*
ERROR at line 1:
ORA-32010: cannot find entry to delete in SPFILE

SQL> set timing on
SQL> exec dbms_workload_repository.create_snapshot;
PL/SQL procedure successfully completed.

Elapsed: 00:00:06.77




Отсюда вывод - СОБИРАЙТЕ СТАТИСТИКУ НА СЛОВАРЬ И НА FIXED TABLES!!!