Mohamed Houri’s Oracle Notes

May 16, 2020

SQL*Net break/reset to client

Filed under: Oracle — hourim @ 6:10 pm

This is a draft I wrote in 2015. I don’t know why I have not published it by that time? probably I was looking for something to add in this context. Anyway, I decided to give it a rebirth right now  after almost 5 years of dormant time.

A SQL*Net break/reset to client wait event was popping out at a dramatic rate so that the client application ASH data was abnormally flushed out from memory. It was then vital to find what is causing this wait event to show up at this high rate. This article aims to explain the steps I have followed trying to figure out the sql_id at the origin of this wait event.

The first article, dealing with SQL*Net break/reset to client error, that pops up when you Google for it, is this one by Tanel Poder.  It explains clearly what this event represents and gives a reproducible example.  In the real life case I’ve faced  ASH was showing this:

SQL> select event, count(1)
    from gv$active_session_history
    where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                      and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
    group by event
    order by 2 desc;

EVENT                                                              COUNT(1)
---------------------------------------------------------------- ----------
SQL*Net break/reset to client                                        164205
                                                                      10438
db file sequential read                                                2960
SQL*Net message from dblink                                            2499
direct path read                                                       1322
log file sync                                                           427
log file parallel write                                                 411
SQL*Net more data from client                                           183
control file sequential read                                             98
Backup: MML create a backup piece                                        82
…/…

Let’s try to find, naively, the sql_id behind this dramatic 164,205 SQL*Net break/reset to client recorded waits

SQL>  select sql_id, count(1)
      from gv$active_session_history
      where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                        and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
      and event = 'SQL*Net break/reset to client'
      group by sql_id
      order by 2 desc;

SQL_ID          COUNT(1)
------------- ----------
                  164205 

Damn!! It is a NULL sql_id

What about the sessions experimenting this wait event

SQL> select session_id, count(1)
     from gv$active_session_history
     where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                       and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
     and event = 'SQL*Net break/reset to client'
     group by session_id
     order by 2 desc;

SESSION_ID   COUNT(1)
---------- ----------
       151       3575
      2846       3575
       465       3575
      1791       3575
      2465       3575
       853       3575
      1216       3575
      1270       3575
      1397       3575
      2912       3575
        90       3575
       412       3575
      1155       3575
      1838       3575
      1957       3575
      2777       3575
      1038       3575 
      1290       3575
      1455       3575
      2648       3575
      2860       3575
      2988       3575
       344       3575
       533       3575
       337       3575
      2424       3575
      1028       3575
      1779       3575
      2047       3575
      2412       3575
       136       3575
       591       3575
       773       3575
       900       3575
       913       3575
      1335       3575
      1657       3575
      2101       3575
      2363       3575
       202       3575
      2226       3575
        16       3575
        79       3575
      1916       3575
      2362       3575
      1705       1429
       908       1181 

More than 45 sessions experimenting this wait event. Let’s then try to get the sql_id of one of those sessions:

SQL> select sql_id, count(1)
    from gv$active_session_history
    where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                      and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
    and session_id = 151
    group by sql_id
    order by 2 desc;

SQL_ID          COUNT(1)
------------- ----------
                    3515 

Damn!! It is a NULL sql_id again.

Let’s now get the list of wait events the above session (151) was experimenting


SQL> select event, count(1)
     from gv$active_session_history
     where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                       and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
     and session_id = 151
     group by event
     order by 2 desc;

EVENT                            COUNT(1)
-------------------------------- -------
SQL*Net break/reset to client    3453

I am going around a vicious circle! Isn’t it?

What if I try, now, to join those particular sessions with v$process view to see, at least, what their process are accomplishing

SQL> with got_my_sid
    as(
       select
            session_id
          , count(1)
       from
           v$active_session_history
       where sample_time between to_date('10072015 11:00:00', 'ddmmyyyy hh24:mi:ss')
                         and     to_date('10072015 12:00:00', 'ddmmyyyy hh24:mi:ss')
      and event = 'SQL*Net break/reset to client'
      group by session_id
      )
   select
          p.username
         ,p.tracefile
         ,p.pga_used_mem
         ,p.pga_alloc_mem
    from
         v$process p
        ,v$session s
   where
         p.addr=s.paddr
    and exists (select null
               from got_my_sid a
               where s.sid = a.session_id);

USERNAME     TRACEFILE                                                                        PGA_USED_MEM PGA_ALLOC_MEM
------------ -------------------------------------------------------------------------------- ------------ -------------
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_116986.trc               44210323      46756230
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58127.trc                22468107      26308998
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58151.trc                51969971      56979846
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_69733.trc                42309691      45969798
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_69747.trc               103456803     115241350
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_69759.trc                 5183995       8810886
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58169.trc               122509563     126316934
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_94674.trc                 4810835      10711430
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_77524.trc                 4867723      10711430
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_77727.trc                48775851      57307526
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_77837.trc                 5697963       6517126
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_77962.trc                 4926947       7500166
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76614.trc               142568163     170160518
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76622.trc                10887843      12743046
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76634.trc                13751019      16675206
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76662.trc                17715523      18772358
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76670.trc                 4852883       7631238
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76676.trc                 5040315       6517126
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76734.trc                20039043      22114694
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76741.trc               110836667     127889798
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76749.trc                29546107      33255814
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76792.trc                 5336891       6975878
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11735.trc               141510371     167014790
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11741.trc                50941459      54882694
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11759.trc                13313739      15102342
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11772.trc                45210595      56390022
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11784.trc                16259099      18641286
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58289.trc                86902963     103838086
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_76815.trc                10668723      13005190
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11808.trc                13386251      15036806
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11844.trc                64225827      68252038
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11856.trc                50413091      54620550
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117006.trc               38196715      46952838
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117012.trc               27739851      30241158
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11862.trc               114249963     120418694
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11868.trc                90697083      95973766
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117042.trc               78140859      79982982
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11892.trc               188237195     226324870
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117078.trc              141404363     171209094
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117092.trc              142334875     166883718
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117098.trc               44335187      46887302
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_117112.trc               98170435     117469574
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11898.trc                 5171715       7696774
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_11904.trc                 4970579       5534086
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_95446.trc               142625387     164524422
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58609.trc                 5278147       7041414
oracle       /oracle/base/diag/rdbms/pwrwdp1/CLSWPROD1/trace/CLSWPROD1_ora_58689.trc                 5316451       6910342 

Finally I have something to get my teeth into.

It looks like sessions that were suffering from the SQL*Net break/reset to client wait event have generated several trace files. And, hopefully, one of those trace files shows the following error:

ORA-04030: out of process memory when trying to allocate 824504 bytes (pga heap,kco buffer)
ORA-04030: out of process memory when trying to allocate 3032 bytes (kkoutlCreatePh,kkotrb : kkoabr) 

The same trace file shows, as well, the SQL Statement which has originated this very high number of  SQL*Net break/reset to client wait event

dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
----- Current SQL Statement for this session (sql_id=d6jgtxn25741y) -----
select * from ( select alias.cols as skey87_0_, alias.skey as skey81_1_ 

This is how I drilled down to the root cause of this wait event.

 

 

2 Comments »

  1. Mohamed, your posts are always absolutely fun to read. Get to learn something new every time.

    Comment by rajiviyer — May 23, 2020 @ 7:14 am | Reply

  2. Rajiv,

    Thanks for your comment. You’re welcome

    Best regards

    Comment by hourim — May 23, 2020 @ 8:05 am | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Create a free website or blog at WordPress.com.

Tony's Oracle Tips

Tony Hasler's light hearted approach to learning about Oracle

Richard Foote's Oracle Blog

Focusing Specifically On Oracle Indexes, Database Administration and Some Great Music

Hatem Mahmoud Oracle's blog

Just another Oracle blog : Database topics and techniques

Mohamed Houri’s Oracle Notes

Qui se conçoit bien s’énonce clairement

Oracle Diagnostician

Performance troubleshooting as exact science

Raheel's Blog

Things I have learnt as Oracle DBA

Coskan's Approach to Oracle

What I learned about Oracle

So Many Oracle Manuals, So Little Time

“Books to the ceiling, Books to the sky, My pile of books is a mile high. How I love them! How I need them! I'll have a long beard by the time I read them”—Lobel, Arnold. Whiskers and Rhymes. William Morrow & Co, 1988.

Carlos Sierra's Tools and Tips

Tools and Tips for Oracle Performance and SQL Tuning

Oracle Scratchpad

Just another Oracle weblog

OraStory

Dominic Brooks on Oracle Performance, Tuning, Data Quality & Sensible Design ... (Now with added Sets Appeal)

%d bloggers like this: