Re: Weird "ORA-03113: end-of-file on communication channel" during parse
Date: Thu, 25 Mar 2021 14:30:23 +0000
Message-ID: <CACj1VR4ydY2J5UzYi2DpW2PiLkA2PWBpLWsYksK625vjxcsXDw_at_mail.gmail.com>
You’re going to need access to the alert log to see what’s going on. There
will be an ORA-7445 being hit which is ending your connection.
Thanks,
On Thu, 25 Mar 2021 at 14:24, Kim Berg Hansen <kibeha_at_gmail.com> wrote:
> Hmmm... If I query for two values, I get again that it works for one less
Andrew
> row than it would return:
>
> SQL> explain plan for
> 2 select sd.iddelivery
> 3 from arrow.splitdelivery sd
> 4 where sd.delpackoutloc in (-1, 2)
> 5 and rownum <= 343251 + 525 - 1;
>
> Explained.
>
>
> And it fails at the exact number of rows for the two values together:
>
> SQL> explain plan for
> 2 select sd.iddelivery
> 3 from arrow.splitdelivery sd
> 4 where sd.delpackoutloc in (-1, 2)
> 5 and rownum <= 343251 + 525;
> where sd.delpackoutloc in (-1, 2)
> *
> ERROR at line 4:
> ORA-03113: end-of-file on communication channel
> Process ID: 9016
> Session ID: 69 Serial number: 1934
>
>
>
> Hmm... ???
>
>
>
> Regards
>
>
> Kim Berg Hansen
> Senior Consultant at Trivadis
> Oracle ACE Director
>
> Author of Practical Oracle SQL
> <https://www.apress.com/gp/book/9781484256169>
> http://www.kibeha.dk
> kibeha_at_kibeha.dk
> _at_kibeha <http://twitter.com/kibeha>
>
>
>
> On Thu, Mar 25, 2021 at 3:12 PM Kim Berg Hansen <kibeha_at_gmail.com> wrote:
>
>> Hi, List
>>
>> I have an ORA-03113 error on a Windows 12.1.0.2 that seems to happen
>> during parse?
>> I don't have a good idea about what happens, so any ideas would be nice.
>>
>> Database version:
>>
>> SQL> select banner
>> 2 from v$version;
>> BANNER
>>
>> --------------------------------------------------------------------------------
>> Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit
>> Production
>> PL/SQL Release 12.1.0.2.0 - Production
>> CORE 12.1.0.2.0 Production
>> TNS for 64-bit Windows: Version 12.1.0.2.0 - Production
>> NLSRTL Version 12.1.0.2.0 - Production
>>
>>
>>
>> I do a simple query and my connection breaks with an ORA-03113:
>>
>> SQL> select sd.iddelivery
>> 2 from splitdelivery sd
>> 3 where sd.delpackoutloc = -1;
>> select sd.iddelivery
>> *
>> ERROR at line 1:
>> ORA-03113: end-of-file on communication channel
>> Process ID: 3964
>> Session ID: 38 Serial number: 45993
>>
>>
>>
>> Adding a superfluous NVL makes it work - the data can be retrieved
>> (doesn't look like corrupted data):
>>
>> SQL> set autotrace traceonly
>> SQL> select sd.iddelivery
>> 2 from arrow.splitdelivery sd
>> 3 where nvl(sd.delpackoutloc, 0) = -1;
>> 343251 rows selected.
>>
>> Execution Plan
>> ----------------------------------------------------------
>> Plan hash value: 87431401
>>
>> -----------------------------------------------------------------------------------
>> | Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
>> Time |
>>
>> -----------------------------------------------------------------------------------
>> | 0 | SELECT STATEMENT | | 343K| 3352K| 3075 (1)|
>> 00:00:01 |
>> |* 1 | TABLE ACCESS FULL| SPLITDELIVERY | 343K| 3352K| 3075 (1)|
>> 00:00:01 |
>>
>> -----------------------------------------------------------------------------------
>> Predicate Information (identified by operation id):
>> ---------------------------------------------------
>> 1 - filter(NVL("SD"."DELPACKOUTLOC",0)=(-1))
>>
>> Statistics
>> ----------------------------------------------------------
>> 67 recursive calls
>> 0 db block gets
>> 33210 consistent gets
>> 0 physical reads
>> 0 redo size
>> 4592111 bytes sent via SQL*Net to client
>> 251949 bytes received via SQL*Net from client
>> 22885 SQL*Net roundtrips to/from client
>> 1 sorts (memory)
>> 0 sorts (disk)
>> 343251 rows processed
>>
>>
>>
>> But the erroneous statement gives ORA-03113 even when trying just to
>> explain it:
>>
>> SQL> explain plan for
>> 2 select sd.iddelivery
>> 3 from splitdelivery sd
>> 4 where sd.delpackoutloc = -1;
>> explain plan for
>> *
>> ERROR at line 1:
>> ORA-03113: end-of-file on communication channel
>> Process ID: 11760
>> Session ID: 72 Serial number: 52015
>>
>>
>>
>> The column in the predicate is very skewed - 343 thousand out of 350
>> thousand have the value -1:
>>
>> SQL> select delpackoutloc, count(*)
>> 2 from splitdelivery
>> 3 group by rollup(delpackoutloc)
>> 4 order by delpackoutloc;
>> DELPACKOUTLOC COUNT(*)
>> ------------- ----------
>> -1 343251
>> 1 417
>> 2 525
>> 3 5865
>> 350058
>>
>>
>> The column has no NULL values, but it is *not *defined as NOT NULL.
>>
>> The query above that fails searches for the value -1. If I search for
>> values 1, 2 or 3, there is no issue at all, works fine.
>>
>> The table/index statistics are recently gathered - gathered number of
>> rows fit exactly:
>>
>> SQL> select num_rows
>> 2 from user_tables
>> 3 where table_name = 'SPLITDELIVERY';
>> NUM_ROWS
>> ----------
>> 350058
>>
>>
>> And column histogram also fit exactly the current values:
>>
>> SQL> select endpoint_value, endpoint_number, endpoint_number -
>> lag(endpoint_number) over (order by endpoint_number) as num
>> 2 from user_histograms
>> 3 where table_name = 'SPLITDELIVERY'
>> 4 and column_name = 'DELPACKOUTLOC'
>> 5 order by endpoint_number;
>> ENDPOINT_VALUE ENDPOINT_NUMBER NUM
>> -------------- --------------- ----------
>> -1 343251
>> 1 343668 417
>> 2 344193 525
>> 3 350058 5865
>>
>>
>> There's an index on the column and stats are current here as well:
>>
>> SQL> select blevel, leaf_blocks, distinct_keys, avg_leaf_blocks_per_key,
>> avg_data_blocks_per_key, clustering_factor, num_rows, sample_size
>> 2 from user_indexes
>> 3 where table_name = 'SPLITDELIVERY'
>> 4 and index_name = 'SPLITDELIVERY_IND01';
>> BLEVEL LEAF_BLOCKS DISTINCT_KEYS AVG_LEAF_BLOCKS_PER_KEY
>> AVG_DATA_BLOCKS_PER_KEY CLUSTERING_FACTOR NUM_ROWS SAMPLE_SIZE
>> ---------- ----------- ------------- -----------------------
>> ----------------------- ----------------- ---------- -----------
>> 2 864 4 216
>> 3393 13573 350058 350058
>>
>>
>>
>> I noticed it worked by adding AND ROWNUM <= xxx, so I tried different
>> values and found that 343250 (one less than the actual row count) worked
>> fine:
>>
>> SQL> set autotrace traceonly
>> SQL> select sd.iddelivery
>> 2 from splitdelivery sd
>> 3 where sd.delpackoutloc = -1
>> 4 and rownum <= 343250;
>> 343250 rows selected.
>>
>> Execution Plan
>> ----------------------------------------------------------
>> Plan hash value: 1924021054
>>
>> ------------------------------------------------------------------------------------------------------------
>> | Id | Operation | Name | Rows
>> | Bytes | Cost (%CPU)| Time |
>>
>> ------------------------------------------------------------------------------------------------------------
>> | 0 | SELECT STATEMENT | |
>> 343K| 3352K| 14182 (1)| 00:00:01 |
>> |* 1 | COUNT STOPKEY | |
>> | | | |
>> | 2 | TABLE ACCESS BY INDEX ROWID BATCHED| SPLITDELIVERY |
>> 343K| 3352K| 14182 (1)| 00:00:01 |
>> |* 3 | INDEX RANGE SCAN | SPLITDELIVERY_IND01 |
>> | | 852 (1)| 00:00:01 |
>>
>> ------------------------------------------------------------------------------------------------------------
>> Predicate Information (identified by operation id):
>> ---------------------------------------------------
>> 1 - filter(ROWNUM<=343250)
>> 3 - access("SD"."DELPACKOUTLOC"=(-1))
>>
>> Statistics
>> ----------------------------------------------------------
>> 0 recursive calls
>> 0 db block gets
>> 56495 consistent gets
>> 0 physical reads
>> 0 redo size
>> 4592104 bytes sent via SQL*Net to client
>> 251962 bytes received via SQL*Net from client
>> 22885 SQL*Net roundtrips to/from client
>> 0 sorts (memory)
>> 0 sorts (disk)
>> 343250 rows processed
>>
>>
>>
>> That worked fine, though I find it weird that it chooses an INDEX RANGE
>> SCAN + TABLE ACCESS BY INDEX when it knows that it is going to retrieve 98%
>> of the rows? A full table scan would use fewer gets as seen in the
>> autotrace above?
>>
>> Anyway, ORA-03113 appears when I add 1 to 343250 making it 34325*1*
>> (which is the exact number of rows having the value -1, which the optimizer
>> knows from the histogram):
>>
>> SQL> select sd.iddelivery
>> 2 from splitdelivery sd
>> 3 where sd.delpackoutloc = -1
>> 4 and rownum <= 343251;
>> select sd.iddelivery
>> *
>> ERROR at line 1:
>> ORA-03113: end-of-file on communication channel
>> Process ID: 11164
>> Session ID: 72 Serial number: 37013
>>
>>
>>
>> Same for just calling EXPLAIN PLAN - it works for 343250:
>>
>> SQL> explain plan for
>> 2 select sd.iddelivery
>> 3 from splitdelivery sd
>> 4 where sd.delpackoutloc = -1
>> 5 and rownum <= 343250;
>> Explained.
>>
>> SQL> select * from table(dbms_xplan.display);
>> PLAN_TABLE_OUTPUT
>>
>> ----------------------------------------------------------------------------------------------------------------------------------------------------------------
>> Plan hash value: 1924021054
>>
>> ------------------------------------------------------------------------------------------------------------
>> | Id | Operation | Name | Rows
>> | Bytes | Cost (%CPU)| Time |
>>
>> ------------------------------------------------------------------------------------------------------------
>> | 0 | SELECT STATEMENT | |
>> 343K| 3352K| 14182 (1)| 00:00:01 |
>> |* 1 | COUNT STOPKEY | |
>> | | | |
>> | 2 | TABLE ACCESS BY INDEX ROWID BATCHED| SPLITDELIVERY |
>> 343K| 3352K| 14182 (1)| 00:00:01 |
>> |* 3 | INDEX RANGE SCAN | SPLITDELIVERY_IND01 |
>> | | 852 (1)| 00:00:01 |
>>
>> ------------------------------------------------------------------------------------------------------------
>> Predicate Information (identified by operation id):
>> ---------------------------------------------------
>> 1 - filter(ROWNUM<=343250)
>> 3 - access("SD"."DELPACKOUTLOC"=(-1))
>> 16 rows selected.
>>
>>
>>
>> But it fails for 343251:
>>
>> SQL> explain plan for
>> 2 select sd.iddelivery
>> 3 from splitdelivery sd
>> 4 where sd.delpackoutloc = -1
>> 5 and rownum <= 343251;
>> explain plan for
>> *
>> ERROR at line 1:
>> ORA-03113: end-of-file on communication channel
>> Process ID: 10888
>> Session ID: 457 Serial number: 32869
>>
>>
>>
>> At the moment I have no access to trace files or alert log on this
>> server. Might get it after the weekend.
>> Also it is a development server, nothing urgent to solve. I'm only diving
>> a bit deeper for curiosity as well as check if this potentially could
>> happen in production database as well.
>>
>> It'll be easier if/when I get trace access, but do anyone have an idea
>> about what might be happening here?
>>
>>
>> Thanks in advance.
>>
>> Cheerio
>> /Kim
>>
>>
>> Regards
>>
>>
>> Kim Berg Hansen
>> Senior Consultant at Trivadis
>> Oracle ACE Director
>>
>> Author of Practical Oracle SQL
>> <https://www.apress.com/gp/book/9781484256169>
>> http://www.kibeha.dk
>> kibeha_at_kibeha.dk
>> _at_kibeha <http://twitter.com/kibeha>
>>
>>
-- http://www.freelists.org/webpage/oracle-lReceived on Thu Mar 25 2021 - 15:30:23 CET