Return-Path: Delivered-To: apmail-db-derby-user-archive@www.apache.org Received: (qmail 61242 invoked from network); 27 May 2009 22:53:29 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 27 May 2009 22:53:29 -0000 Received: (qmail 13197 invoked by uid 500); 27 May 2009 21:33:34 -0000 Delivered-To: apmail-db-derby-user-archive@db.apache.org Received: (qmail 13180 invoked by uid 500); 27 May 2009 21:33:34 -0000 Mailing-List: contact derby-user-help@db.apache.org; run by ezmlm Precedence: bulk list-help: list-unsubscribe: List-Post: List-Id: Reply-To: "Derby Discussion" Delivered-To: mailing list derby-user@db.apache.org Received: (qmail 13172 invoked by uid 99); 27 May 2009 21:33:34 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 27 May 2009 21:33:34 +0000 X-ASF-Spam-Status: No, hits=2.2 required=10.0 tests=HTML_MESSAGE,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: local policy) Received: from [68.142.236.188] (HELO web58505.mail.re3.yahoo.com) (68.142.236.188) by apache.org (qpsmtpd/0.29) with SMTP; Wed, 27 May 2009 21:33:23 +0000 Received: (qmail 58274 invoked by uid 60001); 27 May 2009 21:33:01 -0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s1024; t=1243459981; bh=nG/FGarff0d8XMZIJmkE1tDICFSGgINVQI4ZVzqKE3o=; h=Message-ID:X-YMail-OSG:Received:X-Mailer:References:Date:From:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=qMw4xv/bqDNnPLeqjWMHyKCykuSC8nZMOpVKjJVqt4NYYQKaIjsxsFGQXaH1IWhTFzwvESVsgMTkTejX6UDTUDF7HaMGgL6+zJq8xeEIOkan4NrTbGiHKIa8X6xZKGoOWox1qT43j1K6RVS+2IDEnBM2pMnjGNGqdlD+yT/dcXo= DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; h=Message-ID:X-YMail-OSG:Received:X-Mailer:References:Date:From:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=QZBshWWMO7BOapWTy5shX0fmUsyxFZnL5SGeuT0R73g2TUp/jUdaT6lw2SXIXpPd0oJN4t5xe/T8JsfQ5bmTwO72BMMPrg1KJ20+QUA6iBTPB7PvqTd4GxPgLIz1bXtLVVEJg5esKfoMwf42TWKP5Znq2HsyIsqRxl1F6Sj0oTI=; Message-ID: <395757.57868.qm@web58505.mail.re3.yahoo.com> X-YMail-OSG: Xflnu6oVM1leozRkLMWvpxbPJDRSUSYvOrGu49FOvmVvhkByu_2c9EFiRflen5v1RfZDCNe92qb_hiyoltcmIgaThN6zGXnPu3u9H_.mNxLbRFWYYm0wV9tw.op6NH7OTvPK2d_CJY36BXEy504Lvcm56FmImUs7kojVFYGNuS3G8F5yMPYHvRS9xA.7FpocnvF40oouZemC_yeRqzpmgT4AXDAdPbDBUqno9CUjQXJc0Tl6td7g1E02kzikVZ.DbFiNlx_Z6zr16_RyAz8Vs0t0M2hel_wtyXf9bCmTWf3DH5wrCDBCiVZEuPPZaUVy0HKKuT7wN5hcfdNSJwl4ng-- Received: from [198.22.153.8] by web58505.mail.re3.yahoo.com via HTTP; Wed, 27 May 2009 14:33:01 PDT X-Mailer: YahooMailRC/1277.43 YahooMailWebService/0.7.289.10 References: <200588.95837.qm@web58504.mail.re3.yahoo.com> <4A1D6A42.5020806@sbcglobal.net> <805369.57030.qm@web58505.mail.re3.yahoo.com> <4A1D8EE4.8090702@sbcglobal.net> Date: Wed, 27 May 2009 14:33:01 -0700 (PDT) From: T K Subject: Re: syscs_compress_table deadlock To: Derby Discussion In-Reply-To: <4A1D8EE4.8090702@sbcglobal.net> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="0-851692304-1243459981=:57868" X-Virus-Checked: Checked by ClamAV on apache.org --0-851692304-1243459981=:57868 Content-Type: text/plain; charset=us-ascii Thank you. > I assume the inserts are part of a multi-statement transaction, is that true? Yes, batch and non-batch. > Does the transaction include the creation of the table? No, the schema is fixed and created beforehand. This is a simple case of straight forward INSERTs as new data pours into the system for later analysis, with a daemon thread trying to run stats on a periodic basis, in a stress-test situation. So I am not sure where to go from here... table-level locking by default, which I assume will fix this, isn't an option; rerouting the data to a temp table is an option, albeit ugly. I assume no one else has ever seen this before? ________________________________ From: Mike Matrigali To: Derby Discussion Sent: Wednesday, May 27, 2009 3:05:08 PM Subject: Re: syscs_compress_table deadlock The table locking nomenclature is somewhat confusing. Let me try to explain. Derby always uses 2 level locking so that it can support both table level and row level locking. What people usually refer to as "table" locking are the cases of S and X locks on "TABLE" locks. An S table lock logically means a shared lock on every row in the table. An X table lock logically means an exclusive lock on every row in the table. Derby update row locking always first gets an IX table lock (intent to get x row locks), and read row locking gets an IS table lock (intent to get s row locks). In derby the only purpose for these intent locks is to block as appropriate the S and X table locks. So X table lock is not compatible with any other table lock. An S table lock is not compatible with X or IX. It is compatible with IS. transaction 27040324 (compress transaction): o is waiting to get an IX table lock on SYSCONGLOMERATES o owns a an X table lock on SOMETABLE transaction 27058697 (insert transaction): o is waiting on a IX lock on SOMETABLE (which is not compatible with the above X lock held by 27040324 o is granted a S table lock on SYSCONGLOMERATES (which is not compatible with the above IX table lock request on SYSCONGLOMERATES. More on Derby isolation and locking can be found in the docs: http://db.apache.org/derby/docs/10.5/devguide/cdevconcepts30291.html I assume the inserts are part of a multi-statement transaction, is that true? Does the transaction include the creation of the table? T K wrote: > Hmm.... My reading of the situation is a bit different... You said: > > > Compress is doing row locking as indicated by it requesting a (IX), intended share table lock. > > To me IX is Intended Exclusive and the fact some other transaction has a shared lock (S) on SOMETABLE shouldn't really matter, so going back to the error report - and for a deadlock to exist - I would expect to see some transaction A holding exclusive lock L1 while requesting exclusive lock L2, and another transaction B holding L2 while requesting L1. This means I would expect to see two X locks in the report between two tables but I don't - there is just one X lock... Here's the report again for clarity: > > 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is: > Lock : TABLE, SYSCONGLOMERATES, Tablelock > Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential > Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S} > Lock : TABLE, SOMETABLE, Tablelock > Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?) > Granted XID : {27040324, X} > . The selected victim is XID : 27040324.' was thrown while evaluating an expression. > From: XXX > SQL: {call syscs_util.syscs_compress_table('MYSCHEMA','SOMETABLE',1)} > > If my reading of this is accurate, what I see is that 27040324 has an X lock on SOMETABLE and 27058697 is waiting to obtain the same lock (IX), while 27058697 is not holding any other X locks for it to engage in a deadlock. At the same time 27040324 is intending to obtain an exclusive lock on SYSCONGLOMERATES but the report is not telling who's holding an X lock on it. Basically in this report, and for a deadlock to occur, I am expecting to see that 27058697 also has an X lock on SYSCONGLOMERATES, but I don't. Therefore, there is either some sort of bug here, or I have to assume there must be a third transaction (not reported here) that has this exclusive lock, and this would then appear to be a 3-way deadlock, but the report isn't telling me this, and detecting a 3-way deadlock is a very difficult thing to begin with... so from this I conclude that we are dealing with some sort of bug here... > > The code is not accessing SYSCONGLOEMERATES directly or doing metadata queries - threads are simply INSERTing while another thread runs stats periodically. > > Thanks > > ------------------------------------------------------------------------ > *From:* Mike Matrigali > *To:* Derby Discussion > *Sent:* Wednesday, May 27, 2009 12:28:50 PM > *Subject:* Re: syscs_compress_table deadlock > > Is there any chance you can post a reproducible test case? The part of > this I am having a hard time understanding is that somehow the transaction which is doing the inserts has gotten a table level read lock on SYSCONGLOMERATES, as indicated by the following line from the > error: > Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , > > {27058697, S} > > Transaction 27043904 has a S (shared) table lock on SYSCONGLOMERATES which is a system table. The key is figuring out how that happened. > Compress is doing row locking as indicated by it requesting a (IX), > intended share table lock. > > Any chance the inserting threads are either doing direct queries on > SYSCONGLOMERATES or doing database metadata queries? Setting > derby.language.logStatementText=true may help track down what the > insert threads are doing to get this unexpected lock. It is probably > prudent to commit after any database metadata query to release any locks > which may have been requested on system catalogs unless you require that > info for a consistent transaction. > > Also search the documentation for derby.locks.monitor=true for ways to > get the system to print more information when it gets a deadlock. > > > T K wrote: > > While we call this stored proc INSERTS keep coming in from other threads, > > resulting in the deadlock exception at the bottom, and I assume this is expected > > although I did not see anything in the documentation. Can someone please > > confirm the proper conditions for calling this stored proc? Derby 10.3.3.0. > > > > tia > > > > com.XXX.pub.database.DatabaseException: code: -1 SQLState: 38000 Message: The exception 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is: > > Lock : TABLE, SYSCONGLOMERATES, Tablelock > > Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential > > Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S} > > Lock : TABLE, SOMETABLE, Tablelock > > Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?) > > Granted XID : {27040324, X} > > . The selected victim is XID : 27040324.' was thrown while evaluating an expression. > > From: XXX > > SQL: {call syscs_util.syscs_compress_table('MYSCHEMA','SOMETABLE',1)} > > SQL Inserts: > > > > Caused by SQL Problems. > > Problem #1, SQLState 38000, Error code -1: java.sql.SQLException: The exception 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is: > > Lock : TABLE, SYSCONGLOMERATES, Tablelock > > Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential > > Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S} > > Lock : TABLE, SOMETABLE, Tablelock > > Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?) > > Granted XID : {27040324, X} > > . The selected victim is XID : 27040324.' was thrown while evaluating an expression. > > Problem #2, SQLState 40001, Error code 99999: java.sql.SQLNonTransientConnectionException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is: > > Lock : TABLE, SYSCONGLOMERATES, Tablelock > > Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential > > Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S} > > Lock : TABLE, SOMETABLE, Tablelock > > Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?) > > Granted XID : {27040324, X} > > . The selected victim is XID : 27040324. > > at .... > > > > --0-851692304-1243459981=:57868 Content-Type: text/html; charset=us-ascii
Thank you.

> I assume the inserts are part of a multi-statement transaction, is that true? 

Yes, batch and non-batch.

> Does the transaction include the creation of the table?

No, the schema is fixed and created beforehand. This is a simple case of straight forward INSERTs as new data pours into the system for later analysis, with a daemon thread trying to run stats on a periodic basis, in a stress-test situation.

So I am not sure where to go from here... table-level locking by default, which I assume will fix this, isn't an option; rerouting the data to a temp table is an option, albeit ugly.

I assume no one else has ever seen this before?

From: Mike Matrigali <mikem_app@sbcglobal.net>
To: Derby Discussion <derby-user@db.apache.org>
Sent: Wednesday, May 27, 2009 3:05:08 PM
Subject: Re: syscs_compress_table deadlock

The table locking nomenclature is somewhat confusing.  Let me try to
explain.  Derby always uses 2 level locking so that it can support
both table level and row level locking.

What people usually refer to as "table" locking are the cases of
S and X locks on "TABLE" locks.  An S table lock logically means a
shared lock on every row in the table.  An X table lock logically means
an exclusive lock on every row in the table.
Derby update row locking always first gets an IX table lock (intent to
get x row locks), and read row locking gets an IS table lock (intent to
get s row locks).  In derby the only purpose for these intent locks is
to block as appropriate the S and X table locks.

So X table lock is not compatible with any other table lock.
An S table lock is not compatible with X or IX.  It is compatible with IS.

transaction 27040324 (compress transaction):
    o is waiting to get an IX table lock on SYSCONGLOMERATES
    o owns a an X table lock on SOMETABLE

transaction 27058697 (insert transaction):
    o is waiting on a IX lock on SOMETABLE (which is not compatible with
      the above X lock held by 27040324
    o is granted a S table lock on SYSCONGLOMERATES (which is not
      compatible with the above IX table lock request on SYSCONGLOMERATES.

More on Derby isolation and locking can be found in the docs:
http://db.apache.org/derby/docs/10.5/devguide/cdevconcepts30291.html


I assume the inserts are part of a multi-statement transaction, is
that true?  Does the transaction include the creation of the table?


T K wrote:
> Hmm.... My reading of the situation is a bit different... You said:
>
>  > Compress is doing row locking as indicated by it requesting a (IX), intended share table lock.
>
> To me IX is Intended Exclusive and the fact some other transaction has a shared lock (S) on SOMETABLE shouldn't really matter, so going back to the error report - and for a deadlock to exist - I would expect to see some transaction A holding exclusive lock L1 while requesting exclusive lock L2, and another transaction B holding L2 while requesting L1. This means I would expect to see two X locks in the report between two tables but I don't - there is just one X lock... Here's the report again for clarity:
>
> 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
> Lock : TABLE, SYSCONGLOMERATES, Tablelock
>  Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential
>  Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S}
> Lock : TABLE, SOMETABLE, Tablelock
>  Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?)
>  Granted XID : {27040324, X}
> . The selected victim is XID : 27040324.' was thrown while evaluating an expression.
> From: XXX
>    SQL: {call syscs_util.syscs_compress_table('MYSCHEMA','SOMETABLE',1)}
>
> If my reading of this is accurate, what I see is that 27040324 has an X lock on SOMETABLE and 27058697 is waiting to obtain the same lock (IX), while 27058697 is not holding any other X locks for it to engage in a deadlock. At the same time 27040324 is intending to obtain an exclusive lock on SYSCONGLOMERATES but the report is not telling who's holding an X lock on it. Basically in this report, and for a deadlock to occur, I am expecting to see that 27058697 also has an X lock on SYSCONGLOMERATES, but I don't. Therefore, there is either some sort of bug here, or I have to assume there must be a third transaction (not reported here) that has this exclusive lock, and this would then appear to be a 3-way deadlock, but the report isn't telling me this, and detecting a 3-way deadlock is a very difficult thing to begin with... so from this I conclude that we are dealing with some sort of bug here...
>
> The code is not accessing SYSCONGLOEMERATES directly or doing metadata queries - threads are simply INSERTing while another thread runs stats periodically.
>
> Thanks
>
> ------------------------------------------------------------------------
> *From:* Mike Matrigali <mikem_app@sbcglobal.net>
> *To:* Derby Discussion <derby-user@db.apache.org>
> *Sent:* Wednesday, May 27, 2009 12:28:50 PM
> *Subject:* Re: syscs_compress_table deadlock
>
> Is there any chance you can post a reproducible test case?  The part of
> this I am having a hard time understanding is that somehow the transaction which is doing the inserts has gotten a table level read lock on SYSCONGLOMERATES, as indicated by the following line from the
> error:
> Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} ,
>  > {27058697, S}
>
> Transaction 27043904 has a S (shared) table lock on SYSCONGLOMERATES which is a system table.  The key is figuring out how that happened.
> Compress is doing row locking as indicated by it requesting a (IX),
> intended share table lock.
>
> Any chance the inserting threads are either doing direct queries on
> SYSCONGLOMERATES or doing database metadata queries?  Setting
> derby.language.logStatementText=true may help track down what the
> insert threads are doing to get this unexpected lock.  It is probably
> prudent to commit after any database metadata query to release any locks
> which may have been requested on system catalogs unless you require that
> info for a consistent transaction.
>
> Also search the documentation for derby.locks.monitor=true for ways to
> get the system to print more information when it gets a deadlock.
>
>
> T K wrote:
>  > While we call this stored proc INSERTS keep coming in from other threads,
>  > resulting in the deadlock exception at the bottom, and I assume this is expected
>  > although I did not see anything in the documentation. Can someone please
>  > confirm the proper conditions for calling this stored proc? Derby 10.3.3.0.
>  >
>  > tia
>  >
>  > com.XXX.pub.database.DatabaseException: code: -1 SQLState: 38000 Message: The exception 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
>  > Lock : TABLE, SYSCONGLOMERATES, Tablelock
>  >  Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential
>  >  Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S}
>  > Lock : TABLE, SOMETABLE, Tablelock
>  >  Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?)
>  >  Granted XID : {27040324, X}
>  > . The selected victim is XID : 27040324.' was thrown while evaluating an expression.
>  > From: XXX
>  >    SQL: {call syscs_util.syscs_compress_table('MYSCHEMA','SOMETABLE',1)}
>  >    SQL Inserts:
>  >
>  > Caused by SQL Problems.
>  > Problem #1, SQLState 38000, Error code -1: java.sql.SQLException: The exception 'java.sql.SQLException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
>  > Lock : TABLE, SYSCONGLOMERATES, Tablelock
>  >  Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential
>  >  Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S}
>  > Lock : TABLE, SOMETABLE, Tablelock
>  >  Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?)
>  >  Granted XID : {27040324, X}
>  > . The selected victim is XID : 27040324.' was thrown while evaluating an expression.
>  > Problem #2, SQLState 40001, Error code 99999: java.sql.SQLNonTransientConnectionException: A lock could not be obtained due to a deadlock, cycle of locks and waiters is:
>  > Lock : TABLE, SYSCONGLOMERATES, Tablelock
>  >  Waiting XID : {27040324, IX} , MYSCHEMA, alter table "MYSCHEMA"."SOMETABLE" compress sequential
>  >  Granted XID : {27040324, IS} , {27043904, S} , {27043904, IS} , {27058697, S}
>  > Lock : TABLE, SOMETABLE, Tablelock
>  >  Waiting XID : {27058697, IX} , MYSCHEMA, insert into SOMETABLE (COLUMN1) values (?)
>  >  Granted XID : {27040324, X}
>  > . The selected victim is XID : 27040324.
>  >    at ....
>  >
>
>


--0-851692304-1243459981=:57868--