Module & Action

Monitoring activity in a busy database is easy from a session perspective; we can see the SQL statements that are being executed and a raft of other details. However, understanding the particular business process that’s being executed can be difficult, especially when various processes execute the same statements.

Oracle provides mechanisms to help us in this regard by providing two session level variables; module and action. The supplied package DBMS_APPLICATION_INFO provides routines for setting these variables; SET_MODULE and SET_ACTION. The documentation for DBMS_APPLICATION_INFO notes the purpose of the module and action to be:

“Your applications should set the name of the module and name of the action automatically each time a user enters that module. The module name could be the name of a form in an Oracle Forms application, or the name of the code segment in an Oracle Precompilers application. The action name should usually be the name or description of the current transaction within a module.”

The reality is that the settings are session-based string variables that can be set as required. The module can be up to 48 bytes and the action can be up to 32 bytes. I typically adopt one of two strategies for setting these variables:

Make the module the name of the executing package and the action the name of the routine within the paackge

or

Set the module to name of the business process and the action to be a combination of the executing package and package routine.

The particular strategy adopted is based on which one I believe to be most effective for the situation that presents itself. If the particular process is predominantly self-contained in a single package then I’ll use the former. If the process is involved and spread out across multiple packages then I’ll adopt the latter. The action may not be set for every routine, especially if the routine is a “helper” style of routine as opposed to a core contributor of the overall process.

So, how can we use these settings? Well, they’re exposed in the v$session view, which is typically the first place people look to figure our what’s running in the database. GUI tools such as SQL Developer and TOAD display the module and action settings in their session monitor windows. From a performance tuning perspective, as of Oracle 10g it’s possible to invoke SQL Trace based on the module and action values. This is a particularly nice feature if you have a complex multi-tiered application with connection pooling that makes it hard to identify specific end-user activity at the database level.

Let’s look at a simple script that illustrates how the module and action settings might be used. The script outlines an ETL process that obtains the source data, cleans it, transforms it and loads it into a destination. Rather than actually performing these tasks we’ll just use placeholders.

SET ECHO ON
SET SERVEROUPTUT ON

-- clear any existing settings for module and action
-- before we run the script
EXEC dbms_application_info.set_module (NULL,NULL)

DECLARE

   -- a routine that obtains the module and action and outputs them
   -- using dbms_output, along with a message
   PROCEDURE display (p_msg IN VARCHAR2)
   AS
      l_module_name  VARCHAR2(48);
	  l_action_name  VARCHAR2(32);
   BEGIN
      dbms_application_info.read_module (module_name => l_module_name
	                                    ,action_name => l_action_name);
      dbms_output.put_line (NVL(l_module_name,'<>') || ':'   || 
	                        NVL(l_action_name,'<>') || ' - ' || 
							p_msg);
   END display;

   -- simple stubs that do nothing except set the action   
   PROCEDURE read_data
   AS
   BEGIN
      dbms_application_info.set_action ('read_data');
      display ('Inside read_data');
   END read_data;   

   PROCEDURE clean_data
   AS
   BEGIN
      dbms_application_info.set_action ('clean_data');
      display ('Inside clean_data');
   END clean_data;   

   PROCEDURE transform_data
   AS
   BEGIN
      dbms_application_info.set_action ('transform_data');
      display ('Inside transform_data');
   END transform_data;   

   PROCEDURE load_data
   AS
   BEGIN
      dbms_application_info.set_action ('load_data');
      display ('Inside load_data');
   END load_data;   
BEGIN

   display ('Start');

   dbms_application_info.set_module (module_name => 'ETL Process'
                                    ,action_name => NULL);
				
   read_data;
   clean_data;
   transform_data;
   load_data;   

   display ('End');

END;   
/

The script produces the following output:

<>:<> - Start
ETL Process:read_data - Inside read_data
ETL Process:clean_data - Inside clean_data
ETL Process:transform_data - Inside transform_data
ETL Process:load_data - Inside load_data
ETL Process:load_data - End

PL/SQL procedure successfully completed.

We can see easily that the module and action settings are being set as expected.

Despite the simplicity behind setting the variables there are some points to consider. The module and action settings stay set until until changed to some other value or the session terminates. So, if a process fails to set the variables then they remain with whatever their current values might be. This means that if your application uses connection pooling then potentially the settings may be retained across different application sessions.

The retention of the settings means that if routines modify the setting then they remain in effect once the routine exits. So, if proc_a calls proc_b and proc_b modifies the action setting, then any processing performed by proc_a after the call to proc_b will be done under the action that proc_b set. Let’s modify the previous example to illustrate this. Instead of calling the various procedures in sequence, our new process requires that the transform_data routine invokes the clean_data routine. I’ve modified the code to display the module and action setting before and after the call to clean_data:

SET ECHO ON
SET SERVEROUPTUT ON

-- clear any existing settings for module and action
EXEC dbms_application_info.set_module (NULL,NULL)

DECLARE

   -- a routine that obtains the module and action and outputs them
   -- using dbms_output, along with a message
   PROCEDURE display (p_msg IN VARCHAR2)
   AS
      l_module_name  VARCHAR2(48);
	  l_action_name  VARCHAR2(32);
   BEGIN
      dbms_application_info.read_module (module_name => l_module_name
	                                    ,action_name => l_action_name);
      dbms_output.put_line (NVL(l_module_name,'<>') || ':'   || 
	                        NVL(l_action_name,'<>') || ' - ' || 
							p_msg);
   END display;

   -- simple stubs that do nothing except set the action   
   PROCEDURE read_data
   AS
   BEGIN
      dbms_application_info.set_action ('read_data');
      display ('Inside read_data');
   END read_data;   

   PROCEDURE clean_data
   AS
   BEGIN
      dbms_application_info.set_action ('clean_data');
      display ('Inside clean_data');
   END clean_data;   

   PROCEDURE transform_data
   AS
   BEGIN
      dbms_application_info.set_action ('transform_data');
      display ('Inside transform_data, before clean_data');
      clean_data;
      display ('Inside transform_data, after clean_data');
   END transform_data;   

   PROCEDURE load_data
   AS
   BEGIN
      dbms_application_info.set_action ('load_data');
      display ('Inside load_data');
   END load_data;   
BEGIN

   display ('Start');

   dbms_application_info.set_module (module_name => 'ETL Process'
                                    ,action_name => NULL);
				
   read_data;
   transform_data;
   load_data;   

   display ('End');

END;   
/

This produces the following output:

<>:<> - Start
ETL Process:read_data - Inside read_data
ETL Process:clean_data - Inside clean_data
ETL Process:clean_data - Inside transform_data
ETL Process:load_data - Inside load_data
ETL Process:load_data - End

PL/SQL procedure successfully completed.

We can see from the above output that the “Inside transform data” entry has the action “clean_data”, which was what the “clean_data” routine set it to. This is probably not what is intended. So, how do we manage this?

One strategy is to simply to be strict as to which routines do and do not alter the module and action settings. Routines that call others should “know” whether the module or action settings will be modified by those routines and, if necessary, revert the values once the call has completed. So, in the above example, the transform_data routine would need to reset the action after the call to clean_data. Obviously this may not be as easy to achieve, especially in a large environment with routines that are used by many different processes.

Another strategy, and to date it’s my preferred one, is for any routine that changes the module and / or action setting to reset them back to their previous values prior to exit. However, this too isn’t as easy as it may appear. To start with it requires programming discipline to ensure the current values are saved and then restored on exit. Failure to do so will not result in any obvious error except for the fact that the settings will no longer reflect the expected values. Only specific testing or close monitoring will pick this up. Also, routines have two exit mechanisms; normal completion of the main body and exception exit. Exit of a routine via an exception will either need to restore the values, via an exception handler, or accept the corruption of the settings in the event of an exception.

Can we make the handling of the module and action settings easier for us? The next post looks at a small package that helps me…


Download scripts shown in this post.

Advertisements

Session Longops

One area that PL/SQL is commonly used for is large, batch-style data processing. Afterall, why pull large volumes of data out of the database, manipulate it and then push it back into the database when the process can be accomplished within the database by a language that is tailored for that type of activity?

Not only do bulk data processes manipulate large volumes of data but they are often long running. As with any long running process the question of “how long before it is finished?” is raised, particularly when the process is vitally important for the organisation or if other processes are waiting for it to complete. While historical statistics will give run time averages, the question of how far through an executing process has progressed is difficult to determine if the process hasn’t been designed to reveal that information.

One obvious strategy to obtain current execution details is for the process to log its progress, and I would highly recommend this strategy. However, this post is concerned with another mechanism for monitoring processes; session longops.

The supplied package DBMS_APPLICATION_INFO exposes the SET_SESSION_LONGOPS procedure. This routine is used to create an entry in the v$session_longops view and record processing progress. The details recorded are simply “processed X many widgets out of Y” so it is ideal for tracking progress through a collection of items. It is the responsibility of the process to invoke SET_SESSION_LONGOPS to update the progress statistics.

Let’s look at a simple scenario; we have a process that works its way through 120 “things” and “does stuff” for each one (feel free to substitute something relevant to you for “things” and “does stuff”). The code for this process may vaguely resemble:

SET ECHO ON

-- display the session SID so we can query
-- v$session_longops for this session
SELECT SYS_CONTEXT('userenv','sid') AS session_sid
FROM   dual
/

PAUSE

-- simply loop through an array of 120 entry, pausing for one
-- second and updating session longops per iteration
DECLARE
   -- create a associative array to store the "things" we process
   TYPE t_number_tab IS TABLE OF NUMBER INDEX BY BINARY_INTEGER;
   l_number_tab  t_number_tab;

   -- longops variables
   l_rindex             BINARY_INTEGER;
   l_slno               BINARY_INTEGER;
   l_sofar              NUMBER;
   l_totalwork          NUMBER;
   
   PROCEDURE do_stuff (p_number IN NUMBER)
   AS
   BEGIN
      -- we'll simulate activity by sleeping for a while...
      -- (and I'm sure there's a joke lurking in that statement somewhere...)
      dbms_lock.sleep(1);
   END do_stuff;

BEGIN   

   -- populate the array with 120 values
   FOR i IN 1..120
   LOOP
      l_number_tab(i) := i;
   END LOOP;
   
   -- create a new entry in the session longops view
   l_rindex    := dbms_application_info.set_session_longops_nohint;
   -- set the total amount of processing we expect to do
   l_totalwork := l_number_tab.COUNT; 
   -- set the current progress
   l_sofar := 0;
   -- initialise the session longops monitoring
   dbms_application_info.set_session_longops
     (rindex      => l_rindex
     ,slno        => l_slno
     ,op_name     => 'Doing stuff'
     ,target      => 0
     ,context     => 0
     ,sofar       => l_sofar
     ,totalwork   => l_totalwork
     ,target_desc => 'Array of things'
     ,units       => 'Things'); 
   
   -- simply loop through the elements in the array
   FOR i IN l_number_tab.FIRST..l_number_tab.LAST
   LOOP
      --"do stuff" for each array element
      do_stuff (l_number_tab(i));
	  
      -- increament the activity counter
      l_sofar := l_sofar + 1;
      -- update the session longops
      dbms_application_info.set_session_longops
         (rindex      => l_rindex
         ,slno        => l_slno
         ,totalwork   => l_totalwork
         ,sofar       => l_sofar); 
   END LOOP;

END;
/

The above script will display the session’s SID before continuing with the processing. We need the SID to feed into the following query, which we will run from a separate session to see how our process is going:

SET ECHO ON
SET DEFINE ON
SET LINESIZE 132

COLUMN opname FORMAT A15
COLUMN target FORMAT A15
COLUMN units  FORMAT A10

SELECT sid
,      opname
,      target
,      sofar
,      totalwork
,      units
,      start_time
,      time_remaining
FROM   v$session_longops
WHERE  sid = &sid
/

Running the above query whilst our processing script is execute we get (after 10 seconds since the our process commenced):

       SID OPNAME          TARGET               SOFAR  TOTALWORK UNITS      START_TIM TIME_REMAINING
---------- --------------- --------------- ---------- ---------- ---------- --------- --------------
       144 Doing stuff                             10        120 Things     03-AUG-11            110

The above output tells us that our processing has got through 10 “things” out of the 120 that will be processed. You’ll also note that the time remaining has been correctly calculated, which is a very nice touch to session longops. Obviously if the time per “thing” varies then Oracle may not be quite the “Oracle” that its name may imply…

If the “things” to process are being taken from a cursor then the number of entries may be unknown. Session longops does not require that the total work attribute be populated so this parameter may be left as NULL. Obviously in this scenario Oracle will be unable to calculate the time remaining.


Download scripts shown in this post.

Interval Aggregation

Interval data types were introduced in Oracle 9i. The idea is that they store an “amount” of time, e.g. “5 minutes”, “1 year and 2 months”. Before interval data types it was common to track time units using simple numeric values. Oracle natively supports date arithmetic on the DATE data types with a value of 1 denoting “1 day”. This mechanism allows us to do things like determine the following week by adding 7 to a DATE variable.

Oracle now provides 2 interval data types; YEAR TO MONTH and DAY TO SECOND. Two data types are necessary to be able to handle the fact that months have a different number of days.

Interval data types have a number of advantages over the dates and a number offset approach. Oracle “knows” about the time they represent and is able to handle operations correctly. For example, Oracle “knows” that “1 day, 6 hours” is equivalent to “30 hours” if a comparison is made between them, Furthermore, it also “knows” that it is the same as “adding 18 hours and 12 hours”. Adding an interval data type to a timestamp data type results in a timestamp that is the interval value beyond the original timestamp. All this operates in a nice and logical manner! You can find more about how Oracle handles datetime / interval arithmetic in the Oracle documentation.

One area that is lacking for interval data types is with the SQL aggregate functions. As mentioned earlier, Oracle can correctly add two intervals together:

SELECT INTERVAL '18' HOUR + INTERVAL '12' HOUR AS time_period
FROM   dual
/

and this correctly gives us:

TIME_PERIOD
-----------------------------
+000000001 06:00:00.000000000

However, if we try to use the SUM aggregate function to add together a column of an interval data type:

SELECT SUM(time_period) AS sum_time_period
FROM   (SELECT INTERVAL '18' HOUR AS time_period
        FROM   dual
		UNION ALL
		SELECT INTERVAL '12' HOUR
		FROM   dual)
/

we get:

SELECT SUM(time_period) AS sum_time_period
           *
ERROR at line 1:
ORA-00932: inconsistent datatypes: expected NUMBER got INTERVAL DAY TO SECOND

This behaviour is rather annoying but can be worked around by creating our own aggregate function. Documentation on creating aggregate functions can be found in Chapter 11 of the Oracle Database Data Cartridge Developer’s Guide.

So, how do we create an aggregate function that we can use to sum interval data types? We will need an object type and a function, which for this example we’ll name t_sum_interval and sum_interval respectively. We’ll use the DAY TO SECOND interval data type as I have found that this data type is more common than the YEAR TO MONTH type, although this could easily be adapted if your requirements differ.

The core work is done by the object type. There are 4 routines and the Oracle provided documentation is quite clear on what purpose they serve. For our interval aggregation function our object type specification is simply:

CREATE OR REPLACE TYPE t_SumInterval AS OBJECT
(
--------------------------------------------------------------------------------
--  Type          : t_SumInterval
--  Author        : Mark Hoxey
--  Creation Date : 01/09/2009
--
--  Overview      : Object type to implement the SumInterval aggregate function
--------------------------------------------------------------------------------
-- Source Control : $Id$
--------------------------------------------------------------------------------
--  Modification History :
--
--  Initials  Date        Description
--  --------  ----------  ---------------------------------------
--  M Hoxey   01/09/2009  Initial version
--------------------------------------------------------------------------------
 
--------------------------------------------------------------------------------
-- Member Properties

-- Used to track the sum of intervals
l_interval  INTERVAL DAY(9) TO SECOND(9),

--------------------------------------------------------------------------------
-- Function      : ODCIAggregateInitialize
--
-- Description   : Initialisation function for the aggregate function which
--                 simply calls the default constructor.
--------------------------------------------------------------------------------
STATIC FUNCTION ODCIAggregateInitialize (p_SumInterval IN OUT t_SumInterval) 
RETURN NUMBER,
   
--------------------------------------------------------------------------------
-- Function      : ODCIAggregateIterate
--
-- Description   : Adds the interval specified to the interval member property
--                 after ensuring that either the provided interval or the
--                 member property is NOT NULL. If both are NULL then no action
--                 is taken and the member property is left as NULL.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateIterate (self         IN OUT t_SumInterval, 
                                      p_interval   IN     DSINTERVAL_UNCONSTRAINED) 
RETURN NUMBER,
   
--------------------------------------------------------------------------------
-- Function      : ODCIAggregateTerminate
--
-- Description   : Returns the interval member property on termination of the 
--                 aggregation operation.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateTerminate (self        IN  t_SumInterval, 
                                        p_interval  OUT DSINTERVAL_UNCONSTRAINED, 
                                        flags       IN  NUMBER) 
RETURN NUMBER,
   
--------------------------------------------------------------------------------
-- Function      : ODCIAggregateMerge
--
-- Description   : Adds an interval member property to the interval member 
--                 property of the current object, preserving NULLs are
--                 required for aggregate processing.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateMerge  (self            IN OUT t_SumInterval, 
                                     p_SumInterval   IN     t_SumInterval) 
RETURN NUMBER
   
);
/

Other than the prescribed functions, our object type has a single member property, which is used to accumulate the sum of the intervals we’re processing. If we were creating an average aggregate function then we would need to keep track of two values; the sum of values and the number of values.

The logic required for the 4 prescribed routines is:

ODCIAggregateInitialize – return, via the out parameter, a new object type instance with the member property initialised to NULL
ODCIAggregateIterate – add the specified interval onto the member property of the current instance
ODCIAggregateTerminate – return the member property of the current instance
ODCIAggregateMerge – take the member property of the input object type and add it onto the member property of the current instance

Our object type body implementation is:

CREATE OR REPLACE TYPE BODY t_SumInterval IS

--------------------------------------------------------------------------------
--  Type          : t_SumInterval
--  Author        : Mark Hoxey
--  Creation Date : 01/09/2009
--
--  Overview      : Object type to implement the SumInterval aggregate function
--------------------------------------------------------------------------------
-- Source Control : $Id$
--------------------------------------------------------------------------------
--  Modification History :
--
--  Initials  Date        Description
--  --------  ----------  ---------------------------------------
--  M Hoxey   01/09/2009  Initial version
--------------------------------------------------------------------------------

--------------------------------------------------------------------------------
-- Function      : ODCIAggregateInitialize
--
-- Description   : Initialisation function for the aggregate function which
--                 simply calls the default constructor.
--------------------------------------------------------------------------------
STATIC FUNCTION ODCIAggregateInitialize (p_SumInterval IN OUT t_SumInterval) 
RETURN NUMBER 
AS 
BEGIN
   p_SumInterval := t_SumInterval(NULL);
   RETURN ODCIConst.Success;
END ODCIAggregateInitialize;

--------------------------------------------------------------------------------
-- Function      : ODCIAggregateIterate
--
-- Description   : Adds the interval specified to the interval member property
--                 after ensuring that either the provided interval or the
--                 member property is NOT NULL. If both are NULL then no action
--                 is taken and the member property is left as NULL.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateIterate (self         IN OUT t_SumInterval, 
                                      p_interval   IN     DSINTERVAL_UNCONSTRAINED) 
RETURN NUMBER IS
BEGIN
   IF (self.l_interval IS NOT NULL OR p_interval IS NOT NULL) THEN
      self.l_interval := NVL(self.l_interval ,INTERVAL '0' SECOND) + NVL(p_interval ,INTERVAL '0' SECOND);
   END IF;
   RETURN ODCIConst.Success;
END ODCIAggregateIterate;

--------------------------------------------------------------------------------
-- Function      : ODCIAggregateTerminate
--
-- Description   : Returns the interval member property on termination of the 
--                 aggregation operation.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateTerminate (self        IN  t_SumInterval, 
                                        p_interval  OUT DSINTERVAL_UNCONSTRAINED, 
                                        flags       IN  NUMBER) 
RETURN NUMBER 
AS
BEGIN
   p_interval := self.l_interval;
   RETURN ODCIConst.Success;
END ODCIAggregateTerminate;

--------------------------------------------------------------------------------
-- Function      : ODCIAggregateMerge
--
-- Description   : Adds an interval member property to the interval member 
--                 property of the current object, preserving NULLs are
--                 required for aggregate processing.
--------------------------------------------------------------------------------
MEMBER FUNCTION ODCIAggregateMerge (self            IN OUT t_SumInterval, 
                                    p_SumInterval   IN     t_SumInterval) 
RETURN NUMBER 
AS
BEGIN
   IF (self.l_interval IS NOT NULL OR p_SumInterval.l_interval IS NOT NULL) THEN
      self.l_interval := NVL(self.l_interval ,INTERVAL '0' SECOND) + NVL(p_SumInterval.l_interval ,INTERVAL '0' SECOND);
   END IF;
   RETURN ODCIConst.Success;
END ODCIAggregateMerge;

END;
/

The only part remaining is the creation of the aggregate function that invokes our object type:

CREATE OR REPLACE FUNCTION SumInterval (p_interval DSINTERVAL_UNCONSTRAINED) 
--------------------------------------------------------------------------------
--  Function      : SumInterval
--  Author        : Mark Hoxey
--  Creation Date : 01/09/2009
--
--  Overview      : SUM aggregate function for DAY TO SECOND interval data type
--                  using the t_SumInterval object type
--------------------------------------------------------------------------------
-- Source Control : $Id$
--------------------------------------------------------------------------------
--  Modification History :
--
--  Initials  Date        Description
--  --------  ----------  ---------------------------------------
--  M Hoxey   01/09/2009  Initial version
--------------------------------------------------------------------------------
RETURN DSINTERVAL_UNCONSTRAINED 
PARALLEL_ENABLE
AGGREGATE USING t_SumInterval;
/

Quite simple really. The only potential stumbling point is with the handling of NULLs. If we look at how the SUM function works with respect to NULL entries we can ensure we mimic the correct behaviour (that is assuming we don’t already know how SQL aggregate functions are required to handle NULLs…).

Let’s create some tests for our new aggregate function to check that it’s working correctly, comparing the output to the standard SUM function operating on simple numeric values. Rather than creating a table of values I’ve SELECTed from DUAL to obtain a small set within an in-line view:

SELECT SumInterval(interval_val) AS sum_interval_val
,      SUM(number_val)           AS sum_number_val
FROM   (SELECT INTERVAL '2' DAY  AS interval_val
        ,      2                 AS number_val
        FROM   dual
        UNION ALL
        SELECT INTERVAL '3' DAY
        ,      3                
        FROM   dual
        UNION ALL
        SELECT INTERVAL '4' DAY
        ,      4               
        FROM   dual)
/

which gives us an output of:

SUM_INTERVAL_VAL               SUM_NUMBER_VAL
------------------------------ --------------
+000000009 00:00:00.000000000               9

So, our aggregated interval value appear to be correct. Now, how what happens if we introduce NULLs into the picture:

SELECT SumInterval(interval_val) AS sum_interval_val
,      SUM(number_val)           AS sum_number_val
FROM   (SELECT INTERVAL '2' DAY  AS interval_val
        ,      2                 AS number_val
        FROM   dual
        UNION ALL
        SELECT INTERVAL '3' DAY
        ,      3               
        FROM   dual
        UNION ALL
        SELECT NULL
        ,      NULL
        FROM   dual
        UNION ALL	
        SELECT INTERVAL '4' DAY
        ,      4               
        FROM   dual)
/

which gives us:

SUM_INTERVAL_VAL               SUM_NUMBER_VAL
------------------------------ --------------
+000000009 00:00:00.000000000               9

From the above we can see that we’ve correctly handled the behaviour of NULLs in that we ignored it. What about if all values are NULL though:

SELECT SumInterval(interval_val) AS sum_interval_val
,      SUM(number_val)           AS sum_number_val 
FROM   (SELECT NULL  AS interval_val
        ,      NULL  AS number_val
        FROM   dual
        UNION ALL
        SELECT NULL
        ,      NULL
        FROM   dual)
/

which gives us:

SUM_INTERVAL_VAL               SUM_NUMBER_VAL
------------------------------ --------------

So, it would appear that our interval aggregate function if behaving as expected. Normally I would recommend a larger test suite but I won’t include that for this post. We could easily implement other aggregate functions, MIN, MAX, AVG, etc, for interval data types in a similar manner. The hard part is remembering that the standard aggregate functions cannot be used with interval data types and that we will need to invoke our custom functions instead.


Download scripts shown in this post.

Package: pkg_err

Tools make life easier for developers. One of these tools that I find indispensible is a logging package. This post is not about that package though but one that is built on top of it; an error logging package.

Exception handling is one area that I have frequently found to be poor with PL/SQL applications. In particular identifying the specific place in the code where an exception is thrown can be a difficult task if any routine in the call stack has an exception handler that is simply:

EXCEPTION
   WHEN OTHERS THEN
      RAISE;

(I actually worked at a place where the above was part of the standard for any PL/SQL routine!)

The package I’ll introduce here exposes two very simple routines:

  • A function that returns the last SQL error message, complete with a error stack trace
  • A procedure that logs the last error message to the, as yet unspecified, logging package. This routine permits the user to include a customised message at the start of the error message text.

The package specification (or header) is:

CREATE OR REPLACE PACKAGE pkg_err
AS

--------------------------------------------------------------------------------
--  Package       : pkg_err
--  Author        : Mark Hoxey
--  Creation Date : 17/11/2009
--
--  Overview      : Error handling routines
--
--------------------------------------------------------------------------------
--  Source Control: $Id$
--------------------------------------------------------------------------------
--  Modification History :
--
--  Initials  Date        Description
--  --------  ----------  ---------------------------------------
--  M Hoxey   17/11/2009  Initial version
--  M Hoxey   02/12/2009  Added p_custom_message parameter to 
--                        log_last_err
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
-- Function      : full_err_msg
--
-- Description   : Returns the full error message stack
--------------------------------------------------------------------------------
FUNCTION full_err_msg
RETURN   pkg_log.t_log_msg;

--------------------------------------------------------------------------------
-- Procedure     : log_last_err
--
-- Description   : Logs the last error details
--------------------------------------------------------------------------------
PROCEDURE log_last_err (p_custom_message  IN pkg_db_type.t_big_string DEFAULT NULL);


END pkg_err;
/

The package body is:

CREATE OR REPLACE PACKAGE BODY pkg_err
AS

--------------------------------------------------------------------------------
--  Package       : pkg_err
--  Author        : Mark Hoxey
--  Creation Date : 17/11/2009
--
--  Overview      : Error handling routines
--
--------------------------------------------------------------------------------
--  Source Control: $Id$
--------------------------------------------------------------------------------
--  Modification History :
--
--  Initials  Date        Description
--  --------  ----------  ---------------------------------------
--  M Hoxey   17/11/2009  Initial version
--  M Hoxey   02/12/2009  Added p_custom_message parameter to 
--                        log_last_err
--  M Hoxey   09/12/2009  Added the NULLIF function to log_last_err_msg
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
-- Function      : full_err_msg
--
-- Description   : Returns the full error message stack
--------------------------------------------------------------------------------
FUNCTION full_err_msg
RETURN   pkg_log.t_log_msg
AS
BEGIN
   RETURN dbms_utility.format_error_stack || 
          pkg_gen_const.c_new_line || 
          dbms_utility.format_error_backtrace;
END full_err_msg;

--------------------------------------------------------------------------------
-- Procedure     : log_last_err
--
-- Description   : Logs the last error details
--------------------------------------------------------------------------------
PROCEDURE log_last_err (p_custom_message  IN pkg_db_type.t_big_string DEFAULT NULL)
AS
BEGIN
   pkg_log.err (NULLIF(p_custom_message || pkg_gen_const.c_new_line, pkg_gen_const.c_new_line) || 
                full_err_msg(),SQLCODE);
END log_last_err;


END pkg_err;
/

You’ll note the dependencies to the pkg_db_type package described in a previous post. With the pkg_err package deployed any time I want to log an exception I can simply include the following in my code:

EXCEPTION
   WHEN OTHERS THEN
      pkg_err.log_last_error;
	  RAISE;

My logging package will log the error message using an autonomous transaction so I’m free to rollback or do whatever other action I may like to do inside the exception handler. You will need to replace the call to pkg_log.err with whatever logging routine you use.

Let’s look at an example of how we would use these routines. The following code consists of an anonymous with 3 local procedures; proc_a, proc_b and proc_c (hey, I work with database systems so don’t expect imaginative names!). Proc_a, calls proc_b, which in turn calls proc_c. Initially we have no exception handling:

DECLARE
   PROCEDURE proc_c
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_c');
      RAISE NO_DATA_FOUND;
      dbms_output.put_line ('Start of proc_c');
   END proc_c;
   PROCEDURE proc_b
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_b');
      proc_c;
      dbms_output.put_line ('End of proc_b');
   END proc_b;
   PROCEDURE proc_a
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_a');
      proc_b;
      dbms_output.put_line ('End of proc_a');
   END proc_a;
BEGIN
   dbms_output.put_line ('Start of test');
   proc_a;
   dbms_output.put_line ('End of test');
END;
/

The execution of this code gives us:

Start of test
Start of proc_a
Start of proc_b
Start of proc_c
DECLARE
*
ERROR at line 1:
ORA-01403: no data found
ORA-06512: at line 6
ORA-06512: at line 13
ORA-06512: at line 20
ORA-06512: at line 25

All appears as we want; we can see the error and the line in the code where it originated. Now, let’s put an exception handler in proc_a. Inside the exception handler we’ll simply report the error and re-raise it:

DECLARE
   PROCEDURE proc_c
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_c');
      RAISE NO_DATA_FOUND;
      dbms_output.put_line ('Start of proc_c');
   END proc_c;
   PROCEDURE proc_b
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_b');
      proc_c;
      dbms_output.put_line ('End of proc_b');
   END proc_b;
   PROCEDURE proc_a
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_a');
      proc_b;
      dbms_output.put_line ('End of proc_a');
   EXCEPTION
      WHEN OTHERS THEN
	     dbms_output.put_line (SQLERRM);
         dbms_output.put_line ('-------------');
         RAISE;
   END proc_a;
BEGIN
   dbms_output.put_line ('Start of test');
   proc_a;
   dbms_output.put_line ('End of test');
END;
/

The output we get is:

Start of test
Start of proc_a
Start of proc_b
Start of proc_c
ORA-01403: no data foun
-------------
DECLARE
*
ERROR at line 1:
ORA-01403: no data foun
ORA-06512: at line 26
ORA-06512: at line 30

Hmmm… while we can still see the type of exception we have lost the details as to where it originated. We know that the proc_a exception handler caught it but that’s as specific as we can get. Let’s try again and this time use a combination of dbms_utility.format_error_stack and dbms_utility.format_error_backtrace.

DECLARE
   PROCEDURE proc_c
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_c');
      RAISE NO_DATA_FOUND;
      dbms_output.put_line ('Start of proc_c');
   END proc_c;
   PROCEDURE proc_b
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_b');
      proc_c;
      dbms_output.put_line ('End of proc_b');
   END proc_b;
   PROCEDURE proc_a
   AS
   BEGIN
      dbms_output.put_line ('Start of proc_a');
      proc_b;
      dbms_output.put_line ('End of proc_a');
   EXCEPTION
      WHEN OTHERS THEN
         dbms_output.put_line (dbms_utility.format_error_stack);
         dbms_output.put_line ('-------------');
         dbms_output.put_line (dbms_utility.format_error_backtrace);
         dbms_output.put_line ('-------------');
         RAISE;
   END proc_a;
BEGIN
   dbms_output.put_line ('Start of test');
   proc_a;
   dbms_output.put_line ('End of test');
END;
/

The output we get is:

Start of test
Start of proc_a
Start of proc_b
Start of proc_c
ORA-01403: no data found

-------------
ORA-06512: at line 6
ORA-06512: at line 13
ORA-06512: at line 20

-------------
DECLARE
*
ERROR at line 1:
ORA-01403: no data found
ORA-06512: at line 28
ORA-06512: at line 32

Ah, so now we’ve got the full error message, thanks to dbms_utility.format_error_stack, and the location of where it originated, thanks to dbms_utility.format_error_backtrace. This is exactly what the routine pkg_err.full_err_msg does. Note, dbms_utility.format_error_backtrace was introduced in Oracle 10g. Prior to this version, trapping exceptions and working out exactly where they originated was rather hard.

Once we’ve intercepted an exception we will often want to log it to our standard logging facility. This is the purpose of the other routine in pkg_err, log_last_err. As an option, the routine will accept a string that will prefix the standard Oracle error message. The idea behind this to provide some scenario specifc information that may help interpretation of the error at a later stage. For example, lets say I do a SELECT…INTO looking for details on a specific widget as shown below:

BEGIN
   SELECT ...
   INTO   ...
   FROM   widgets w
   WHERE  w.widget_id = l_widget_id;
EXCEPTION
   WHEN NO_DATA_FOUND THEN
      pkg_err.log_last_err ('Cannot locate widget with ID of ' || l_widget_id);
	  RAISE;
END;

Then my logged exception not only tells me what exception was thrown and where it occurred but also specifically the widget ID that the code was looking for. All this makes for speedy problem resolution.

Once we’ve trapped the exception and logged it then we can do whatever we want; continue as if nothing has happened, re-raise the exception (as shown above) or throw some other sort of exception. I plan on discussing the latter strategy in a future post.


Download scripts shown in this post.

More Concurrency

This article was inspired by a situation that was recently observed in a vendor supplied system I deal with. In a previous article we looked at concurrency handling where we were inserting or updating a row on a table with a simple primary key. These days people want to maintain the history of changes that have been made to their data and one approach to this requirement is to maintain a start and end date for each row. Commonly the entry that is currently in effect wlll not have an end date.

Given a table that implements a versioning strategy via this date stamping approach, our requirement is to create a mechanism to perform a versioning update. Here we will need to update the end date of the existing effective row and insert a new row, which will become the current effective entry. For simplicity, we will assume that we will only ever be inserting a new entry effective from the current system date.

The table used for our example is:

CREATE TABLE test_table
  (pk_id       NUMBER(10)   NOT NULL
  ,id          NUMBER(10)   NOT NULL
  ,start_date  DATE         NOT NULL
  ,end_date    DATE
  ,padding     VARCHAR2(100) NOT NULL
  )
/

-- create the primary key constraint
ALTER TABLE test_table
ADD CONSTRAINT test_table_pk
PRIMARY KEY (pk_id)
/

CREATE SEQUENCE test_table_pk_id_seq
/

You’ll note that the only integrity constraint declared is a surrogate primary key, which is completely useless for imposing any business rule integrity to our data. More on this later. We’ll use the sequence created to populate this column.

Lets turn our attention to performing the required update. As noted before we need to perform two operations for our chosen entity ID; set the end date on the current entry if it exists (i.e. the row that currently has no end date) and create a new entry with a start date from the current system date. Since we’re using DATE data types for the start and end date range, we’ll ensure that the end date used is 1 second less than the start date.

Our script is as follows. We have a simple procedure to handle the update and insert operations that we require. We make sure to use a variable for the effective date so that there won’t be any problem of a delay between the update of the existing entry and the creation of the new one. We commit after each update and introduce a short delay to ensure we aren’t updating the table multiple times within the one second.

SET ECHO ON
SET SERVEROUTPUT ON

DECLARE

PROCEDURE new_version (p_id IN test_table.id%TYPE)
AS
   c_one_second CONSTANT NUMBER := 1/24/60/60;
   l_pk_id      test_table.pk_id%TYPE;
   l_eff_date   DATE;
BEGIN

   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of new_version');
   
   l_eff_date :=  SYSDATE;

   -- end date the current entry to be one second prior 
   -- to the start date of the new entry we will be
   -- creating
   UPDATE test_table
   SET    padding = padding || ', updated by SID ' || SYS_CONTEXT('userenv','sid')
   ,      end_date = l_eff_date - c_one_second
   WHERE  id = p_id
   AND    end_date IS NULL;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After UPDATE');

   INSERT INTO test_table
     (pk_id
     ,id
     ,start_date
     ,end_date
     ,padding)
   VALUES
     (test_table_pk_id_seq.nextval
     ,p_id
     ,l_eff_date
     ,NULL
     ,'Inserted by SID ' || SYS_CONTEXT('userenv','sid'))
   RETURNING pk_id INTO l_pk_id;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After INSERT - created row pk_id ' || TO_CHAR(l_pk_id));
   
   dbms_lock.sleep(10);
   COMMIT;
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of new_version');
   
   
END new_version;

BEGIN
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of test');
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 1');
   new_version (p_id => 1);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 2');
   new_version (p_id => 1);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of test');
END;
/

The following query lists the content of the table, for clarity only showing the time component for the date columns:

SET LINESIZE 132
COLUMN PADDING FORMAT A60

SELECT t.pk_id
,      t.id
,      TO_CHAR(t.start_date,'hh24:mi:ss') AS start_date
,      TO_CHAR(t.end_date,'hh24:mi:ss')   AS end_date
,      t.padding
FROM   test_table t
ORDER  BY
       t.start_date
/	   

If we run this query after executing our script we get:

     PK_ID         ID START_DA END_DATE PADDING
---------- ---------- -------- -------- ---------------------------------------
         1          1 06:49:46 06:49:55 Inserted by SID 141, updated by SID 141
         2          1 06:49:56          Inserted by SID 141

All looks as we would want.

Now let’s see how well concurrency is handled. You’ll have noted that the short delay in the test script is done before the COMMIT. This is deliberate so as to keep the transaction active and allow us to illustrate the concurrency problems with the script. If we run the script from 2 sessions simultaneously and query our table we get:

     PK_ID         ID START_DA END_DATE PADDING
---------- ---------- -------- -------- ---------------------------------------
         1          1 07:02:59 07:03:08 Inserted by SID 149, updated by SID 149
         2          1 07:03:00 07:03:09 Inserted by SID 141, updated by SID 141
         3          1 07:03:09 07:03:09 Inserted by SID 149, updated by SID 141
         4          1 07:03:10          Inserted by SID 141

Hmmm… not exactly what we would want…

We can see that both sessions created an initial entry; one at 7:22:30 and one at 7:32:32. The session with SID 149 then updated the row with PK_ID of 1 and then created the row with PK_ID of 3. The session with SID 141 then updated the end date on the rows with PK_ID of 2 and 3 before creating the last row.

If we run the scripts a second time, after the table has been populated do we continue to have trouble? Let’s see:

     PK_ID         ID START_DA END_DATE PADDING
---------- ---------- -------- -------- ---------------------------------------
         1          1 07:02:59 07:03:08 Inserted by SID 149, updated by SID 149
         2          1 07:03:00 07:03:09 Inserted by SID 141, updated by SID 141
         3          1 07:03:09 07:03:09 Inserted by SID 149, updated by SID 141
         4          1 07:03:10 07:04:37 Inserted by SID 141, updated by SID 149
         5          1 07:04:38 07:04:47 Inserted by SID 149, updated by SID 149
         7          1 07:04:40 07:05:07 Inserted by SID 141, updated by SID 141
         6          1 07:04:48 07:04:39 Inserted by SID 149, updated by SID 141
         8          1 07:05:08          Inserted by SID 141

The problem is still there. We have overlapping date ranges, which will definitely cause trouble when trying to work out which entry was effective at any point in time.

So, what can we do to overcome this. As mentioned at the start of this post, there are no constraints declared on the table to enforce the integrity we’re looking for. Let’s see if we can create one.

Ideally we want a constraint that says “for a given entry, don’t permit the start date to overlap with the start and end dates in any other row and don’t let the end date overlap with the start and end dates in any other row”. Unfortunately it’s not possible to declare such a constraint.

One constraint I have seen people use is to declare uniqueness on the ID and START_DATE. Obviously the thinking is that we don’t want two entries effective from the same point in time for the same ID. However, if you look at the data in our table you will see that it meets this constraint and the data is still wrong. Clearly this constraint is inadequate.

Another possible constraint is to ensure that only a single entry has a NULL end date for a give ID value. This won’t actually prevent all types off errors but it may prevent the problems we are observing above. We can’t declare this as a constraint in Oracle but we can create a unique function-based index to enforce this:

CREATE UNIQUE INDEX test_table_i1
ON test_table (CASE WHEN end_date IS NULL THEN id ELSE NULL END)
/

(Purists will point out that the “ELSE NULL” part is not required in the above CASE expression but I prefer to include it for clarity.)

So, rerunning our scripts in 2 sessions, how does this index impact us? One session completed successfully while the other session gave us the following error:

DECLARE
*
ERROR at line 1:
ORA-00001: unique constraint (DEVELOPER.TEST_TABLE_I1) violated
ORA-06512: at line 25
ORA-06512: at line 51

Line 24 is the INSERT statement. What’s happening here is that the first session has performed its actions and created a new entry with a NULL end date. The second session has performed its UPDATE followed by an INSERT. However, when the first session commits its changes then Oracle flags an error in the second session as the row it has tried to insert violates the unique index we have created.

So, on one hand we managed to prevent data corruption but at the expense of failing one of the transactions. Can we do better?

Given that we need to maintain data integrity over a number of rows and not just within a single row we need to look at different strategies for managing the data. Preventing multiple sessions from manipulating the rows for a given ID will allow a single session to perform its changes safe from interference. In general, serialising access like this should not be taken lightly but at times it may be necessary.

How can we prevent multiple sessions from manipulating the same set of data at at the same time? An obvious solution is to perform a SELECT FOR UPDATE on all the rows for a given ID before we perform our changes. The session that manages to lock the rows will be able to make its changes and any other session is blocked until it is able to obtain the lock. Lets give this a try by running the following script in 2 sessions:

SET ECHO ON
SET SERVEROUTPUT ON

DECLARE

PROCEDURE new_version (p_id IN test_table.id%TYPE)
AS
   CURSOR test_cur (p_cur_id test_table.id%TYPE)
   IS
   SELECT *
   FROM   test_table
   WHERE  id = p_cur_id
   FOR UPDATE;

   c_one_second CONSTANT NUMBER := 1/24/60/60;
   l_pk_id      test_table.pk_id%TYPE;
   l_eff_date   DATE;
BEGIN

   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of new_version');

   -- obtain a lock on all the rows for the given ID by opening
   -- a cursor that returns all the rows for the ID
   OPEN test_cur (p_id);   
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After SELECT FOR UPDATE');
	
   -- we calculate the effective date after we've obtained the locks, not before!	
   l_eff_date := SYSDATE;

   -- end date the current entry to be one second prior 
   -- to the start date of the new entry we will be
   -- creating
   UPDATE test_table
   SET    padding = padding || ', updated by SID ' || SYS_CONTEXT('userenv','sid')
   ,      end_date = l_eff_date - c_one_second
   WHERE  id = p_id
   AND    end_date IS NULL;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After UPDATE');

   INSERT INTO test_table
     (pk_id
     ,id
     ,start_date
     ,end_date
     ,padding)
   VALUES
     (test_table_pk_id_seq.nextval
     ,p_id
     ,l_eff_date
     ,NULL
     ,'Inserted by SID ' || SYS_CONTEXT('userenv','sid'))
   RETURNING pk_id INTO l_pk_id;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After INSERT - created row pk_id ' || TO_CHAR(l_pk_id));
   
   dbms_lock.sleep(10);
   COMMIT;
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of new_version');
   
   
END new_version;

BEGIN
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of test');
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 1');
   new_version (p_id => 2);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 2');
   new_version (p_id => 2);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of test');
END;
/

Both scripts executed successfully and the table shows:

     PK_ID         ID START_DA END_DATE PADDING
---------- ---------- -------- -------- ---------------------------------------
         1          2 07:12:33 07:12:42 Inserted by SID 149, updated by SID 149
         2          2 07:12:34 07:12:52 Inserted by SID 141, updated by SID 141
         3          2 07:12:43 07:12:52 Inserted by SID 149, updated by SID 141
         4          2 07:12:53          Inserted by SID 141

Oh, that’s not right though. The cause of the problem is probably clear; both sessions initially created new rows as the SELECT FOR UPDATE had no rows to lock so we didn’t get the serialisation that we wanted. Can we solve this? If we had a table that held the domain of IDs, i.e. one row per ID, then we could potentially lock that row. Whichever session held the lock would be able to make changes to the date versioned entries. Lacking this though we can create our own lock using DBMS_LOCK. With DBMS_LOCK we can “lock” a string value. If the value is constructed to reflect the ID that we’re updating then whichever session is able to lock that string is able to make the changes to the table. The script below illustrates this:

SET ECHO ON
SET SERVEROUTPUT ON

DECLARE

PROCEDURE new_version (p_id IN test_table.id%TYPE)
AS
   c_one_second CONSTANT NUMBER := 1/24/60/60;
   l_pk_id      test_table.pk_id%TYPE;
   l_eff_date   DATE;
   l_lockhandle VARCHAR2(100);
   l_lock       NUMBER;
BEGIN

   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of new_version');

   -- obtain a lock on a string that reflects the ID 
   dbms_lock.allocate_unique (lockname    => 'TEST_TABLE_ID_' || TO_CHAR(p_id)
                             ,lockhandle  => l_lockhandle);
   l_lock := dbms_lock.request (lockhandle        => l_lockhandle
--                               ,lockmode          => dbms_lock.x_mode
--                               ,timeout           => dbms_lock.maxwait
                               ,release_on_commit => TRUE);
	
   -- we calculate the ffective date after we've obtained the lock, not before!	
   l_eff_date := SYSDATE;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After DMBS_LOCK');

   -- end date the current entry to be one second prior 
   -- to the start date of the new entry we will be
   -- creating
   UPDATE test_table
   SET    padding = padding || ', updated by SID ' || SYS_CONTEXT('userenv','sid')
   ,      end_date = l_eff_date - c_one_second
   WHERE  id = p_id
   AND    end_date IS NULL;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After UPDATE');

   INSERT INTO test_table
     (pk_id
     ,id
     ,start_date
     ,end_date
     ,padding)
   VALUES
     (test_table_pk_id_seq.nextval
     ,p_id
     ,l_eff_date
     ,NULL
     ,'Inserted by SID ' || SYS_CONTEXT('userenv','sid'))
   RETURNING pk_id INTO l_pk_id;
   
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - After INSERT - created row pk_id ' || TO_CHAR(l_pk_id));
   
   dbms_lock.sleep(10);
   COMMIT;
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of new_version');
   
   
END new_version;

BEGIN
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Start of test');
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 1');
   new_version (p_id => 2);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - Create version 2');
   new_version (p_id => 2);
   dbms_output.put_line (TO_CHAR(SYSTIMESTAMP,'hh:mi:ss.ff3') || ' - End of test');
END;
/

Looking at the table data after we run the script in 2 sessions simultaneously, we see:

     PK_ID         ID START_DA END_DATE PADDING
---------- ---------- -------- -------- ---------------------------------------
         1          2 07:23:18 07:23:27 Inserted by SID 149, updated by SID 141
         2          2 07:23:28 07:23:37 Inserted by SID 141, updated by SID 149
         3          2 07:23:38 07:23:47 Inserted by SID 149, updated by SID 141
         4          2 07:23:48          Inserted by SID 141

Success! We can see that the two sessions took it in turns to create a new entry, end dating the previous entry created by the other session. The lock worked as expected. The serialisation of access isn’t without its downfalls. Most obvious, if the data is subject to a high frequency of update then permitting only one session at a time to make changes may result in unacceptable delays. However, if this were the case then I would probably argue that the data structure is inappropriate.

In this post we’ve seen that the lack of declarative contraints makes it easy for concurrent changes to corrupt the structure that we were expecting within our data. For this example we had to resort to a programmatic locking strategy to serialise modification of the data to avoid the concurrency problems. Not necessarily the best of strategies but one that may need to be applied when no other options are available.