ORA-03113 ao Coletar Estatísticas

Tive o erro abaixo ao coletar as estatísticas do banco de dados.

[oracle@NomeDoServidor ~]$ rlwrap sqlplus / as sysdba

SQL*Plus: Release 11.2.0.4.0 Production on Tue Nov 21 13:13:54 2017

Copyright (c) 1982, 2013, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Release 11.2.0.4.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options

13:13:54 SYS@NomeDaInstância> EXEC DBMS_STATS.GATHER_DATABASE_STATS(OPTIONS=>'GATHER STALE', GATHER_SYS=>FALSE);
BEGIN DBMS_STATS.GATHER_DATABASE_STATS(OPTIONS=>'GATHER STALE', GATHER_SYS=>FALSE); END;

*
ERROR at line 1:
ORA-03113: end-of-file on communication channel
Process ID: 43593
Session ID: 1424 Serial number: 63041


Elapsed: 00:19:26.44
13:33:23 SYS@NomeDaInstância>

Executei a coleta em Trace 10046, e encontrei no arquivo de Trace o momento onde o erro acontecia, que era ao fazer Full Table Scan em uma determinada tabela.

WAIT #139856296838216: nam='db file sequential read' ela= 7262 file#=12 block#=3954630 blocks=1 obj#=143592 tim=1511278401731267
WAIT #139856296838216: nam='db file sequential read' ela= 3881 file#=12 block#=3954646 blocks=1 obj#=143592 tim=1511278401736803
WAIT #139856296838216: nam='db file sequential read' ela= 6128 file#=12 block#=3954648 blocks=1 obj#=143592 tim=1511278401743063
WAIT #139856296838216: nam='db file sequential read' ela= 7003 file#=12 block#=3954664 blocks=1 obj#=143592 tim=1511278401751324
WAIT #139856296838216: nam='gc cr block 2-way' ela= 539 p1=12 p2=3954730 p3=1 obj#=143592 tim=1511278401755496
WAIT #139856296838216: nam='db file sequential read' ela= 8441 file#=12 block#=3954825 blocks=1 obj#=143592 tim=1511278401765580
WAIT #139856296838216: nam='db file sequential read' ela= 7681 file#=12 block#=3954841 blocks=1 obj#=143592 tim=1511278401773661
WAIT #139856296838216: nam='db file sequential read' ela= 3302 file#=12 block#=3954965 blocks=1 obj#=143592 tim=1511278401787616
WAIT #139856296838216: nam='db file sequential read' ela= 2590 file#=12 block#=3955028 blocks=1 obj#=143592 tim=1511278401793624
WAIT #139856296838216: nam='db file sequential read' ela= 5395 file#=12 block#=3955048 blocks=1 obj#=143592 tim=1511278401800672
WAIT #139856296838216: nam='db file sequential read' ela= 7526 file#=12 block#=3955064 blocks=1 obj#=143592 tim=1511278401808825
WAIT #139856296838216: nam='db file sequential read' ela= 3732 file#=12 block#=3955141 blocks=1 obj#=143592 tim=1511278401815277
WAIT #139856296838216: nam='db file sequential read' ela= 1298 file#=12 block#=3955157 blocks=1 obj#=143592 tim=1511278401817521
WAIT #139856296838216: nam='db file scattered read' ela= 4655 file#=12 block#=3955172 blocks=2 obj#=143592 tim=1511278401822979
WAIT #139856296838216: nam='db file scattered read' ela= 4344 file#=12 block#=3955188 blocks=2 obj#=143592 tim=1511278401828221
WAIT #139856296838216: nam='db file sequential read' ela= 7057 file#=12 block#=3955223 blocks=1 obj#=143592 tim=1511278401836666
WAIT #139856296838216: nam='db file sequential read' ela= 5353 file#=12 block#=3955239 blocks=1 obj#=143592 tim=1511278401842694
FETCH #139856296838216:c=18624168,e=19313973,p=217,cr=81660,cu=0,mis=0,r=1,dep=1,og=1,plh=1298281348,tim=1511278401843303
STAT #139856296838216 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=81660 pr=217 pw=0 time=19313636 us)'
STAT #139856296838216 id=2 cnt=1178556 pid=1 pos=1 obj=0 op='APPROXIMATE NDV AGGREGATE (cr=81660 pr=217 pw=0 time=9759463 us cost=16834 size=361237110 card=896370)'
STAT #139856296838216 id=3 cnt=1178556 pid=2 pos=1 obj=143592 op='TABLE ACCESS FULL NomeDaTabela (cr=81660 pr=217 pw=0 time=2457609 us cost=16834 size=361237110 card=896370)'
CLOSE #139856296838216:c=0,e=48,dep=1,type=0,tim=1511278401850104

*** 2017-11-21 13:33:21.850
Exception [type: SIGSEGV, Address not mapped to object] [ADDR:0xFFFFFFFFFFFFFFF0] [PC:0x9009415, kghfnd()+2725] [flags: 0x0, count: 1]

*** 2017-11-21 13:33:21.950
Incident 855537 created, dump file: /u01/app/oracle/diag/rdbms/NomeDoBanco/NomeDaInstância/incident/incdir_855537/NomeDaInstância_ora_43593_i855537.trc
ORA-07445: exception encountered: core dump [kghfnd()+2725] [SIGSEGV] [ADDR:0xFFFFFFFFFFFFFFF0] [PC:0x9009415] [Address not mapped to object] []

ssexhd: crashing the process...
Shadow_Core_Dump = partial
ksdbgcra: writing core file to directory '/u01/app/oracle/diag/rdbms/NomeDoBanco/NomeDaInstância/cdump'

Tentei apagar as estatísticas da tabela, e coleta, mas não funcionou.

13:35:40 SYS@NomeDaInstância> EXEC DBMS_STATS.DELETE_TABLE_STATS('NomeDoOwner','NomeDaTabela');

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.80
13:35:47 SYS@NomeDaInstância> EXEC DBMS_STATS.GATHER_TABLE_STATS('NomeDoOwner','NomeDaTabela');
BEGIN DBMS_STATS.GATHER_TABLE_STATS('NomeDoOwner','NomeDaTabela'); END;

*
ERROR at line 1:
ORA-03113: end-of-file on communication channel
Process ID: 9935
Session ID: 1424 Serial number: 63063


Elapsed: 00:00:16.35

Como o erro ocorria ao executar APPROXIMATE NDV AGGREGATE (NDV – Number of Distinct Values), arrisquei coletar com 100%, ao invés de utilizar a aproximação, pois o Approximate Query Processing é uma New Feature lançada no 11.2.0.4, e New Feature = New Problem. Também não funcionou, mas pelo menos o erro mudou. 😀
Fonte: Approximate Query Processing in Oracle Database 12c Release 2 (12.2)

[oracle@NomeDoServidor ~]$ rlwrap sqlplus / as sysdba

SQL*Plus: Release 11.2.0.4.0 Production on Tue Nov 21 13:37:06 2017

Copyright (c) 1982, 2013, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Release 11.2.0.4.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options

13:51:32 SYS@NomeDaInstância> EXEC DBMS_STATS.GATHER_TABLE_STATS('NomeDoOwner', 'NomeDaTabela', ESTIMATE_PERCENT=>100);
BEGIN DBMS_STATS.GATHER_TABLE_STATS('NomeDoOwner', 'NomeDaTabela', ESTIMATE_PERCENT=>100); END;

*
ERROR at line 1:
ORA-03113: end-of-file on communication channel
Process ID: 26320
Session ID: 1564 Serial number: 16205


Elapsed: 00:00:58.63
13:53:06 SYS@NomeDaInstância>

...
WAIT #140109894027136: nam='direct path read temp' ela= 1089 file number=201 first dba=2335488 block cnt=31 obj#=143592 tim=1511279584161497
WAIT #140109894027136: nam='direct path read temp' ela= 1446 file number=201 first dba=2336512 block cnt=22 obj#=143592 tim=1511279584206923
WAIT #140109894027136: nam='direct path read temp' ela= 824 file number=201 first dba=2335744 block cnt=19 obj#=143592 tim=1511279584230417
WAIT #140109894027136: nam='direct path read temp' ela= 143165 file number=201 first dba=2336896 block cnt=10 obj#=143592 tim=1511279584383697
WAIT #140109894027136: nam='direct path read temp' ela= 2675 file number=201 first dba=2338176 block cnt=31 obj#=143592 tim=1511279584400785
WAIT #140109894027136: nam='direct path read temp' ela= 687 file number=201 first dba=2336477 block cnt=1 obj#=143592 tim=1511279584423615

*** 2017-11-21 13:53:04.428
Exception [type: SIGSEGV, SI_KERNEL(general_protection)] [ADDR:0x0] [PC:0x4281632, __intel_new_memcpy()+3554] [flags: 0x0, count: 1]

*** 2017-11-21 13:53:04.580
Incident 855553 created, dump file: /u01/app/oracle/diag/rdbms/NomeDoBanco/NomeDaInstância/incident/incdir_855553/NomeDaInstância_ora_26320_i855553.trc
ORA-07445: exception encountered: core dump [__intel_new_memcpy()+3554] [SIGSEGV] [ADDR:0x0] [PC:0x4281632] [SI_KERNEL(general_protection)] []

ssexhd: crashing the process...
Shadow_Core_Dump = PARTIAL
ksdbgcra: writing core file to directory '/u01/app/oracle/diag/rdbms/NomeDoBanco/NomeDaInstância/cdump'

Desconfiei que o “erro” está nos dados, o que foi confirmado por uma tentativa de MOVE.

13:53:55 SYS@NomeDaInstância> ALTER TABLE NomeDoOwner.NomeDaTabela MOVE;
alter table NomeDoOwner.NomeDaTabela move
*
ERROR at line 1:
ORA-12899: value too large for column ??? (actual: 8, maximum: 1)


Elapsed: 00:00:00.08
13:54:04 SYS@NomeDaInstância>

E o que funcionou? Executar o velho ANALYZE com VALIDATE STRUCTURE, depois com COMPUTE STATISTICS, e como a tabela não era mais considerada STALE, minha rotina de coleta de estatísticas voltava a funcionar. Mas os Histogramas foram para o espaço, e eles necessários para algumas colunas desta tabela (e imagino que era exatamente por isso que o APPROXIMATE NDV AGGREGATE era necessário).

13:59:40 SYS@NomeDaInstância> ANALYZE TABLE NomeDoOwner.NomeDaTabela VALIDATE STRUCTURE;

Table analyzed.

Elapsed: 00:00:02.79
13:59:52 SYS@NomeDaInstância> ANALYZE TABLE NomeDoOwner.NomeDaTabela COMPUTE STATISTICS;

Table analyzed.

Elapsed: 00:02:12.67
14:02:18 SYS@NomeDaInstância> EXEC DBMS_STATS.GATHER_DATABASE_STATS(OPTIONS=>'GATHER STALE', GATHER_SYS=>FALSE);

PL/SQL procedure successfully completed.

Elapsed: 00:15:07.26
14:18:00 SYS@NomeDaInstância>

Como era esperado, esse problema voltou a ocorrer algumas vezes, por conta da tabela voltar a ser considerada STALE. Mas após aplicar o último PSU do 11.2.0.4, o problema deixou de ocorrer.

Leave a Reply

O seu endereço de e-mail não será publicado. Campos obrigatórios são marcados com *