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

Thanks, Mohamed.

Interesting point about the DDL optimization and could easily have been relevant, except that it would not be relevant in 12.1 as you say. But nice to know about for sure 😉

Cheerio
/Kim

On Thu, Mar 25, 2021 at 3:56 PM Mohamed Houri <mohamed.houri_at_gmail.com> wrote:

>
>>> As Andy has already pointed it out you need to get the alert log trace
>>> file
>>>
>>>
>>>
>>> I was thinking that the column delpackoutloc has been added using the
>>> DDL optimization technique
>>>
>>>
>>>
>>> SQL> alter table add delpackoutloc number default -1 null;
>>>
>>>
>>>
>>> But this DDL optimization technique is only possible for a 12cR2
>>> database (where it has been extended to nullable columns) and you are using
>>> 12cR1. And even in the execution plan that works and which you have shown,
>>> I don't see any added NVL function in the predicate part
>>>
>>>
>>>
>>> I got the same error a couple of years ago when I was moving from 11gR2
>>> to 12cR2 which turned to be due to a DDL optimized column. The solution was
>>> drop/recreate the table. This was possible because the underlying table was
>>> not very big and not very critical
>>>
>>>
>>>
>>> Best regards
>>> Mohamed Houri
>>>
>>
>
>> oing 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_at_gmail.com> 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_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>
>>>>>
>>>>>
>
> --
>
> Houri Mohamed
>
> Oracle DBA-Developer-Performance & Tuning
>
> Visit My - Blog <http://www.hourim.wordpress.com/>
>
> Let's Connect - <http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*Linkedin
> Profile <http://fr.linkedin.com/pub/mohamed-houri/11/329/857/>*
>
> My Twitter <https://twitter.com/MohamedHouri> - MohamedHouri
> <https://twitter.com/MohamedHouri>
>
>

--
http://www.freelists.org/webpage/oracle-l