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

  • From: Andy Sayer <andysayer@xxxxxxxxx>
  • To: kibeha@xxxxxxxxx
  • Date: Thu, 25 Mar 2021 14:30:23 +0000

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,
Andrew

On Thu, 25 Mar 2021 at 14:24, Kim Berg Hansen <kibeha@xxxxxxxxx> wrote:

Hmmm... If I query for two values, I get again that it works for one less
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@xxxxxxxxx
@kibeha <http://twitter.com/kibeha>



On Thu, Mar 25, 2021 at 3:12 PM Kim Berg Hansen <kibeha@xxxxxxxxx> 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@xxxxxxxxx
@kibeha <http://twitter.com/kibeha>


Other related posts: