You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Bergquist, Brett" <BB...@canoga.com> on 2015/09/02 23:19:03 UTC
Need help understanding a database deadlock that was detected
Derby 10.9.1.0
Here is the output from the derby.log:
Wed Sep 02 16:42:17 EDT 2015 Thread[DRDAConnThread_14,5,main] (XID = 50633), (SESSIONID = 2110), (DATABASE = csemdb), (DRDAID = NF000001.D5E2-4183279662650783751{166}), Cleanup action starting
Wed Sep 02 16:42:17 EDT 2015 Thread[DRDAConnThread_14,5,main] (XID = 50633), (SESSIONID = 2110), (DATABASE = csemdb), (DRDAID = NF000001.D5E2-4183279662650783751{166}), Failed Statement is: SELECT CHASSIS_9145E10G_ID, IP_STR, DS.TEMPLATE, DS.SYSTEM_TEMPLATE, DS.ADMIN_ENABLED, DS.ALIAS_NAME, DS.MODEL, DS.HARDWARE_VERSION, DS.ACTIVE_FIRMWARE, DS.INACTIVE_FIRMWARE, DS.BOOTCODE, CONTACT, CIRCUIT, CIRCUIT_2, LOCATION, HAS_MGMT_PORT, HAS_CONSOLE_PORT, POWERSUPPLY_A_MODEL, POWERSUPPLY_B_MODEL, HAS_FANS, HAS_TEMP_SENSOR, HAS_USER_XFP_CONNECTOR, USER_XFP_MODEL, HAS_NET_XFP_CONNECTOR, NET_XFP_MODEL, IP, SYNCHRONIZING, LAST_SYNCHRONIZED_TIMESTAMP, CREATED_TIMESTAMP, ADMIN_STATE_TIMESTAMP, MACADDRESS_STR, PEER_MACADDRESS_STR, ZTP_STAGED, ZTP_STAGED_TIMESTAMP, ZTP_PROVISIONING_STATE, ZTP_PROVISIONING_STATE_TIMESTAMP, R2_MODEL FROM --DERBY-PROPERTIES joinOrder=FIXED
PKG_9145E10G.DEVICE_SUMMARY DS JOIN CORE_V1.MANAGED_HARDWARE_SUMMARY MHS ON DS.CHASSIS_9145E10G_ID = MHS.MANAGED_HARDWARE_ID WHERE DS.CHASSIS_9145E10G_ID = ? with 1 parameters begin parameter #1: 1052 :end parameter
ERROR 40001: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
Lock : ROW, MANAGED_HARDWARE_SUMMARY, (47,8)
Waiting XID : {50633, S} , CSEM, SELECT CHASSIS_9145E10G_ID, IP_STR, DS.TEMPLATE, DS.SYSTEM_TEMPLATE, DS.ADMIN_ENABLED, DS.ALIAS_NAME, DS.MODEL, DS.HARDWARE_VERSION, DS.ACTIVE_FIRMWARE, DS.INACTIVE_FIRMWARE, DS.BOOTCODE, CONTACT, CIRCUIT, CIRCUIT_2, LOCATION, HAS_MGMT_PORT, HAS_CONSOLE_PORT, POWERSUPPLY_A_MODEL, POWERSUPPLY_B_MODEL, HAS_FANS, HAS_TEMP_SENSOR, HAS_USER_XFP_CONNECTOR, USER_XFP_MODEL, HAS_NET_XFP_CONNECTOR, NET_XFP_MODEL, IP, SYNCHRONIZING, LAST_SYNCHRONIZED_TIMESTAMP, CREATED_TIMESTAMP, ADMIN_STATE_TIMESTAMP, MACADDRESS_STR, PEER_MACADDRESS_STR, ZTP_STAGED, ZTP_STAGED_TIMESTAMP, ZTP_PROVISIONING_STATE, ZTP_PROVISIONING_STATE_TIMESTAMP, R2_MODEL FROM --DERBY-PROPERTIES joinOrder=FIXED
PKG_9145E10G.DEVICE_SUMMARY DS JOIN CORE_V1.MANAGED_HARDWARE_SUMMARY MHS ON DS.CHASSIS_9145E10G_ID = MHS.MANAGED_HARDWARE_ID WHERE DS.CHASSIS_9145E10G_ID = ?
Granted XID : {50631, X}
Lock : ROW, DEVICE_SUMMARY, (4,8)
Waiting XID : {50631, X} , CSEM, UPDATE PKG_9145E10G.DEVICE_SUMMARY SET ZTP_STAGED_TIMESTAMP = ?, ZTP_STAGED = ? WHERE (ID = ?)
Granted XID : {50633, S}
. The selected victim is XID : 50633.
at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
at org.apache.derby.impl.services.locks.Deadlock.buildException(Unknown Source)
at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source)
at org.apache.derby.impl.services.locks.ConcurrentLockSet.zeroDurationLockObject(Unknown Source)
at org.apache.derby.impl.services.locks.AbstractPool.zeroDurationlockObject(Unknown Source)
I have the following properties set:
derby.locks.waitTimeout=60
derby.locks.deadlockTrace=true
derby.locks.monitor=true
derby.locks.escalationThreshold=20000
#derby.storge.pageCacheSize=16000
derby.jdbc.xaTransactionTimeout=1800
derby.language.statementCacheSize=10000
derby.infolog.append=true
derby.storage.indexStats.auto=true
derby.stream.error.style=rollingFile
derby.stream.error.rollingFile.limit=10000000
derby.stream.error.rollingFile.count=10
derby.stream.error.rollingFile.pattern=%d/derby-%g.log
I don’t understand the deadlock. The first statement does query the DEVICE_SUMMARY table that the second statement is trying to update, but I don’t see in the output the second statement having any requirement for the locks the first statement has MANAGED_HARDWARE_SUMMARy row lock.
I tried to force the join order as
DEVICE_SUMMARY
MANAGED_HARDWARE_SUMMARY
in the select statement to force the query to acquire locks first on DEVICE_SUMMARY and then MANAGED_HARDWARE_SUMMARY so that the locking pattern would be the same an the second statement of
DEVICE_SUMMARY
but this does not seem to had the desired effect.
Any ideas will be greatly appreciated.
Brett
________________________________
Canoga Perkins
20600 Prairie Street
Chatsworth, CA 91311
(818) 718-6300
This e-mail and any attached document(s) is confidential and is intended only for the review of the party to whom it is addressed. If you have received this transmission in error, please notify the sender immediately and discard the original message and any attachment(s).
RE: Need help understanding a database deadlock that was detected
Posted by "Bergquist, Brett" <BB...@canoga.com>.
I will try to update that shortly. Thanks.
-----Original Message-----
From: Bryan Pendleton [mailto:bpendleton.derby@gmail.com]
Sent: Wednesday, September 02, 2015 11:08 PM
To: derby-dev@db.apache.org
Subject: Re: Need help understanding a database deadlock that was detected
> I guess what I was expecting to see was the statement(s) were 50631 was getting a lock on the MANAGED_HARDWARE_SUMMARY. I turned on statement logging and see the issue. Your help here on how to read this output has help quite a bit though. I did not understand that the output:
>
>>> Granted XID : {50631, X}
>
> meant that the transaction 50631 had acquired
Yes, I agree, that would make the output much easier to read and diagnose.
I think we only have easy access to the current statement, so as you say you have to look to tools like logStatementText and the derby.log to reconstruct the history leading up to your deadlock.
It would be cool if you could contribute some of your techniques to help improve
http://wiki.apache.org/db-derby/LockDebugging
thanks,
bryan
Canoga Perkins
20600 Prairie Street
Chatsworth, CA 91311
(818) 718-6300
This e-mail and any attached document(s) is confidential and is intended only for the review of the party to whom it is addressed. If you have received this transmission in error, please notify the sender immediately and discard the original message and any attachment(s).
Re: Need help understanding a database deadlock that was detected
Posted by Bryan Pendleton <bp...@gmail.com>.
> I guess what I was expecting to see was the statement(s) were 50631 was getting a lock on the MANAGED_HARDWARE_SUMMARY. I turned on statement logging and see the issue. Your help here on how to read this output has help quite a bit though. I did not understand that the output:
>
>>> Granted XID : {50631, X}
>
> meant that the transaction 50631 had acquired
Yes, I agree, that would make the output much easier to read
and diagnose.
I think we only have easy access to the current statement,
so as you say you have to look to tools like logStatementText
and the derby.log to reconstruct the history leading up to
your deadlock.
It would be cool if you could contribute some of your
techniques to help improve
http://wiki.apache.org/db-derby/LockDebugging
thanks,
bryan
Re: Need help understanding a database deadlock that was detected
Posted by "Bergquist, Brett" <BB...@canoga.com>.
Thanks Bryan.
I guess what I was expecting to see was the statement(s) were 50631 was getting a lock on the MANAGED_HARDWARE_SUMMARY. I turned on statement logging and see the issue. Your help here on how to read this output has help quite a bit though. I did not understand that the output:
>> Granted XID : {50631, X}
meant that the transaction 50631 had acquired
>> Lock : ROW, MANAGED_HARDWARE_SUMMARY, (47,8)
Now I understand how to read this better. Thanks again!
> On Sep 2, 2015, at 7:03 PM, Bryan Pendleton <bp...@gmail.com> wrote:
>
>> Lock : ROW, MANAGED_HARDWARE_SUMMARY, (47,8)
>> Waiting XID : {50633, S} , CSEM, SELECT CHASSIS_9145E10G_ID, IP_STR, DS.TEMPLATE, DS.SYSTEM_TEMPLATE, DS.ADMIN_ENABLED, DS.ALIAS_NAME, DS.MODEL, DS.HARDWARE_VERSION, DS.ACTIVE_FIRMWARE, DS.INACTIVE_FIRMWARE, DS.BOOTCODE, CONTACT, CIRCUIT, CIRCUIT_2,
>> LOCATION, HAS_MGMT_PORT, HAS_CONSOLE_PORT, POWERSUPPLY_A_MODEL, POWERSUPPLY_B_MODEL, HAS_FANS, HAS_TEMP_SENSOR, HAS_USER_XFP_CONNECTOR, USER_XFP_MODEL, HAS_NET_XFP_CONNECTOR, NET_XFP_MODEL, IP, SYNCHRONIZING, LAST_SYNCHRONIZED_TIMESTAMP, CREATED_TIMESTAMP,
>> ADMIN_STATE_TIMESTAMP, MACADDRESS_STR, PEER_MACADDRESS_STR, ZTP_STAGED, ZTP_STAGED_TIMESTAMP, ZTP_PROVISIONING_STATE, ZTP_PROVISIONING_STATE_TIMESTAMP, R2_MODEL FROM --DERBY-PROPERTIES joinOrder=FIXED
>> PKG_9145E10G.DEVICE_SUMMARY DS JOIN CORE_V1.MANAGED_HARDWARE_SUMMARY MHS ON DS.CHASSIS_9145E10G_ID = MHS.MANAGED_HARDWARE_ID WHERE DS.CHASSIS_9145E10G_ID = ?
>> Granted XID : {50631, X}
>
> 50631 has an exclusive lock on row 8 of page 47 of table MANAGED_HARDWARE_SUMMARY.
>
> 50633 is trying to get a share lock on that same row, and is hence blocked.
>
>> Lock : ROW, DEVICE_SUMMARY, (4,8)
>> Waiting XID : {50631, X} , CSEM, UPDATE PKG_9145E10G.DEVICE_SUMMARY SET ZTP_STAGED_TIMESTAMP = ?, ZTP_STAGED = ? WHERE (ID = ?)
>> Granted XID : {50633, S}
>
> 50633 has a share lock on row 8 of page 4 of table DEVICE_SUMMARY.
>
> 50631 is trying to get an exclusive lock on that same row,
> and is hence blocked.
>
> So in the MANAGED_HARDWARE_SUMMARY table, 50633 is waiting on 50631.
>
> And in the DEVICE_SUMMARY table, 50631 is waiting on 50633.
>
> Deadlock.
>
> thanks,
>
> bryan
>
>
Canoga Perkins
20600 Prairie Street
Chatsworth, CA 91311
(818) 718-6300
This e-mail and any attached document(s) is confidential and is intended only for the review of the party to whom it is addressed. If you have received this transmission in error, please notify the sender immediately and discard the original message and any attachment(s).
Re: Need help understanding a database deadlock that was detected
Posted by Bryan Pendleton <bp...@gmail.com>.
> Lock : ROW, MANAGED_HARDWARE_SUMMARY, (47,8)
> Waiting XID : {50633, S} , CSEM, SELECT CHASSIS_9145E10G_ID, IP_STR, DS.TEMPLATE, DS.SYSTEM_TEMPLATE, DS.ADMIN_ENABLED, DS.ALIAS_NAME, DS.MODEL, DS.HARDWARE_VERSION, DS.ACTIVE_FIRMWARE, DS.INACTIVE_FIRMWARE, DS.BOOTCODE, CONTACT, CIRCUIT, CIRCUIT_2,
> LOCATION, HAS_MGMT_PORT, HAS_CONSOLE_PORT, POWERSUPPLY_A_MODEL, POWERSUPPLY_B_MODEL, HAS_FANS, HAS_TEMP_SENSOR, HAS_USER_XFP_CONNECTOR, USER_XFP_MODEL, HAS_NET_XFP_CONNECTOR, NET_XFP_MODEL, IP, SYNCHRONIZING, LAST_SYNCHRONIZED_TIMESTAMP, CREATED_TIMESTAMP,
> ADMIN_STATE_TIMESTAMP, MACADDRESS_STR, PEER_MACADDRESS_STR, ZTP_STAGED, ZTP_STAGED_TIMESTAMP, ZTP_PROVISIONING_STATE, ZTP_PROVISIONING_STATE_TIMESTAMP, R2_MODEL FROM --DERBY-PROPERTIES joinOrder=FIXED
> PKG_9145E10G.DEVICE_SUMMARY DS JOIN CORE_V1.MANAGED_HARDWARE_SUMMARY MHS ON DS.CHASSIS_9145E10G_ID = MHS.MANAGED_HARDWARE_ID WHERE DS.CHASSIS_9145E10G_ID = ?
> Granted XID : {50631, X}
50631 has an exclusive lock on row 8 of page 47 of table MANAGED_HARDWARE_SUMMARY.
50633 is trying to get a share lock on that same row, and is hence blocked.
> Lock : ROW, DEVICE_SUMMARY, (4,8)
> Waiting XID : {50631, X} , CSEM, UPDATE PKG_9145E10G.DEVICE_SUMMARY SET ZTP_STAGED_TIMESTAMP = ?, ZTP_STAGED = ? WHERE (ID = ?)
> Granted XID : {50633, S}
50633 has a share lock on row 8 of page 4 of table DEVICE_SUMMARY.
50631 is trying to get an exclusive lock on that same row,
and is hence blocked.
So in the MANAGED_HARDWARE_SUMMARY table, 50633 is waiting on 50631.
And in the DEVICE_SUMMARY table, 50631 is waiting on 50633.
Deadlock.
thanks,
bryan