Oracle Session Tracing Part I

Author : James F. Koopmann

This is the first in a series to introduce some of the new tracing concepts and options within Oracle. This installment focuses on the new CLIENT_IDENTIFIER environment variable that can be assigned to sessions.

The goal of this series is to inform DBAs on how to track and trace connected sessions so that they can properly determine where sessions are experiencing performance problems. This article presents the very important concept of assigning a client identifier to a session. This client identifier will be used in future articles as this will be one way to initiate traces. This article first presents the issue of why we should use the client identifier and then how we can utilize it when looking at sessions as they are connected in real time.

To begin, we must first come to grips with the simple concept of the globalization of sessions within Oracle that occurs. The days of single dedicated server connections and one connection uniquely identifying a single user are long gone. Now many middle-tier applications make use of pooling mechanisms that hide the identity of a connected user or session that does not allow you or me to adequately track and trace effectively because of the reuse of session ids. This is where you need to start thinking of defining your own client identifier for the users that use your database systems. This is just what Oracle now has and through the use of a client identifier allows for you to either further segregate or consolidate sessions by assigning an identifier that describes the connection for a particular user or set of users.. For example, suppose you have a development environment where everyone logs in as a particular schema user and because of the connection mechanisms employed, users will reuse the same session id sometimes when they connect. Well, if you ever wanted to trace these sessions to determine who was consuming vast amounts of resources or was issuing particular SQL, you would be very hard pressed to run a trace and filter for that user since the high activity would not guarantee any one user was on a particular session id. This is where you could employ the use of a client identifier as Oracle now lets us trace and trace reports on a unique client identifier. To get this going all you need to do is invoke the DBMS_SESSION.SET_IDENTIFIER procedure when the session logs in. Figure 1 gives a very simplistic method through a logon trigger to set the client identifier. You can use anything to distinguish the session such as IP address, computer / host name, o/s user, or a predefined application name. I have taken use of the DBMS_CONTXT calls for user environment information.

Figure 1

Logon trigger to set client_identifier

CREATE OR REPLACE TRIGGER LOGON_TRIGGER

AFTER LOGON ON DATABASE

DECLARE

v_user_identifier varchar2(64);

BEGIN

SELECT SYS_CONTEXT('USERENV', 'OS_USER')

||':'||

SYS_CONTEXT('USERENV', 'IP_ADDRESS')

INTO v_user_identifier

FROM dual;

DBMS_SESSION.SET_IDENTIFIER(v_user_identifier);

END;

Now when we take a look at the V$SESSION view, we can see this CLIENT_IDENTIFIER set for various sessions. Listing 1 gives this type of output. Now if we had the same database user connect through some polling mechanism, if we set our client identifier properly, we have the potential to see a different client identifier. Also if we want to set the same client identifier for a group of users, we could do that also. There are also methods of setting the client identifier from within OCI and JDBC.

Listing 1

V$SESSION output

1 SELECT sid, client_identifier,

2 service_name, action, module

3* FROM V$SESSION

SID CLIENT_IDENTIFIER SERVICE_NAME ACTION MODULE

---------- -------------------- ------------- ------------ -----------

145 jkoopmann:127.0.0.1 k101 msqry32.exe

146 jkoopmann:127.0.0.1 k101 mmc.exe

147 jkoopmann:127.0.0.1 k101 SQL*Plus

156 jkoopmann:127.0.0.1 k101 slplus.exe

We will get to actually tracing in a future article but basically the columns supplied in the SQL select statement in Listing 1 are all allowed to filter and consolidate tracing statistics on. Hopefully you can see that by setting a client identifier we have just added great power in determining the unknown users of our database. We can now through extra tracing options determine who and what’s causing problems in our database. Also note that because this field can be changed at will, there is nothing to limit you to keeping the same CLIENT_IDENTIFIER for the life of the session. This may come in handy if your session actually performs different tasks that distinguish it from other sessions that originally had the same identifier.

After setting this client identifier, we have already seen that you may view this setting by the a query to the V$SESSION view. You may can also see the statistics around a particular CLIENT_IDENTIFIER from the V$ACTIVE_SESSION_HISTORY view. Listing 2 gives a query that we would typically issue to see the historical wait activity for sessions in the last 30 minutes. Notice that we have the same client identifier (CLIENT_ID) for each of the rows. This is fine if you are concerned with only tracking down one session that might be experiencing high wait times but sometimes it is the accumulated wait time that is caused by an application you are concerned about. To answer that question we can group on the CLIENT_ID column now and get a summation for a particular client identifier. This does assume you have set your client identifier to something more than what I have set mine to and something in line with the application area of interest. Listing 3 shows just such a query you might issue to sum total waits for an application area or in my case user connection across multiple sessions.

Listing 2

Looking at individual session wait activity

select session_id, client_id, event,

sum(wait_time + time_waited) ttl_wait_time

from v$active_session_history active_session_history

where sample_time between sysdate - 60/2880 and sysdate

group by session_id, client_id, event

order by 2;

SESSION_ID CLIENT_ID EVENT TTL_WAIT_TIME

---------- -------------------- ------------------------------ -------------

145 jkoopmann:127.0.0.1 SQL*Net message to client 3

145 jkoopmann:127.0.0.1 db file scattered read 111167

145 jkoopmann:127.0.0.1 db file sequential read 59003

145 jkoopmann:127.0.0.1 direct path read temp 93314

145 jkoopmann:127.0.0.1 direct path write temp 2

156 jkoopmann:127.0.0.1 SQL*Net message from client 243192681

160 jkoopmann:127.0.0.1 db file scattered read 18657

160 jkoopmann:127.0.0.1 db file sequential read 28141

160 jkoopmann:127.0.0.1 direct path read temp 4887

160 jkoopmann:127.0.0.1 direct path write temp 24

Listing 3

Accumulated wait activity for an application area or user defined area

select client_id, event,

sum(wait_time + time_waited) ttl_wait_time

from v$active_session_history active_session_history

where sample_time between sysdate - 60/2880 and sysdate

group by client_id, event

order by 1;

CLIENT_ID EVENT TTL_WAIT_TIME

-------------------- ------------------------------ -------------

jkoopmann:127.0.0.1 SQL*Net message from client 243192681

jkoopmann:127.0.0.1 SQL*Net message to client 3

jkoopmann:127.0.0.1 db file scattered read 129824

jkoopmann:127.0.0.1 db file sequential read 115553

jkoopmann:127.0.0.1 direct path read temp 98201

jkoopmann:127.0.0.1 direct path write temp 26

Also if you ever find yourself wanting to know what your CLIENT_IDENTIFIER is set to so that you can monitor or take some for of logical action within an application, you need only issue the following SQL.

SELECT SYS_CONTEXT('USERENV','CLIENT_IDENTIFIER') CLIENT_IDENTIFIER

FROM DUAL;

CLIENT_IDENTIFIER

-------------------

jkoopmann:127.0.0.1

If you ever wish to clear out the CLIENT_IDENTIFIER for a session, you need only execute the following procedure.

DBMS_SESSION.CLEAR_IDENTIFIER

The use of a CLIENT_IDENTIFIER can come in handy for many situations where monitoring individual sessions or a group of sessions is required. It does not matter if those sessions connect to the same session id or different ones. If you choose your client identifier properly for groups of applications or users, you can now generate true wait related information that tells you exactly what they have been doing. Stay tuned for more session tracing in the next part of this series.