Results 1 to 7 of 7
  1. #1
    Join Date
    Aug 2013
    Posts
    4

    Question Unanswered: NS lock blocking others

    Hi there,

    My database (V9.5) hit a locking problem that I cannot figure out how it happened.

    From the snapshot, my database had a chain of locks like this:

    Locks being waited on :
    AppHandl [nod-index] TranHdl Lockname Type Mode Conv Sts CoorEDU
    24150 [000-24150] 39 000300870000000505F4000352 Row .NS G 4414
    24554 [000-24554] 99 000300870000000505F4000352 Row ..U ..X C 4289
    25034 [000-25034] 97 000300870000000505F4000352 Row .NS W 7272
    24677 [000-24677] 89 000300870000000505F4000352 Row .NS W 4689
    25152 [000-25152] 82 000300870000000505F4000352 Row .NS W 7776
    25225 [000-25225] 12 000300870000000505F4000352 Row .NS W 8795
    24789 [000-24789] 78 000300870000000505F4000352 Row .NS W 4711
    25264 [000-25264] 118 000300870000000505F4000352 Row .NS W 7269
    25285 [000-25285] 41 000300870000000505F4000352 Row .NS W 4700
    24500 [000-24500] 69 000300870000000505F4000352 Row .NS W 4550
    25505 [000-25505] 59 000300870000000505F4000352 Row .NS W 7777
    25479 [000-25479] 11 000300870000000505F4000352 Row .NS W 63
    29467 [000-29467] 211 000300870000000505F4000352 Row .NS W 8914
    29361 [000-29361] 178 000300870000000505F4000352 Row .NS W 4325
    30202 [000-30202] 263 000300870000000505F4000352 Row .NS W 9044
    30196 [000-30196] 255 000300870000000505F4000352 Row .NS W 9035
    30088 [000-30088] 207 000300870000000505F4000352 Row .NS W 8879
    30379 [000-30379] 243 000300870000000505F4000352 Row .NS W 9074
    30373 [000-30373] 276 000300870000000505F4000352 Row .NS W 9057
    29980 [000-29980] 249 000300870000000505F4000352 Row .NS W 8950
    30457 [000-30457] 330 000300870000000505F4000352 Row .NS W 9118
    30251 [000-30251] 430 000300870000000505F4000352 Row .NS W 9230
    19422 [000-19422] 392 000300870000000505F4000352 Row .NS W 9181


    One NS lock held for a long time and blocked an updated statement and that update statement blocked other select statements. The first granted NS lock did not release.

    The isolation level is CS while the lock timeout is -1.

    However, I have checked the application handle (24150), the UOW status is WAITING.
    Cannot figure out what was happening on that NS lock.

    What kind of concurrent situation(s) will end up such unreleased NS lock?


    Thanks in advance.
    Last edited by kyl; 08-28-13 at 06:17.

  2. #2
    Join Date
    Apr 2006
    Location
    Belgium
    Posts
    2,514
    Provided Answers: 11
    all locks should be released with a commit
    uow waiting just means, control has been given to the application.....
    Best Regards, Guy Przytula
    Database Software Consultant
    Good DBAs are not formed in a week or a month. They are created little by little, day by day. Protracted and patient effort is needed to develop good DBAs.
    Spoon feeding : To treat (another) in a way that discourages independent thought or action, as by overindulgence.
    DB2 UDB LUW Certified V7-V8-V9-V9.7-V10.1-V10.5 DB Admin - Advanced DBA -Dprop..
    Information Server Datastage Certified
    http://www.infocura.be

  3. #3
    Join Date
    Aug 2013
    Posts
    4
    The application (24150) holding the NS lock was a SELECT statement.
    (i.e. the one and only one active statement according to the snapshot)

    Can it not release the lock after the query complete?

  4. #4
    Join Date
    Jul 2013
    Location
    Moscow, Russia
    Posts
    666
    Provided Answers: 55
    Hi,

    May be this application has uncommitted changes?
    What's the result of:
    Code:
    select SQL_REQS_SINCE_COMMIT from sysibmadm.snapappl where agent_id=24150
    If you have an active event monitor for deadlocks you can get all statements in the current transaction by
    db2pd -db mydb -api 24150

    Also even after commit you may have some open cursors with hold option which may have locks.
    Regards,
    Mark.

  5. #5
    Join Date
    Aug 2013
    Posts
    4
    The database was restarted. I have snapshot taken before the restart.

    Extract from the db2pd output:
    ---------------------------------------------------------------------------
    Lock timeout (seconds) = -1
    Locks held by application = 5
    Lock waits since connect = 1
    Time application waited on locks (ms) = 3
    Deadlocks detected = 0
    Lock escalations = 0
    Exclusive lock escalations = 0
    Number of Lock Timeouts since connected = 0
    Total time UOW waited on locks (ms) = 0

    ...

    Number of SQL requests since last commit = 1114
    Commit statements = 1277
    Rollback statements = 0
    Dynamic SQL statements attempted = 5111
    Static SQL statements attempted = 1277
    Failed statement operations = 0
    Select SQL statements executed = 2290
    Xquery statements executed = 0
    Update/Insert/Delete statements executed = 122
    DDL statements executed = 0
    Inactive stmt history memory usage (bytes) = 0
    Internal automatic rebinds = 0
    Internal rows deleted = 0
    Internal rows inserted = 0
    Internal rows updated = 0
    Internal commits = 1
    Internal rollbacks = 0
    Internal rollbacks due to deadlock = 0
    Binds/precompiles attempted = 0
    Rows deleted = 9
    Rows inserted = 47
    Rows updated = 66
    Rows selected = 9485
    Rows read = 601391
    Rows written = 12282

    UOW log space used (Bytes) = 0
    Previous UOW completion timestamp = 08/21/2013 17:33:55.191653
    Elapsed time of last completed uow (sec.ms)= 0.059356
    UOW start timestamp = 08/21/2013 17:34:05.044810
    UOW stop timestamp =
    UOW completion status =

    Open remote cursors = 0
    Open remote cursors with blocking = 0
    Rejected Block Remote Cursor requests = 6
    Accepted Block Remote Cursor requests = 2284
    Open local cursors = 1
    Open local cursors with blocking = 1
    Total User CPU Time used by agent (s) = 23.790072
    Total System CPU Time used by agent (s) = 2.261134
    Host execution elapsed time = 409.710527

    ...

    Most recent operation = Close
    Cursor name = SQL_CURSH200C4
    Most recent operation start timestamp = 08/21/2013 18:23:56.931081
    Most recent operation stop timestamp = 08/21/2013 18:23:56.931271
    Agents associated with the application = 1
    Number of hash joins = 319
    Number of hash loops = 0
    Number of hash join overflows = 0
    Number of small hash join overflows = 0
    Number of OLAP functions = 0
    Number of OLAP function overflows = 0


    Statement type = Dynamic SQL Statement
    Statement = Close
    Section number = 4
    Application creator = NULLID
    Package name = SYSSH200
    Consistency Token =
    Package Version ID =
    Cursor name = SQL_CURSH200C4
    Statement database partition number = 0
    Statement start timestamp = 08/21/2013 18:23:56.931081
    Statement stop timestamp = 08/21/2013 18:23:56.931271
    Elapsed time of last completed stmt(sec.ms)= 0.000011
    Total Statement user CPU time = 0.000051
    Total Statement system CPU time = 0.000126
    SQL compiler cost estimate in timerons = 26
    SQL compiler cardinality estimate = 1
    Degree of parallelism requested = 1
    Number of agents working on statement = 1
    Number of subagents created for statement = 1
    Statement sorts = 0
    Total sort time = 0
    Sort overflows = 0
    Rows read = 0
    Rows written = 0
    Rows deleted = 0
    Rows updated = 0
    Rows inserted = 0
    Rows fetched = 0
    Buffer pool data logical reads = 0
    Buffer pool data physical reads = 0
    Buffer pool temporary data logical reads = 0
    Buffer pool temporary data physical reads = 0
    Buffer pool index logical reads = 2
    Buffer pool index physical reads = 2
    Buffer pool temporary index logical reads = 0
    Buffer pool temporary index physical reads = 0
    Buffer pool xda logical reads = 0
    Buffer pool xda physical reads = 0
    Buffer pool temporary xda logical reads = 0
    Buffer pool temporary xda physical reads = 0
    Blocking cursor = YES
    Dynamic SQL statement text:
    select * from item where ............... fetch first 1000 rows only for read only

    Statement type = Dynamic SQL Statement
    Statement = Fetch
    Section number = 2
    Application creator = NULLID
    Package name = SYSSH200
    Consistency Token =
    Package Version ID =
    Cursor name = SQL_CURSH200C2
    Statement database partition number = 0
    Statement start timestamp = 08/21/2013 17:34:05.113272
    Statement stop timestamp = 08/21/2013 17:34:12.090638
    Elapsed time of last completed stmt(sec.ms)= 6.977312
    Total Statement user CPU time = 0.240852
    Total Statement system CPU time = 0.070727
    SQL compiler cost estimate in timerons = 34433
    SQL compiler cardinality estimate = 1
    Degree of parallelism requested = 1
    Number of agents working on statement = 1
    Number of subagents created for statement = 1
    Statement sorts = 1
    Total sort time = 872
    Sort overflows = 0
    Rows read = 8192
    Rows written = 0
    Rows deleted = 0
    Rows updated = 0
    Rows inserted = 0
    Rows fetched = 26
    Buffer pool data logical reads = 6552
    Buffer pool data physical reads = 1567
    Buffer pool temporary data logical reads = 0
    Buffer pool temporary data physical reads = 0
    Buffer pool index logical reads = 8837
    Buffer pool index physical reads = 39
    Buffer pool temporary index logical reads = 0
    Buffer pool temporary index physical reads = 0
    Buffer pool xda logical reads = 0
    Buffer pool xda physical reads = 0
    Buffer pool temporary xda logical reads = 0
    Buffer pool temporary xda physical reads = 0
    Blocking cursor = YES
    Dynamic SQL statement text:
    select * from workorder where ......... for read only

    Memory usage for application:

    Memory Pool Type = Application Heap
    Current size (bytes) = 131072
    High water mark (bytes) = 327680
    Configured size (bytes) = 8388608

    Agent process/thread ID = 4414
    Agent Lock timeout (seconds) = -1
    Memory usage for agent:

    Memory Pool Type = Other Memory
    Current size (bytes) = 917504
    High water mark (bytes) = 1179648
    Configured size (bytes) = 16994992128

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

    The above information has some contradiction. Which one is the last UOW of the application?
    - The one started at 21/8/2013 17:34:05 , or
    - The one started at 08/21/2013 18:23:56 ??

  6. #6
    Join Date
    Jul 2013
    Location
    Moscow, Russia
    Posts
    666
    Provided Answers: 55
    Quote Originally Posted by kyl View Post
    The above information has some contradiction. Which one is the last UOW of the application?
    - The one started at 21/8/2013 17:34:05 , or
    - The one started at 08/21/2013 18:23:56 ??
    It doesn't matter which one was the latest.
    This application had quite large transaction:
    Code:
    Number of SQL requests since last commit = 1114
    and it seems that someone forgot to close this cursor with hold:
    Code:
    Statement type = Dynamic SQL Statement
    Statement = Fetch
    Application creator = NULLID
    Package name = SYSSH200
    Statement start timestamp = 08/21/2013 17:34:05.113272
    Statement stop timestamp = 08/21/2013 17:34:12.090638
    Elapsed time of last completed stmt(sec.ms)= 6.977312
    Rows fetched = 26
    Dynamic SQL statement text:
    select * from workorder where ......... for read only
    The statement itself completed quickly, but the cursor was not closed and the statement is still active.
    Also we know nothing about these 1114 statements of the transaction.
    There might be other statements with RS or RR isolation which were not already active but could create some locks.
    Regards,
    Mark.

  7. #7
    Join Date
    Aug 2013
    Posts
    4
    Quote Originally Posted by mark.b View Post
    It doesn't matter which one was the latest.
    This application had quite large transaction:
    Code:
    Number of SQL requests since last commit = 1114
    and it seems that someone forgot to close this cursor with hold:
    Code:
    Statement type = Dynamic SQL Statement
    Statement = Fetch
    Application creator = NULLID
    Package name = SYSSH200
    Statement start timestamp = 08/21/2013 17:34:05.113272
    Statement stop timestamp = 08/21/2013 17:34:12.090638
    Elapsed time of last completed stmt(sec.ms)= 6.977312
    Rows fetched = 26
    Dynamic SQL statement text:
    select * from workorder where ......... for read only
    The statement itself completed quickly, but the cursor was not closed and the statement is still active.
    Also we know nothing about these 1114 statements of the transaction.
    There might be other statements with RS or RR isolation which were not already active but could create some locks.

    How to know whether that NS lock is originated from previous statements or the active statement?
    Can I?

    --------------------------------------------------------------------------------
    Application :
    Address : 0xC00000001A5B63C0
    AppHandl [nod-index] : 24150 [000-24150]
    TranHdl : 39
    Application PID : 0
    Application Node Name : app01
    IP Address: xxx.xxx.xxx.xxx
    Connection Start Time : (1377070682)Wed Aug 21 15:38:02 2013
    Client User ID : n/a
    System Auth ID : MAXIMO
    Coordinator EDU ID : 4414
    Coordinator Partition : 0
    Number of Agents : 1
    Locks timeout value : NotSet
    Locks Escalation : No
    Workload ID : 1
    Workload Occurrence ID : 22914
    Trusted Context : n/a
    Connection Trust Type : non trusted
    Role Inherited : n/a
    Application Status : UOW-Waiting
    Application Name : db2jcc_application
    Application ID : xxx.xxx.xxx.xxx.49953.1308210738
    ClientUserID : n/a
    ClientWrkstnName : app01
    ClientApplName : n/a
    ClientAccntng : n/a

    List of active statements :
    UOW-ID : 1278
    Activity ID : 1
    Package Schema : NULLID
    Package Name : SYSSH200
    Package Version :
    Section Number : 2
    SQL Type : Dynamic
    Isolation : CS
    Statement Type : DML, Select (blockable)
    Statement : select * from workorder
    where ....... for read only

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

Tags for this Thread

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •