Skip to Main Content
  • Questions
  • What is the meaning of SQL*Net message from client

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Jaklin.

Asked: August 07, 2009 - 3:21 am UTC

Last updated: July 30, 2012 - 7:55 am UTC

Version: 10.2.0.4

Viewed 50K+ times! This question is

You Asked

Can you please help interpreting this output?

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 160878 26.95 25.80 4 18 30 0
Execute 160878 130.97 126.94 355 31756 163997 17532
Fetch 139738 68.34 66.24 9 269118 23464 119624
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 461494 226.26 218.98 368 300892 187491 137156

Misses in library cache during parse: 40
Misses in library cache during execute: 33

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 692413 0.00 1.20
SQL*Net message from client 692412 0.75 1183.87
db file sequential read 361 0.02 0.65
log file sync 5920 0.62 9.09


Does high SQL*Net message from client means network latency?

Thanks in advance.

and we said...

In general, sqlnet message from client is the "idle wait event experienced by the server while waiting for the client to tell it to do something".

http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:1154234872764#1639863671441

for example - say the client

o at 12:00:00.0000 submits "select * from dual"
o spends 30 seconds pondering the results
o at 12:00:30.0000 submits "select sysdate from dual"

you will see some 30 seconds of "sql net message from client" wait.

If you have an application that should CONSTANTLY be doing work in the database (eg: a batch process) and you see high "sqlnet message from client"- that is time spent in the client outside the database - and it could be a problem in that case (the client is spending a lot of time doing something OUTSIDE of the database)

So, if a developer comes to you and says "database is slow, my program takes 20-25 minutes to run, database is very slow" and you develop a tkprof report that looks like the above, you can say to them:

Look - the database spent 1,183 seconds (about 20 minutes) waiting to be told to do something by you. When you did tell us to do stuff, we finished it in about 218.98 seconds (the time spent doing sql). So, we spent 4 minutes doing work in the database - and you spent 20 minutes doing "something". Now, even if we made the database infinitely fast - you will still take 20 minutes to run. Since we cannot make the database infinitely fast - I suggest you figure out where you are spending your 20 minutes and I'll look in the tkprof to see I I can make that less than 4 minutes any smaller.



call    count    cpu     elapsed    disk   query  current    rows
------- ------ -------- ---------- ----- ------- -------- ----------
Parse   160878   26.95    25.80      4       18       30         0
Execute 160878  130.97   126.94    355    31756   163997     17532
Fetch   139738   68.34    66.24      9   269118    23464    119624
------- ------ -------- ---------- ----- ------- -------- ----------
total   461494  226.26   218.98    368   300892   187491    137156

Misses in library cache during parse: 40
Misses in library cache during execute: 33

Elapsed times include waiting on following events:
Event waited on                  Times  Max. Wait Total Waited
----------------------------------------  Waited ---------- ------------
SQL*Net message to client            692413    0.00      1.20
SQL*Net message from client          692412    0.75   1183.87
db file sequential read                 361    0.02      0.65
log file sync                          5920    0.62      9.09

 



so, what can we say about that:

a) your parse = execute. Since I doubt you have 160,878 UNIQUE sql statements, your developers need to learn that you do not need to parse every time you execute - they should parse ONCE and execute many times. 10% of your runtime was spent parsing sql - not executing it. This is a huge scalability inhibitor and work that needs not be done.

A sql statement needs to be parsed at least once by a program to execute it. A sql statement needs to be parsed on MOST once by a program to execute it as many times as it likes

b) Most of your parses are soft parses (misses in library cache during parse: 40 - only 40 hard parses). Gives strength to comments in (a). You have few unique statements - but you parse them over and over.

c) your shared pool might be small - maybe. something to investigate. 33 times during your execution, a statement that had been in the shared pool was not there anymore. We did an implicit hard parse - that could be caused by other things (ddl, statistics, another program flooding the shared pool with tons of literal sql...)

d) you run tons of tiny sql - I based that on the number of IO's (query+current) divided by number of executions. Perhaps you have the classic slow by slow program that would benefit greatly from set based operations

e) you have no significant waits, you waited 5,920 times for a commit to finish (the log file sync) so each commit caused you to wait 0.0015 seconds - not bad.

f) most of your time was spent in the client - you spent 1,183 seconds waiting while this client was connected to the database to be told to do something. If the client is an interactive application - that might well be OK (see the above link to sqlplus example). That would be end user think time and end users are slow. If this is a batch process - you probably have a problem with the client - it is using 5 units of time for every 1 unit of database time.

Rating

  (18 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Jaklin Ekdawi, August 07, 2009 - 5:11 pm UTC

Thank you Tom, great response as usual.

Can you please explain whatdo you mean by "set based operations".

The developers said that they run the same program on their PC ¿windows 2003 SP2¿ which is running Oracle DB Enterprise Edition 10.2.0.1 and the program in less than 5 minutes, however in the test environment (Oracle Standard Edition 10.2.0.4 on Solaris SPARC10 and the App on windows 2003 SP2 server with F/.W in between ) it took ~25 minutes.

Can you please advise your recommendation in investigating this issue?

Tom Kyte
August 07, 2009 - 5:18 pm UTC

...
Can you please advise your recommendation in investigating this issue?
......

it is exactly what I said - developers say "this is slow, must be the database"

but your trace shows..... 20 minutes spent waiting for the developers program - THEIR CODE - to give us work to do. 5 minutes spent doing work.

Ask developers to instrument their code in the way Oracle has already done so - so they can figure out where THEY are spending THEIR time. Unless of course they are using java and our app server, then they are already instrumented and you would use enterprise manager to see where they spend their time.



By set based operations - I see them doing hundreds of thousands of tiny sqls - they are processing single rows at a time.

Instead of coding logic that looks like:

for x in (select * from t1)
loop
insert into t2 values ( x );
end loop

they should use set based processing and just insert into t2 select * from t1 - no code.

I think they have written a ton of procedural code - bad.



But in any case - the bottleneck is.....

their program, not your database.

Jaklin Ekdawi, August 07, 2009 - 6:19 pm UTC

I totally agree with you that it is not a database issue.

Am I right to say it is a network issue as the developers confirmed that the same code is running in 5 minutes in their dev env? If so how can I confirm that?

Many thanks



Tom Kyte
August 07, 2009 - 6:45 pm UTC

almost certainly - it is not a network issue.

do they have THEIR application instrumented.
can they tell you where THEY are spending THEIR time.

these are rhetorical questions of course because of course the answer is "of course not".

get the tkprof from the environment that runs fast
compare it to the tkprof from the environment that does not

see if they are doing even remotely similar things.

(eg: two different databases, two different data sets I presume - meaning "you cannot compare them")

Jaklin Ekdawi, August 07, 2009 - 7:11 pm UTC

They are exact data sets, different databases with the same init parameters, different Oracle editions and Oracle patch level. (Different O/S, different network architecture)

I¿ll get the tkprof from them and do the comparison.

Thank you

Tom Kyte
August 11, 2009 - 12:17 pm UTC

and - you have shown that the database is performing the same on both - however, their application spends 20 minutes doing something in one environment and not so in the other.

Jaklin Ekdawi, August 11, 2009 - 3:53 pm UTC

Thanks Tom for the following up. I'm still waiting for their tkprof.

Meanwhile, I executed the following basic SQL statements as a SQL batch file from the DB server and the client

alter session set events '10046 trace name context forever, level 12';
select sysdate from dual;
select * from objadm.users;
select sysdate from dual;
exit

I noticed a big difference in the SQL*Net message from client "Total Wait"

- The out of tkprof when executing the SQL batch from the server

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call countcpu elapseddiskquery currentrows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 49 0.02 0.01 0 67 0 660
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 55 0.02 0.01 0 67 0 660

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 50 0.00 0.00
SQL*Net message from client 50 0.01 0.62
SQL*Net more data to client 1 0.00 0.00

-The out of tkprof when executing the SQL batch from the client

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 49 0.02 0.01 0 67 0 660
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 55 0.02 0.01 0 67 0 660

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 50 0.00 0.00
SQL*Net message from client 50 0.19 5.56

Does that mean it is a network issue?
Tom Kyte
August 13, 2009 - 9:12 am UTC

could be - do something infinitely more sizeable - with

set autotrace traceonly
select ...
set autotrace off

so you are not timing how long it takes sqlplus to print stuff - and make sure you are running from the SAME client.

Jaklin Ekdawi, August 13, 2009 - 3:34 pm UTC

I executed the following on the same client and the server

set autotrace traceonly;
select * from objadm.users;
set autotrace off;


- From the same client
Execution Plan
----------------------------------------------------------
Plan hash value: 4086905487

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 658 | 92778 | 7 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| USERS | 658 | 92778 | 7 (0)| 00:00:01 |
---------------------------------------------------------------------------


Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
67 consistent gets
0 physical reads
0 redo size
75066 bytes sent via SQL*Net to client
548 bytes received via SQL*Net from client
45 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
658 rows processed

- From the server
Execution Plan
----------------------------------------------------------
Plan hash value: 4086905487

---------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 658 | 92778 | 7 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| USERS | 658 | 92778 | 7 (0)| 00:00:01 |
---------------------------------------------------------------------------


Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
67 consistent gets
0 physical reads
0 redo size
82432 bytes sent via SQL*Net to client
965 bytes received via SQL*Net from client
45 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
658 rows processed


Can you please advise why the bytes received via SQL*Net from client (when run on the server) is bigger than the bytes received via SQL*Net from client (when run on the client).

Note: the server is Solaris SPARC 64 bit and the client is Windows 2003 32 bit.

Thank you

Tom Kyte
August 24, 2009 - 7:13 am UTC

dump packets if you are curious about something this small.

I would guess "different clients sending slightly different information when run from different platforms"

Jaklin Ekdawi, August 24, 2009 - 3:01 pm UTC

The output of tkprof when the developers run the same program on their PC shows a big difference in SQL*Net message from client.

The SQL*Net message from client from my tkprof is almost 4-5 times theirs.

Could you please advise what might be the cause of that?

Thanks



Tom Kyte
August 25, 2009 - 9:53 am UTC

that could mean.....

your machine is slow (their desktop cpus blow your server cpus away) as much as anything.

since their code is not instrumented, try SQL*Net trace (with TIMESTAMPS) can be helpful to check out the time in the network between the client and server. See Note 16658.1 - see if you experience radically different response times on the various machines.

Jaklin Ekdawi, August 25, 2009 - 2:11 pm UTC

My Database server is T5120 with 4 core 1.2 GHz Ultra SPARC T2 processor (from O/S it is seen as 32 CPU * 1.2 GHz).

Their PC has 2 CPU * 4 Ghz.

Based on the above, How come their PC is more powerful than my server?

The ASH Report for the execution period of the program shows ¿CPU + Wait for CPU¿ is the top event, however, tkprof shows ¿SQL*Net from client¿ is the top event waited on.

Top User Events
Event Event Class % Activity Avg Active Sessions
CPU + Wait for CPU CPU 81.66 0.14
log file sync Commit 5.92 0.01
db file scattered read User I/O 2.37 0.00


Can you please explain why there is a difference between tkprof and ASH report?

Thank You
Tom Kyte
August 25, 2009 - 8:41 pm UTC

I only care about a single cpu, your client program is not using more than one.

I often downloaded stuff from my big bad sparc to my desktop because my desktop was many times faster than the sparc.


look further down in the ash report - sqlnet message from client is an idle wait, we tend to ignore it as it is the time we spent WAITING FOR THE CLIENT.

Their pc looks a lot faster than your server since you are only using a single cpu - your client is not multi-process. It only uses a single cpu.

Jaklin Ekdawi, August 25, 2009 - 2:36 pm UTC

Sorry, I forgot to say that during the execution time the cpu on the server was 98-99% idle based on (using top and sar).

Thanks
Tom Kyte
August 25, 2009 - 8:42 pm UTC

I agree, because you could not use 31 out of 32 cpus, I would expect it to be almost idle.

97% idle would mean a single cpu was 100% used. So, it sounds like you were using almost 100% of that single cpu you had access to.

and it isn't as fast as their pc.

Jaklin Ekdawi, August 25, 2009 - 10:20 pm UTC

The tkprof from the developer's PC is below

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 122 0.39 0.68 0 403 0 0
Execute 122 0.00 0.00 0 0 0 0
Fetch 396 0.09 0.11 0 25354 0 274
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 640 0.48 0.80 0 25757 0 274

Misses in library cache during parse: 122

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 763 0.00 0.00
SQL*Net message from client 763 14.71 312.91
SQL*Net more data to client 122 0.00 0.00


The tkprof for the running the same process on Solaris DB Server

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 124 0.06 0.03 0 0 0 0
Execute 124 0.04 0.01 0 0 0 0
Fetch 400 0.07 0.10 0 802 0 276
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 648 0.17 0.15 0 802 0 276

Misses in library cache during parse: 1

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 774 0.00 0.00
SQL*Net message from client 774 43.65 964.23

- On Solaris DB server, the CPU is 0.17, however, "SQL*Net message from client" is 964.23.
- On the developer¿s PC, the CPU is 0.48, however, "SQL*Net message from client" is 312.91.

Based on that, how I can approve it is CPU issue?


Tom Kyte
August 26, 2009 - 7:01 pm UTC

how about this.

have the developers write something that mimics what they do without the database in it. Same sorts of loops and processing they do in the code in the client.

run it on their machine
run it on yours

You'll find your big bad server has cpu's that are extremely slow compared to the desktop machine.

Hence - the time spent waiting for sqlnet message from client is - time spent in YOUR client on YOUR server processing the data returned from the database.



saying "the cpu 0.17 on one and 0.48 on the other" is meaningless, they are completely different cpus with completely different performance characteristics.

And that you have 32 of them - no use to you, you use one..

It looks like your server is about 2-3 times slower then their test machine.

SQL*Net Message from client may not be an issue from the app

Thierry B, May 28, 2010 - 8:13 am UTC

Hi,
I just read your post as I experienced the exact same problem. I found something that fixed this problem for me, my sqlnet.ora contained that line after an oracle upgrade:
TRACE_LEVEL_CLIENT=16

I don't know how it came there. But it was the cause of my problem (too long idle time). I simply removed it and no more wait events.

I hope it can be of any help for anyone.

Tom Kyte
May 28, 2010 - 8:34 am UTC

that is a client side issue though, isn't it. It is an application side issue, not a database side issue.

A reader, April 15, 2011 - 10:58 am UTC


active wait on sql*net message from client

Michael, March 12, 2012 - 3:59 am UTC

hi tom,

i've an increasing amount of "active" sessions waiting on "sql*net message from client":

v$session.status = 'ACTIVE'
v$session.event = 'SQL*Net message from client'
v$session.seconds_in_wait = ever increasing
v$session.seq# = remains the same

i read here ( http://www.freelists.org/post/oracle-l/How-to-make-a-session-active-with-wait-event-of-sqlnet-message-FROM-client,5 ) that this message is due to inconsistent reads on the data dictionary.

so, i think the message should be "active" + "sql*net message to client" meaning the database tries to send something TO the client but the client didn't react anymore.

is my understanding correct? how can this happen?

Tom Kyte
March 12, 2012 - 8:03 am UTC

can you describe for us what these sessions are doing.

active wait on sql*net message from client

Michael, March 13, 2012 - 9:36 am UTC

the query does nothing special. a simple delete statement:
"DELETE FROM CMS_InfoObjects6 WHERE ObjectID IN (1397826)"



[508] sys@QL032> select sid, status, event, seconds_in_wait from v$session where sid = 510;

       SID STATUS   EVENT                         SECONDS_IN_WAIT
---------- -------- ----------------------------- ---------------
       510 ACTIVE   SQL*Net message from client             38818



an ASH report for this session over the last hour shows:
ASH Report For QL032/QL032
(1 Report Target Specified)

DB Name         DB Id    Instance     Inst Num Release     RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
QL032          387875684 QL032               1 11.1.0.7.0  NO  ux1026

CPUs           SGA Size       Buffer Cache        Shared Pool    ASH Buffer Size
---- ------------------ ------------------ ------------------ ------------------
   4      1,019M (100%)       160M (15.7%)       639M (62.6%)        8.0M (0.8%)


          Analysis Begin Time:   13-Mar-12 14:26:54
            Analysis End Time:   13-Mar-12 15:26:55
                 Elapsed Time:        60.0 (mins)
            Begin Data Source:   V$ACTIVE_SESSION_HISTORY
              End Data Source:   V$ACTIVE_SESSION_HISTORY
                 Sample Count:       3,595
      Average Active Sessions:        1.00
  Avg. Active Session per CPU:        0.25
                Report Target: SESSION_ID = 510
              Target Activity: 32.8% of total database activity
...
...
...

Activity Over Time              DB/Inst: QL032/QL032  (Mar 13 14:26 to 15:26)
-> Analysis period is divided into smaller time slots
-> Top 3 events are reported in each of those slots
-> 'Slot Count' shows the number of ASH samples in that slot
-> 'Event Count' shows the number of ASH samples waiting for
   that event in that slot
-> '% Event' is 'Event Count' over all ASH samples in the analysis period

                         Slot                                   Event
Slot Time (Duration)    Count Event                             Count % Event
-------------------- -------- ------------------------------ -------- -------
14:26:54   (3.1 min)      185 CPU + Wait for CPU                  185    5.15
14:30:00   (6.0 min)      361 CPU + Wait for CPU                  361   10.04
14:36:00   (6.0 min)      358 CPU + Wait for CPU                  358    9.96
14:42:00   (6.0 min)      360 CPU + Wait for CPU                  360   10.01
14:48:00   (6.0 min)      360 CPU + Wait for CPU                  360   10.01
14:54:00   (6.0 min)      359 CPU + Wait for CPU                  359    9.99
15:00:00   (6.0 min)      359 CPU + Wait for CPU                  359    9.99
15:06:00   (6.0 min)      361 CPU + Wait for CPU                  361   10.04
15:12:00   (6.0 min)      358 CPU + Wait for CPU                  358    9.96
15:18:00   (6.0 min)      360 CPU + Wait for CPU                  360   10.01
15:24:00   (2.9 min)      174 CPU + Wait for CPU                  174    4.84
          -------------------------------------------------------------

End of Report

Tom Kyte
March 13, 2012 - 10:25 am UTC

it doesn't look like it was waiting for anything - it looks like it was busy (on cpu) the entire time.

Is it expected for this simple delete to take this long? how much work is it performing? I'm suspecting a messed up v$session entry right now. Or is the delete sort of "hung"?

active wait on sql*net message from client

Michael, March 14, 2012 - 8:31 am UTC

no, it should be fast. i did a few "awrsqrpt.sql" reports for this type of statement and got always the same picture (see below).


i'm so confused about this 10 hours active waiting for "sql*net message from client". what is it? is the session really on cpu while waiting?


WORKLOAD REPOSITORY SQL Report
...
...
Elapsed
SQL Id Time (ms)
------------- ----------
0cn08hm9jf0t0 43
Module: boe_cmsd@ux6140 (TNS V1-V3)
DELETE FROM CMS_InfoObjects6 WHERE ObjectID IN (185654)
...
...

Plan 1(PHV: 3926830145)
-----------------------

Plan Statistics DB/Inst: QL032/QL032 Snaps: 5616-5822
-> % Total DB Time is the Elapsed Time of the SQL statement divided
into the Total Database Time multiplied by 100

Stat Name Statement Per Execution % Snap
---------------------------------------- ---------- -------------- -------
Elapsed Time (ms) 43 43.0 0.0
CPU Time (ms) 3 3.0 0.0
Executions 1 N/A N/A
Buffer Gets 52 52.0 0.0
Disk Reads 3 3.0 0.0
Parse Calls 1 1.0 0.0
Rows 1 1.0 N/A
User I/O Wait Time (ms) 29 N/A N/A
Cluster Wait Time (ms) 0 N/A N/A
Application Wait Time (ms) 0 N/A N/A
Concurrency Wait Time (ms) 0 N/A N/A
Invalidations 0 N/A N/A
Version Count 1 N/A N/A
Sharable Mem(KB) 49 N/A N/A
-------------------------------------------------------------

Execution Plan
---------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | | | 1 (100)| |
| 1 | DELETE | CMS_INFOOBJECTS6 | | | | |
| 2 | INDEX UNIQUE SCAN| OBJECTID_I6 | 1 | 228 | 1 (0)| 00:00:01 |
---------------------------------------------------------------------------------------

Tom Kyte
March 14, 2012 - 3:15 pm UTC

ok, let's backup here.

Is the session really active - or is that column apparently wrong?
Is the delete really consuming cpu (a quick glance at the system would verify that)
Is the delete still running?


If the delete is supposed to be really fast - single row via an index - and has been active for 10 hours (and is not blocked - that would show up), then something is seriously wrong.


So, can you just tell us what is going on - was the delete "hung" for 10 hours - or did it complete fast - can you fill us in on what was actually happening?

update - active wait on sql*net message from client

Michael, March 14, 2012 - 9:10 am UTC

short update


i also got some sessions with "cursor: pin s wait on x" now. 


i read metalink note "How to Determine the Blocking Session for Event: 'cursor: pin S wait on X' [ID 786507.1]" and found my blocking sessions to be the ones with "sql*net message from client"!?


[522] sys@PL032> select sid, status, event, seconds_in_wait from v$session where event like 'SQL*Net%' and status = 'ACTIVE';

       SID STATUS   EVENT                                                            SECONDS_IN_WAIT
---------- -------- ---------------------------------------------------------------- ---------------
       488 ACTIVE   SQL*Net message from client                                               220616
       517 ACTIVE   SQL*Net message to client                                                7113983
       521 ACTIVE   SQL*Net message from client                                               225417
       522 ACTIVE   SQL*Net message to client                                                      0

[522] sys@PL032> select sid, status, event, seconds_in_wait from v$session where event like 'cursor: pin S wait on X';

       SID STATUS   EVENT                                                            SECONDS_IN_WAIT
---------- -------- ---------------------------------------------------------------- ---------------
       489 ACTIVE   cursor: pin S wait on X                                                        0
       501 ACTIVE   cursor: pin S wait on X                                                        0
       526 ACTIVE   cursor: pin S wait on X                                                        0

[522] sys@PL032> -
> select sid, p2raw,to_number(substr(to_char(rawtohex(p2raw)),1,8),'XXXXXXXX') sid
from v$session
where event = 'cursor: pin S wait on X';

       SID P2RAW                   SID
---------- ---------------- ----------
       489 0000020900000000        521
       501 000001E800000000        488
       526 0000020900000000        521

Tom Kyte
March 14, 2012 - 3:16 pm UTC

I'll have to ask you to work with support on this one, it isn't supposed to be going like this. Sounds like something is "stuck" and it shouldn't be.

SQL*Net message from client

vinod, July 19, 2012 - 2:37 am UTC

Hello Tom,
We have rhel os ,oracle 10g rel 2
18 GB RAM,8 GB SGA ,1.8 GB PGA target
maximum concurrent sessions about 400
some times application server experienced overload
but db side no issue observed,can load be there
due to any db issue ,is our sga,pga optimized
(based on reports i am generating everyday,pga hit will be
same upto 8 gb)
similar issue with me,i am observing from about 1 year
"SQL*Net message from client" on top
database run normal,cpu ,memory utilization also normal

Session wait....

EVENT STATE COUNT(*)
---------------------------------------------------------------- ------------------- ----------
SQL*Net message from client WAITING 286
rdbms ipc message WAITING 12
Streams AQ: qmn slave idle wait WAITING 1
Streams AQ: waiting for messages in the queue WAITING 1
jobq slave wait WAITING 1
wait for unread message on broadcast channel WAITING 1
pmon timer WAITING 1
Streams AQ: qmn coordinator idle wait WAITING 1
smon timer WAITING 1
Streams AQ: waiting for time management or cleanup tasks WAITING 1
SQL*Net message to client WAITED SHORT TIME 1


TOTAL_SGA FREE FREE_PER
---------- ---------- ----------
864 208.5 24.13

ESTPGATAR:241565696***PGATARFAC:.125***Status:ON***HITPER:23
ESTPGATAR:483131392***PGATARFAC:.25***Status:ON***HITPER:52
ESTPGATAR:966262784***PGATARFAC:.5***Status:ON***HITPER:53
ESTPGATAR:1449394176***PGATARFAC:.75***Status:ON***HITPER:53
ESTPGATAR:1932525568***PGATARFAC:1***Status:ON***HITPER:53
ESTPGATAR:2319030272***PGATARFAC:1.2***Status:ON***HITPER:53
ESTPGATAR:2705534976***PGATARFAC:1.4***Status:ON***HITPER:53
ESTPGATAR:3092040704***PGATARFAC:1.6***Status:ON***HITPER:53
ESTPGATAR:3478545408***PGATARFAC:1.8***Status:ON***HITPER:53
ESTPGATAR:3865051136***PGATARFAC:2***Status:ON***HITPER:53
ESTPGATAR:5797576704***PGATARFAC:3***Status:ON***HITPER:53
ESTPGATAR:7730102272***PGATARFAC:4***Status:ON***HITPER:53
ESTPGATAR:11595153408***PGATARFAC:6***Status:ON***HITPER:53
ESTPGATAR:15460204544***PGATARFAC:8***Status:ON***HITPER:53

Tom Kyte
July 19, 2012 - 10:00 am UTC

maximum concurrent sessions about 400


wow, cool you must have what - like 40 cpus, sweet.

if you don't, you have way too many connections.
http://www.youtube.com/watch?v=xNDnVOCdvQ0



sql*net message from client indicates that the database is patiently waiting for the client to tell it to do something.

we are WAITING patiently for work to asked of us, we are idle, we are just waiting.

The client is not asking us to do anything when you see this.


sounds like your problem lies solely in the middle tier.

SQL*net message ,sessions

vinod, July 20, 2012 - 7:20 am UTC

"maximum concurrent sessions about 400


wow, cool you must have what - like 40 cpus, sweet.

if you don't, you have way too many connections."

So do u mean 400 concurrent sessions is too much,but i was feeling its not significant,in my previous project it was more then 5000 (being finance instiute)
even i was thinking not issue at db side,problem lies in application architecture

Tom Kyte
July 30, 2012 - 7:55 am UTC

did you watch the video?

think about it - just use simple math here.

with 5,000 connections - what can happpen?

all 5,000 could try to become active.

what would happen if that occurred?

a nuclear meltdown of your server. period.


there is no reason to have thousands of connections (unless and until you have HUNDREDS/THOUSANDS of cpus)

SQL*Net message from client

vinod, July 25, 2012 - 9:23 am UTC

"maximum concurrent sessions about 400


wow, cool you must have what - like 40 cpus, sweet.

if you don't, you have way too many connections."

So do u mean 400 concurrent sessions is too much,but i was feeling its not significant,in my
previous project it was more then 5000 (being finance instiute)
even i was thinking not issue at db side,problem lies in application architecture



More to Explore

Performance

Get all the information about database performance in the Database Performance guide.