Determining NLS_DATE_FORMAT

As a short follow-up to a previous post regarding implicit date conversion and the NLS_DATE_FORMAT, which governs the default date format Oracle will use with the TO_DATE and TO_CHAR functions, I forgot to mention a couple of things:

  • how to determine the current NLS_DATE_FORMAT setting
  • changing the NLS_DATE_FORMAT via DBMS_SESSION

As noted in the previous post, the NLS_DATE_FORMAT setting is session modifiable via the ALTER SESSION command, e.g.:

ALTER SESSION SET nls_date_format = 'dd/mm/yyyy'

In order to work out what NLS_DATE_FORMAT your session has been configured with then the NLS_SESSION_PARAMETERS view will provide this information:

SELECT value
FROM   nls_session_parameters
WHERE  parameter = 'NLS_DATE_FORMAT'

If you wanted to work out what the format was for the database, as opposed to your session, then you can query the NLS_DATABASE_PARAMETERS view instead:

SELECT value
FROM   nls_database_parameters
WHERE  parameter = 'NLS_DATE_FORMAT'

NLS_DATE_FORMAT may also be set via the DBMS_SESSION.SET_NLS routine. One advantage to setting it via DBMS_SESSION is that it can done from within PL/SQL without having to go through the messy business of dynamic SQL as ALTER SESSION is not directly callable from PL/SQL. The call is simply:

dbms_session.set_nls ('nls_date_format','''dd/mm/yyyy''')

Note, for string NLS parameter values the embedded quotes need to be contained in the string argument to the procedure call, hence the 3 single quotes on either side of the format parameter.

The following is a basic illustration of the above points, setting the NLS_DATE_FORMAT via DBMS_SESSION and querying the session and database properties:

SQL> EXEC dbms_session.set_nls ('nls_date_format','''dd/mm/yyyy''')

PL/SQL procedure successfully completed.

SQL> SELECT value
  2  FROM   nls_session_parameters
  3  WHERE  parameter = 'NLS_DATE_FORMAT'
  4  /

VALUE
----------------------------------------
dd/mm/yyyy

SQL> SELECT value
  2  FROM   nls_database_parameters
  3  WHERE  parameter = 'NLS_DATE_FORMAT'
  4  /

VALUE
----------------------------------------
DD-MON-RR
Advertisements

Process Monitoring – Active Session History

Previously I noted how I took my early steps in figuring out what Oracle was doing with my code when I ran it. My early attempts were a combination of code instrumentation and polling of v$sql to find what queries Oracle was running and when. The key limitation as far as polling goes is that it required me to be actively monitoring the process in real time. So, how can we work out what a process did after it has been executed?

Prior to Oracle 10g the answer was not easily unless you did something like run an SQL trace on the process. Oracle 10g introduced Active Session History, which changed things for process monitoring. From the Oracle 11g Release 2 documentation:

“The V$ACTIVE_SESSION_HISTORY view provides sampled session activity in the instance. Active sessions are sampled every second and are stored in a circular buffer in SGA. Any session that is connected to the database and is waiting for an event that does not belong to the Idle wait class is considered as an active session. This includes any session that was on the CPU at the time of sampling.”

So, with Active Session History (often abbreviated to ASH), Oracle samples the database every second and stores details of every session that is considered “active”, meaning that it is waiting on a non-idle wait event or is executing on a CPU. These details are exposed via the data dictionary view v$active_session_history (or gv$active_session_history if you’re operating a RAC environment).

A key detail to note is that the underlying data store for Active Session History is a circular memory buffer. Once the buffer is full then older entries are overwritten by new ones. The question that then arises is “how long will an entry remain in the buffer before being overwritten?”. Unfortunately there is no simple answer to that question as it depends on how many active sessions there have been in the database. You may find that it takes a day or more before details are overwritten or it could be a few hours or less. You can easily find out how much ASH history you have available by running the following query:

SELECT MIN(sample_time) AS min_sample_time
FROM   v$active_session_history

If you find that your process has aged out of Active Session History buffer then all is not quite lost. Every 10th sample from v$active_session_history is saved into the Active Workload Repository (AWR) and exposed via the view dba_hist_active_sess_history. From within v$active_session_history, you can tell which samples have been saved from the flag stored in the IS_AWR_SAMPLE column. Unfortunately, 10 second samples are rather too infrequent to obtain a good idea of what a process did.

So, assuming that your recently run process is somewhere in Active Session History, how do you go about getting its details. Well, similar to finding your process if it is currently being executed the first step is to identify the session that it’s running under. Again, there’s no single way to do this and all the suggestions for finding the process in v$session apply: find one or more attributes that you know about your session and filter the ASH data based on those. v$active_session_history has MODULE, ACTION, CLIENT_ID columns so if you’ve been making use of those (as I would encourage) then you’ll probably find it quite easy to locate the necessary session details.

Within v$active session_history the session SID is named SESSION_ID and the SERIAL# is named SESSION_SERIAL# (consistency in naming
with v$session would have been nice…). Once you’ve identified some session entries, obtained these two attributes and have an idea of when your process ran then you can quickly get all of the Active Session History details with the following query:

SELECT *
FROM   v$active_session_history
WHERE  sample_time BETWEEN :start_time and :end_time
AND    session_id = :session_id
AND    session_serial# = :session_serial#
ORDER  BY
       sample_time

Keep in mind that this query will give you an entry per second that your process was executing so there could be quite a few entries for a particularly long running process.

Analysing your process from Active Session History is quite simple once you’ve got a listing of it. The SQL_ID and SQL_CHILD_NUMBER columns give you the particular statement that executing when the sample was taken. As mentioned in the previous post, these details are sufficient to obtain the SQL statement and the execution plan used. Furthermore, Oracle 11.2 introduced the column SQL_EXEC_ID, which can be used to distinguish different executions of the same statement. This is particularly useful if your process runs the same statement frequently. Bear in mind however that it will not tell you how many times a statement has been run if your process executes it many times between the one second sample points.

The EVENT column and associated parameters are useful in determining what the process has spent time waiting on when it hasn’t been active on the CPU. However, I don’t intend to go into wait events here. You will find a listing of the various wait events in Appendix C of the Oracle Database Reference documentation.

The columns starting with BLOCKING are useful in determining if your process was blocked by another session. This can happen for various reasons, such as if another process obtained locks on rows that your process was attempting to modify. The wait event for your session will give you an idea of why your process was being blocked. You can use the blocking session details provided to re-query Active Session History to find what session was blocking your process and what it was doing.

Some other columns that I’ve found useful when using Active Session History are:

  • CURRENT_OBJ# – the OBJECT_ID from the DBA_OBJECTS view of the object being referenced when the sample was taken. If this is constant across a number of samples then it can give you an idea of which area of a query Oracle is spending its time. Keep in mind that SQL monitoring may give better information in this case.
  • TOP_LEVEL_SQL_ID – the SQL_ID of the top level statement that is executing, which could be the stored procedure call from the application initiating the process.
  • IN_HARD_PARSE – this flags whether the process was performing a hard parse when the sample was taken. This can be useful for determining if your process is spending too much time hard parsing queries.
  • SEQ# – a unique wait event identifier, which can be used to track whether a wait event is a continuation of the same event from the previous sample, i.e. the wait has lasted more than 1 second, or if it is a new wait event.

There is a wealth of information available within Active Session History and it is possible to construct all sorts of informative queries. As an example, the following query will list the SQL details of a session in the order that they executed, showing their general duration as measured by the samples:

SELECT ash.sql_id
,      ash.sql_child_number
,      s.sql_text
,      ash.sql_exec_start
,      ash.sql_exec_id
,      TO_CHAR(MIN(ash.sample_time),'hh24:mi:ss') AS min_sample_time
,      TO_CHAR(MAX(ash.sample_time),'hh24:mi:ss') AS max_sample_time
FROM   v$active_session_history ash
,      v$sql s
WHERE  ash.sql_id           = s.sql_id (+)
AND    ash.sql_child_number = s.child_number (+)
AND    ash.session_id       = :session_id
AND    ash.session_serial#  = :session_serial#
GROUP  BY
       ash.sql_id
,      ash.sql_child_number
,      s.sql_text
,      ash.sql_exec_start
,      ash.sql_exec_id
ORDER  BY
       MIN(ash.sample_time)

When run after the following rather simplistic script:

DECLARE
   TYPE t_dba_extents_tab IS TABLE OF dba_extents%ROWTYPE;
   TYPE t_dba_objects_tab IS TABLE OF dba_objects%ROWTYPE;
   TYPE t_dba_users_tab   IS TABLE OF dba_users%ROWTYPE;
   
   l_dba_extents_tab    t_dba_extents_tab;
   l_dba_objects_tab    t_dba_objects_tab;
   l_dba_users_tab      t_dba_users_tab;
   
   l_sid      v$session.sid%TYPE;
   l_serial#  v$session.serial#%TYPE;
BEGIN

   SELECT sid
   ,      serial#
   INTO   l_sid
   ,      l_serial#
   FROM   v$session
   WHERE  sid = SYS_CONTEXT('userenv','sid');

   dbms_output.enable(null);
   dbms_output.put_line ('Session ID: ' || TO_CHAR(l_sid) || ', Serial#: ' || TO_CHAR(l_serial#));

   -- run a few queries in a loop so we can use up some time
   FOR i IN 1..5
   LOOP
      SELECT *
      BULK COLLECT INTO l_dba_extents_tab
      FROM   dba_extents
      ORDER  BY
             owner
      ,      segment_name
      ,      partition_name;

      SELECT *
      BULK COLLECT INTO l_dba_objects_tab
      FROM   dba_objects
      ORDER  BY
             owner
      ,      object_type
      ,      object_name;

      SELECT *
      BULK COLLECT INTO l_dba_users_tab
      FROM   dba_users
      ORDER  BY
             username;
   END LOOP;
END;
/

the results were:

SQL_ID        SQL_CHILD_NUMBER SQL_TEXT             SQL_EXEC_ SQL_EXEC_ID MIN_SAMP MAX_SAMP
------------- ---------------- -------------------- --------- ----------- -------- --------
7mb45hj1u38dk                1 SELECT * FROM DBA_EX 02-MAY-12    16777227 06:56:48 06:56:52
                               TENTS ORDER BY OWNER
                                , SEGMENT_NAME , PA
                               RTITION_NAME

5f4b3676kpnh3                1 SELECT * FROM DBA_OB 02-MAY-12    16777229 06:56:53 06:56:53
                               JECTS ORDER BY OWNER
                                , OBJECT_TYPE , OBJ
                               ECT_NAME

7mb45hj1u38dk                1 SELECT * FROM DBA_EX 02-MAY-12    16777228 06:56:54 06:56:58
                               TENTS ORDER BY OWNER
                                , SEGMENT_NAME , PA
                               RTITION_NAME

7mb45hj1u38dk                1 SELECT * FROM DBA_EX 02-MAY-12    16777229 06:56:59 06:57:03
                               TENTS ORDER BY OWNER
                                , SEGMENT_NAME , PA
                               RTITION_NAME

5f4b3676kpnh3                1 SELECT * FROM DBA_OB 02-MAY-12    16777231 06:57:04 06:57:04
                               JECTS ORDER BY OWNER
                                , OBJECT_TYPE , OBJ
                               ECT_NAME

7mb45hj1u38dk                1 SELECT * FROM DBA_EX 02-MAY-12    16777230 06:57:05 06:57:09
                               TENTS ORDER BY OWNER
                                , SEGMENT_NAME , PA
                               RTITION_NAME

7mb45hj1u38dk                1 SELECT * FROM DBA_EX 02-MAY-12    16777231 06:57:10 06:57:14
                               TENTS ORDER BY OWNER
                                , SEGMENT_NAME , PA
                               RTITION_NAME

5f4b3676kpnh3                1 SELECT * FROM DBA_OB 02-MAY-12    16777233 06:57:15 06:57:15
                               JECTS ORDER BY OWNER
                                , OBJECT_TYPE , OBJ
                               ECT_NAME

From the above we can see that the query against DBA_EXTENTS used up most of the time and that all 5 executions of it appeared in Active Session History. The query against DBA_OBJECTS shows up 3 times while the query against DBA_USERS doesn’t even appear once. This illustrates rather nicely the fact that the Active Session History details are sample based; if a query happens to be running when a sample is taken then its details get recorded, if not then it will not appear and you may not even be aware that it has been run.

So, what are the drawbacks to Active Session History? From a process monitoring perspective it is important to realise that Oracle records details of what a session is doing as at the point it takes the sample, as illustrated in the previous example. So, if in the one second since the previous sample your process has run half a dozen SQL statements then only the one that was being executed at the moment the sample was taken will be picked up. This means that for fast OLTP-type processes it is unlikely that you will obtain details of every statement issued by your process. If you require an in-depth analysis of what your process is doing then obtaining an SQL Trace might be the way to go… but this will have to be set-up prior to the execution of your process.

Probably the bigger drawback for Active Session History is that it requires the Oracle Diagnostics Pack license, which is only available for Enterprise Edition of the database. If you are using Standard Edition or Express Edition then Active Session History simply isn’t available to you.

Basic Process Monitoring

One of the hardest things that I found when starting out developing in Oracle was working out what Oracle was doing with my code. I followed normal development practices, assembled my code into a logical sequence of actions, deployed and ran it… and then Oracle was like a black box until it finished and I could check the results of the process. At times I would be developing long running processes that I would want to monitor as it was executing. So, how should I go about this I wondered?

Not knowing much about the internals of Oracle I started to instrument my code. Before and after any major activity I would write out a message to a log table, which gave me valuable information as to the path that my code took and how long it spent executing the step. Autonomous transactions permitted me to view my log messages as they were generated, which is a huge benefit when tracing an executing process in real time. I still instrument my code and maintain that it is the single most important practice for general problem resolution.

However, while instrumentation gave me insights into my code it didn’t help too much when it came down to working out what a long running query was up to. It was then that I had to delve into the Oracle black box. Thankfully, once I got started I found out that Oracle is quite forthcoming with details. If anything, the amount of detail available can be overwhelming. For my purpose, I simply wanted to observe what my process was up to and what queries it was running.

So, for now, I’m going to describe how I got started by simply identifying a running session and figuring out the details of the SQL that was being executed. Once I was able to track down details about actual SQL execution then I had gained further insights into my processes and why they might not be behaving as I expected.

Session Identification

The first step to monitoring a process is to determine the database session that it is running under. The internal view v$session is a listing of all sessions within the database so the process is one of those entries… but which one? Well, unfortunately there’s no single, simple answer and some detective work is needed to filter down the list to the process entry.

Some column filters that are typically useful are:

  • STATUS – filter for a value of ACTIVE
  • USERNAME – filter for the account name that the proces is run from within
  • OSUSER – filter for the name of the network account that is being used to run the process
  • MACHINE – the name of the remote computer that is being used to run the process

As an example, the following query may be used to identify active sessions being run by a specific network user:

SELECT *
FROM   v$session
WHERE  status = 'ACTIVE'
AND    osuser = :user

From the above filters it’s generally possible to narrow the list of sessions down to a handful of candidates even in a busy system. Problems can still arise though when connection pooling is used by application middle tiers. With such architectures it can be difficult to pinpoint the specific session of interest. The use of MODULE, ACTION and CLIENT_INFO settings can be invaluable in such scenarios but only if the application has been written to utilise them (do I really need to emphasise this point again?). If the database is set up in a shared server configuration then this would present yet another hurdle.

Assuming that the session running the process has been identified then the details within v$session, as of Oracle 10g, provide critical pieces of information of what the process is doing, including:

  • SQL_ID – the ID of the SQL statement that is currently being executed
  • EVENT – the event that the session is currently waiting on. Also provided are the event parameter values (P1, P2, P3) for further diagnoses
  • BLOCKING_SESSION – The SID of the session currently blocking the process

To get the details of the SQL being executed then all we need is the SQL_ID and SQL_CHILD_NUMBER values…

SQL Statement

Once the SQL_ID and SQL_CHILD_NUMBER that the process is executing has been obtaned from v$session then finding the SQL statement is quite trivial. The following simple query against v$sql will yield this information:

SELECT sql_fulltext
FROM   v$sql
WHERE  sql_id        = :sql_id
AND    child_number  = :sql_child_number

Note however that the SQL_FULTEXT column is a CLOB data type, which may present problems for certain database client programs. The SQL_TEXT column can be used instead to obtain the first 1,000 bytes of the full text.

So, we’ve now progressed from identifying the session that the process is running under to identifying the SQL that it’s running. The next check is whether it’s executing in a manner that we expected…

SQL Execution Plan

During development I general check that the execution plan of any SQL is going to be reasonable. Obviously the criteria of what is “reasonable” is variable depending on the type of statement. However, after deployment it may be that either the execution plan turns out to be not appropriate or Oracle chooses to use a plan that is different to what I expected. In any case, it’s worthwhile checking that the actual execution plan of the SQL being executed. The SQL_ID and SQL_CHILD_NUMBER from v$session are used to obtain that:

SELECT *
FROM   TABLE(dbms_xplan.display_cursor(:sql_id,:sql_child_number))

The plan obtained from the above query can then be used to compare to the plan obtained during development to see if there are any significant changes.

It may be that the plan is as expected but the query still seems to take an excessive amount of time. In this situation it may be possible to check the query progress via SQL Monitor, which provides an execution breakdown of each step of the plan.

The above procedure is aimed at helping a newcomer to Oracle to work out some basic details of what an executing process is doing. v$session provides details of the currently executing SQL statement and v$sql gives us the actual statement. Obviously this approach is only effective for processes running for a reasonable length of time. Regular, real time polling (combined with any process instrumentation, of course) is required in order to get a reasonable appreciation of what a process is up to over its total execution.

However, it is regularly the case that the process is already well underway or even completed before the question is asked “what did that process do?”, often with the secondary question of “… and why did it take so long?”. So, is it possible to see what a process got up to after it has finished execution? This will form the basis of a future post…