Analyzing Deadlocks – the new way

The section titled “To Format the Output to a Flat File” was updated on 2/13/2012.
Edit on 12/11/2014: This new method of analyzing locking issues became available in DB2 9.7.
Edit on 09/29/2016: Correction to the SQL for counting statements when context data is collected. Also formatted the SQL statements to be easier to read.

So you can still use the old way, and if you want to avoid event monitors that write to tables, that’s still the only way. See Analyzing Deadlocks – the old way for more details on that method.

This new method is not yet enabled by default, but I would expect it would be in a future release. The pattern I’ve seen IBM follow is that in one version, they introduce a new way of doing something and deprecate the old way. In the next version, they generally make the new way the default, requiring you to take more drastic actions to keep using the old one. Then in the following version, they remove the ability to use the old method. Sometimes they allow more than one version to pass in each of those steps, but it sure seems likely that’s the general direction they’re going now.

I haven’t actually done all that much with this in production, though I’m in the process of doing so now, so I don’t have a strong opinion which is better while we have the choice.

Creating the Event Monitor

So first you’ll want to be creating the table for this in a 32k tablespace. So assuming you don’t already have one, you need to do this:

Create the 32k bufferpool (if you’re working with WebSphere Commerce, this exists out of the box, but you still need to run the last two commands):

db2 "CREATE BUFFERPOOL BUFF32K IMMEDIATE SIZE 2500 AUTOMATIC PAGESIZE 32 K"

Create a 32k tablespace (using AST) – only needed if you don’t already have one you want to use for this:

db2 "create large tablespace TAB32K pagesize 32 K bufferpool BUFF32K dropped table recovery on"

Create a 32k temp tablespace (using AST) – only needed if you don’t already have one:

db2 "CREATE SYSTEM TEMPORARY TABLESPACE TEMPSYS32K PAGESIZE 32 K BUFFERPOOL BUFF32K"

Create the Event Monitor for Locks:

>db2 "create event monitor my_locks for locking write to unformatted event table (table dba.my_locks in TAB32K) autostart"
DB20000I  The SQL command completed successfully.
> db2 "set event monitor MY_LOCKS state=1"
DB20000I  The SQL command completed successfully.

Then verify that the event monitor has the correct state:

> db2 "select substr(evmonname,1,30) as evmonname, EVENT_MON_STATE(evmonname) as state from syscat.eventmonitors where evmonname='MY_LOCKS' with ur"

EVMONNAME                      STATE
------------------------------ -----------
MY_LOCKS                                1

  1 record(s) selected.

1 means active, so that’s what we want. 0 means not active.

Setting the Collection Parameters

So this was new to me. In addition to create the event monitor for locks, you also have to enable collection of information in the database configuration or at the workload level. I’m not used to working at the workload level, so I’ll go with what makes more sense to me and give you the parameters to set at the database level.

MON_LOCKTIMEOUT

Changes to this parameter should take effect without a database recycle. By default, this parameter is set to “NONE”. Possible values include:

• NONE – no data is collected on lock timeouts (DEFAULT)
• WITHOUT_HIST – data about lock timeout events is sent to any active event monitor tracking locking events
• HISTORY – the last 250 activities performed in the same UOW are tracked by event monitors tracking locking events, in addition to the data about lock timeout events.
• HIST_AND_VALUES – In addition to the the last 250 activities perfromed in the same UOW and the data about lock timeout events, values that are not long or xml data are also sent to any active event monitor tracking locking events

> db2 update db cfg for dbname using MON_LOCKTIMEOUT WITHOUT_HIST immediate
DB20000I  The UPDATE DATABASE CONFIGURATION command completed successfully.

MON_DEADLOCK

The values here are similar to those for MON_LOCKTIMEOUT, however, the default is different. The default here is WITHOUT_HIST. all possible values include:

• NONE – no data is collected on deadlocks
• WITHOUT_HIST – data about deadlock events is sent to any active event monitor tracking locking events (DEFAULT)
• HISTORY – the last 250 activities performed in the same UOW are tracked by event monitors tracking locking events, in addition to the data about deadlock events.
• HIST_AND_VALUES – In addition to the the last 250 activities perfromed in the same UOW and the data about deadlock events, values that are not long or xml data are also sent to any active event monitor tracking locking events

MON_LOCKWAIT

This has essentially the same options as the last two. By default, this parameter is set to “NONE”. Possible values include:

• NONE – no data is collected on lock waits (DEFAULT)
• WITHOUT_HIST – data about lock wait events is sent to any active event monitor tracking locking events
• HISTORY – the last 250 activities performed in the same UOW are tracked by event monitors tracking locking events, in addition to the data about lock wait events.
• HIST_AND_VALUES – In addition to the the last 250 activities perfromed in the same UOW and the data about lock wait events, values that are not long or xml data are also sent to any active event monitor tracking locking events

MON_LW_THRESH

The default here is 5 seconds (5,000,000). For whatever reason, this is specified in microseconds (one million to the second). I certainly wouldn’t recommend setting this too low. This parameter only means something if MON_LOCKWAIT is set to something other than NONE.

MON_LCK_MSG_LVL

This parameter indicates what events will be logged to the notify log. Not being a big fan of the notify log, I’m not sure how much I’d use this, but here are the possible values:

• 0 – No notification of locking phenomena is done, including deadlocks, lock escalations, and lock timeouts
• 1 – Notification of only lock escalations is done – notifications are not done for deadlocks or lock timeouts
• 2 – Notification of lock escalations and deadlocks are done – no notification of lock timeouts is done
• 3 – Notification is done for lock escalations, deadlocks, and lock timeouts

> db2 update db cfg for dbname using MON_LCK_MSG_LVL 2 immediate
DB20000I  The UPDATE DATABASE CONFIGURATION command completed successfully.

Parsing/Analyzing Output

So that last bit was the easy part. That gets you basic collection of the data you need, in an unformated way. Now you have to format the data and make sense of it. You can format the data either to a flat file or to tables. If you have severe locking issues, go for flat file to eliminate additional database load. If your locking issues are more moderate and you still have available capacity on your database server, go with the tables – they’re easier to query and summarize.

Getting output in human-readable format

To format the output to a flat file:

This section updated 2/13/2012.

I have, as yet, been unable to test this method, as the samples referenced everywhere are missing from every 9.7 installation I have. I hope to update this portion of this post in the future when I get this figured out.

I had a bear of a time getting this to work. I started with the instructions in this technical article: http://www.ibm.com/developerworks/data/library/techarticle/dm-1004lockeventmonitor/

But that post references files that were missing from every 9.7 installation I have(over a dozen different servers on at least two different flavors of Linux). I asked a colleage who works on a wider variety of systems, and they did not have the same issue. So I have no idea what the deal is here, but there must be someone else in the same place as me, looking at the directories and doing find commands and so on with no results. Here’s how I finally made it work.

Make the directory $HOME/bin if you don’t already have it

mkdir $HOME/bin

Add to your path $HOME/bin:$HOME/sqllib/java/jdk64/bin (substituting your instance home directory for $HOME). Here’s the syntax I used for that:

export PATH=$PATH:/db2home/db2inst1/bin:/db2home/db2inst1/sqllib/java/jdk64/bin

Into a file in $HOME/bin called db2evmonfmt.java, copy the content from this link: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/index.jsp?topic=%2Fcom.ibm.db2.luw.apdv.sample.doc%2Fdoc%2Fjava_jdbc%2Fs-db2evmonfmt-java.html

Install db2 on your laptop or a windows system and copy C:\Program Files\IBM\SQLLIB_01\samples\java\jdbc\DB2EvmonLocking.xsl to $HOME/bin. I could not find DB2EvmonLocking.xsl online anywhere, and I don’t want to get myself on the wrong side of IBM legally by posting it myself, so if anyone reads this at IBM, I urge you to make this file available through the info center too.

Compile db2evmonfmt.java using this as the db2instance owner from the $HOME/bin directory:

javac db2evmonfmt.java

java db2evmonfmt -d sample -ue DBA.MY_LOCKS -ftext

Where the database name replaces ‘sample’, and the unformatted event monitory table name is “DBA.MY_LOCKS”.

The output’s not bad, overall – I think more useful than the db2detaildeadlock formatted output that we got with the old method. The output you get looks like this:

> java db2evmonfmt -d sample -ue DBA.MY_LOCKS -ftext
SELECT evmon.xmlreport FROM TABLE ( EVMON_FORMAT_UE_TO_XML( 'LOG_TO_FILE',FOR EACH ROW OF ( SELECT * FROM DBA.ROS_LOCKS  ORDER BY EVENT_ID, EVENT_TIMESTAMP, EVENT_TYPE, MEMBER ))) AS evmon

-------------------------------------------------------
Event ID               : 1
Event Type             : LOCKTIMEOUT
Event Timestamp        : 2012-02-07-12.52.54.529330
Partition of detection : 0
-------------------------------------------------------

Participant No 1 requesting lock
----------------------------------
Lock Name            : 0x03002900000000000000000054
Lock wait start time : 2012-02-07-12.52.09.070093
Lock wait end time   : 2012-02-07-12.52.54.529330
Lock Type            : TABLE
Lock Specifics       :
Lock Attributes      : 00000000
Lock mode requested  : Intent Exclusive
Lock mode held       : Exclusive
Lock Count           : 0
Lock Hold Count      : 0
Lock rrIID           : 0
Lock Status          : Converting
Lock release flags   : 40000000
Tablespace TID       : 3
Tablespace Name      : TAB8K
Table FID            : 41
Table Schema         : WSCOMUSR
Table Name           : STAGLOG

Attributes            Requester                       Owner
--------------------- ------------------------------  ------------------------------
Participant No        1                               2
Application Handle    030682                          030734
Application ID        REDACTED                        REDACTED
Application Name      db2bp                           db2jcc_application
Authentication ID     REDACTED                        REDACTED
Requesting AgentID    1728                            1385
Coordinating AgentID  1728                            1385
Agent Status          UOW Executing                   UOW Waiting
Application Action    No action                       No action
Lock timeout value    45                              0
Lock wait value       0                               0
Workload ID           1                               1
Workload Name         SYSDEFAULTUSERWORKLOAD          SYSDEFAULTUSERWORKLOAD
Service subclass ID   13                              13
Service subclass      SYSDEFAULTSUBCLASS              SYSDEFAULTSUBCLASS
Current Request       Execute Immediate               Execute
TEntry state          2                               2
TEntry flags1         00000000                        00000000
TEntry flags2         00000200                        00000200
Lock escalation       no                              no
Client userid
Client wrkstnname                                     REDACTED
Client applname
Client acctng

Current Activities of Participant No 1
----------------------------------------
Activity ID        : 1
Uow ID             : 14
Package Name       : SQLC2H21
Package Schema     : NULLID
Package Version    :
Package Token      : AAAAAPAa
Package Sectno     : 203
Reopt value        : none
Incremental Bind   : no
Eff isolation      : CS
Eff degree         : 0
Eff locktimeout    : 45
Stmt first use     : 2012-02-07-12.31.06.297485
Stmt last use      : 2012-02-07-12.31.06.297485
Stmt unicode       : no
Stmt query ID      : 0
Stmt nesting level : 0
Stmt invocation ID : 0
Stmt source ID     : 0
Stmt pkgcache ID   : 1069446856888
Stmt type          : Dynamic
Stmt operation     : DML, Insert/Update/Delete
Stmt text          : delete from attr where attr_id >= 7000000000000000001 and attr_id <= 7000000000000000020

To format the output to tables (to tables in the ‘DBA’ schema for our example):

> db2 "call EVMON_FORMAT_UE_TO_TABLES ('LOCKING', NULL, NULL, NULL, 'DBA', NULL, NULL, -1, 'SELECT * FROM DBA.MY_LOCKS ORDER BY event_timestamp')"

  Return Status = 0

If you receive this error:

SQL0171N  The data type, length or value of the argument for the parameter in
position "3 (query) " of routine "XDB_DECOMP_XML_FROM_QUERY" is incorrect.
Parameter name: "".  SQLSTATE=42815

check to make sure that you’ve specified the right values for the type of event monitor, the schema where the tables should be created, and the table name the event monitor is writing to. Also check to make sure you have the appropriately sized system temporary tablespace, as an order-by on the un-formatted event monitor table will fail without it.

Assuming this is the first time you’ve run EVMON_FORMAT_UE_TO_TABLES, you’ll see a number of new tables:

LOCK_ACTIVITY_VALUES
LOCK_EVENT
LOCK_PARTICIPANTS
LOCK_PARTICIPANT_ACTIVITIES

Some interesting SQL to help you navigate the output in tables

Please first note that this SQL is tested only for functionality and not for performance – I haven’t explained it or done any optimization on it, so expect it to run poorly for large amounts of data.

First to list all of the locking events:

select event_id
    , substr(event_type,1,18) as event_type
    , event_timestamp, dl_conns
    , rolled_back_participant_no 
from DBA.LOCK_EVENT 
order by event_id
    , event_timestamp 
with ur

EVENT_ID             EVENT_TYPE         EVENT_TIMESTAMP            DL_CONNS    ROLLED_BACK_PARTICIPANT_NO
-------------------- ------------------ -------------------------- ----------- --------------------------
                   1 DEADLOCK           2012-01-23-15.36.56.036831           2                          2
                   1 DEADLOCK           2012-01-23-15.36.56.036831           2                          2
                   2 LOCKTIMEOUT        2012-01-23-15.43.06.875032           -                          -
                   2 LOCKTIMEOUT        2012-01-23-15.43.06.875032           -                          -

  4 record(s) selected.

To summarize counts

select substr(event_type,1,18) as event_type
    , count(*) as count
    , sum(dl_conns) sum_involved_connections 
from DBA.LOCK_EVENT 
group by event_type 
with ur

EVENT_TYPE         COUNT       SUM_INVOLVED_CONNECTIONS
------------------ ----------- ------------------------
DEADLOCK                     2                        4
LOCKTIMEOUT                  2                        -

  2 record(s) selected.

To summarize counts by hour

select substr(event_type,1,18) as event_type
    , year(event_timestamp) as year
    , month(event_timestamp) as month
    , day(event_timestamp) as day
    , hour(event_timestamp) as hour
    , count(*) as count 
from DBA.LOCK_EVENT 
group by year(event_timestamp)
    , month(event_timestamp)
    , day(event_timestamp)
    , hour(event_timestamp)
    , event_type 
order by year(event_timestamp)
    , month(event_timestamp)
    , day(event_timestamp)
    , hour(event_timestamp)
    , event_type 
with ur
EVENT_TYPE         YEAR        MONTH       DAY         HOUR        COUNT
------------------ ----------- ----------- ----------- ----------- -----------
DEADLOCK                  2012           1          23          15           2
LOCKTIMEOUT               2012           1          23          15           2

  2 record(s) selected.

To summarize by table and lock event type:

select substr(lp.table_schema,1,18) as table_schema
    , substr(lp.table_name,1,30) as table_name
    , substr(le.event_type,1,18) as lock_event
    , count(*)/2 as count 
from DBA.LOCK_PARTICIPANTS lp, DBA.LOCK_EVENT le 
where lp.xmlid=le.xmlid 
group by lp.table_schema, lp.table_name, le.event_type 
order by lp.table_schema, lp.table_name, le.event_type 
with ur

TABLE_SCHEMA       TABLE_NAME                     LOCK_EVENT         COUNT
------------------ ------------------------------ ------------------ -----------
DB2INST1           INVENTORY                      DEADLOCK                     2
DB2INST1           PURCHASEORDER                  DEADLOCK                     2
DB2INST1           PURCHASEORDER                  LOCKTIMEOUT                  2
-                  -                              LOCKTIMEOUT                  2

  4 record(s) selected.

If you want to only look at deadlocks or lock timeouts, it is easy to add a where clause on event_type to these queries.

To summarize by statement:

with t1 as (
    select STMT_PKGCACHE_ID as STMT_PKGCACHE_ID
        , count(*) as stmt_count 
    from dba.lock_participant_activities 
    where activity_type='current' 
    group by STMT_PKGCACHE_ID) 
select t1.stmt_count
    , (select substr(STMT_TEXT,1,100) as stmt_text 
        from dba.lock_participant_activities a1 
        where a1.STMT_PKGCACHE_ID=t1.STMT_PKGCACHE_ID 
        fetch first 1 row only) 
from t1 order by t1.stmt_count desc 
with ur

STMT_COUNT  STMT_TEXT
----------- ----------------------------------------------------------------------------------------------------
          4 update db2inst1.purchaseorder set ORDERDATE=current timestamp - 7 days where POID='5000'
          2 update db2inst1.INVENTORY set QUANTITY= QUANTITY+5 where PID='100-101-01'

  2 record(s) selected.

The substr on stmt_text in the above statement is included for readability only – I would recommend removing that substr when actually using this SQL.

If you want to do the same thing, counting only statements invloved in deadlocks, try this:

with t1 as (
    select STMT_PKGCACHE_ID as STMT_PKGCACHE_ID
        , count(*) as stmt_count 
    from dba.lock_participant_activities 
    where XMLID like '%DEADLOCK%' 
        and activity_type='current' 
    group by STMT_PKGCACHE_ID) 
select t1.stmt_count
    , (select substr(STMT_TEXT,1,100) as stmt_text 
        from dba.lock_participant_activities a1 
        where a1.STMT_PKGCACHE_ID=t1.STMT_PKGCACHE_ID 
        fetch first 1 row only) 
from t1 with ur 

STMT_COUNT  STMT_TEXT
----------- ----------------------------------------------------------------------------------------------------
          2 update db2inst1.purchaseorder set ORDERDATE=current timestamp - 7 days where POID='5000'
          2 update db2inst1.INVENTORY set QUANTITY= QUANTITY+5 where PID='100-101-01'

  2 record(s) selected.

References

Statement on deprication of event monitor for detaildeadlocks: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/topic/com.ibm.db2.luw.wn.doc/doc/i0054715.html

Syntax for creating lock event monitor: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/topic/com.ibm.db2.luw.sql.ref.doc/doc/r0054074.html

Syntax for EVMON_FORMAT_UE_TO_TABLES: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/topic/com.ibm.db2.luw.sql.rtn.doc/doc/r0054910.html

Reference on tables data is written to: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/topic/com.ibm.db2.luw.admin.mon.doc/doc/r0055559.html

Good article on this topic on DW: http://www.ibm.com/developerworks/data/library/techarticle/dm-1004lockeventmonitor/ – this also has descriptions of how to artificially create a deadlock on the sample database for testing purposes, but doesn’t include SQL to parse the output if you write the formatted data out to tables.

• Author Details

Ember Crooks

https://datageek.blog/

ember.crooks@gmail.com

Ember is always curious and thrives on change. She has built internationally recognized expertise in IBM Db2, and is now pivoting to focus on learning MySQL. Ember shares both posts about her core skill set and her journey learning MySQL. Ember lives in Denver and work from home