Re: Weird "ORA-03113: end-of-file on communication channel" during parse

This looks like the runtime engine failing either on rowsets or on batching (e.g. array processing and managing to fall off the end of the calculated array).

Have you tried adding the hint /*+ no_batch_table_access_by_rowid(_at_sel$1 sd_at_sel$1) */
Can you check a working index-access plan with format=>'projection' to see if it reports "rowsets" for the access, and disable the feature if it's in use.
(alter session set "_rowsets_enabled"=false;)

Regards
Jonathan Lewis

On Thu, 25 Mar 2021 at 14:13, 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-l