Return-Path: Delivered-To: apmail-db-derby-dev-archive@www.apache.org Received: (qmail 8386 invoked from network); 19 May 2008 14:24:20 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 19 May 2008 14:24:20 -0000 Received: (qmail 67222 invoked by uid 500); 19 May 2008 14:24:21 -0000 Delivered-To: apmail-db-derby-dev-archive@db.apache.org Received: (qmail 67199 invoked by uid 500); 19 May 2008 14:24:21 -0000 Mailing-List: contact derby-dev-help@db.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: Delivered-To: mailing list derby-dev@db.apache.org Received: (qmail 67188 invoked by uid 99); 19 May 2008 14:24:21 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 19 May 2008 07:24:21 -0700 X-ASF-Spam-Status: No, hits=-2000.0 required=10.0 tests=ALL_TRUSTED X-Spam-Check-By: apache.org Received: from [140.211.11.140] (HELO brutus.apache.org) (140.211.11.140) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 19 May 2008 14:23:42 +0000 Received: from brutus (localhost [127.0.0.1]) by brutus.apache.org (Postfix) with ESMTP id 59C04234C11A for ; Mon, 19 May 2008 07:23:58 -0700 (PDT) Message-ID: <397824085.1211207038366.JavaMail.jira@brutus> Date: Mon, 19 May 2008 07:23:58 -0700 (PDT) From: "geoff hendrey (JIRA)" To: derby-dev@db.apache.org Subject: [jira] Commented: (DERBY-3678) StackOverflowException in deadlock trace In-Reply-To: <1084632250.1211141455631.JavaMail.jira@brutus> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org [ https://issues.apache.org/jira/browse/DERBY-3678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12597964#action_12597964 ] geoff hendrey commented on DERBY-3678: -------------------------------------- "Or do you have multiple threads creating lots of schemas?" I'm not creating any schemas at the time this problem happens. I will try to describe what I am doing, as background. There are two databases, naturally each has a different connection URL. Let's call them Database A and Database B. I read in a configuration file that describes a set of tables in Database A, and then I create those tables, and store some information about them in Database B. 1) define tables in Database A 2) store some information about tables in Database A in a table in Database B 3) alter tables in Database A to add a named foreign key constraint to some of the tabes 4) store some more information about tables in A into a table in Database B The problem only occurs on step 4, and it only occurs when there are 9 insertions into Database B as part of step (4). If I remove a single item from my configuration file, so that step (4) only processes 8 items, there is no problem. Here is the trace from derby.language.logQueryPlan. I excerpted only the portions related to "SYS....". There are two groups of relevant trace, and I separated them with "=================" in the cut-and-paste that follows. The lock timeout (or StackOverflowException if I turn on derby.locks.deadlockTrace) occurs after the second set of information in the logQueryPlan. 2008-05-18 19:24:52.764 GMT Thread[btpool0-4,5,main] (XID = 8142), (SESSIONID = 2), EXECUTE STATEMENT SYS."getTables" ******* Sort ResultSet: Number of opens = 1 Rows input = 13 Rows returned = 13 Eliminate duplicates = false In sorted order = false Sort information: Number of rows input=13 Number of rows output=13 Sort type=internal constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Source result set: Project-Restrict ResultSet (20): Number of opens = 1 Rows seen = 13 Rows filtered = 0 restriction = false projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Source result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 13 Rows seen from the right = 13 Rows filtered = 0 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Left result set: Nested Loop Exists Join ResultSet: Number of opens = 1 Rows seen from the left = 13 Rows seen from the right = 13 Rows filtered = 0 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.71 Left result set: Project-Restrict ResultSet (5): Number of opens = 1 Rows seen = 32 Rows filtered = 19 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Source result set: Index Row to Base Row ResultSet for SYSTABLES: Number of opens = 1 Rows seen = 32 Columns accessed from heap = {1, 2, 3} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Index Scan ResultSet for SYSTABLES using index SYSTABLES_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 32 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched={0, 2} Number of columns fetched=2 Number of deleted rows visited=8 Number of pages visited=1 Number of rows qualified=32 Number of rows visited=40 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: None optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Right result set: Project-Restrict ResultSet (8): Number of opens = 13 Rows seen = 13 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Source result set: Index Row to Base Row ResultSet for SYSSCHEMAS: Number of opens = 13 Rows seen = 13 Columns accessed from heap = {1} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Index Scan ResultSet for SYSSCHEMAS using index SYSSCHEMAS_INDEX2 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 13 Rows seen = 13 Rows filtered = 0 Fetch Size = 1 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=2 Number of deleted rows visited=0 Number of pages visited=13 Number of rows qualified=13 Number of rows visited=13 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: 0 stop position: > on first 1 column(s). Ordered null semantics on the following columns: 0 qualifiers: None optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Right result set: Project-Restrict ResultSet (19): Number of opens = 13 Rows seen = 52 Rows filtered = 39 restriction = true projection = false constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Source result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 39 Rows seen from the right = 13 Rows returned = 52 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Left result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 26 Rows seen from the right = 13 Rows returned = 39 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 0.00 Left result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 13 Rows seen from the right = 13 Rows returned = 26 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.12 optimizer estimated cost: 0.00 Left result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.12 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 2008-05-18 19:24:52.848 GMT Thread[btpool0-4,5,main] (XID = 8145), (SESSIONID = 2), EXECUTE STATEMENT SYS."getColumns" ******* Sort ResultSet: Number of opens = 1 Rows input = 6 Rows returned = 6 Eliminate duplicates = false In sorted order = false Sort information: Number of rows input=6 Number of rows output=6 Sort type=internal constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Source result set: Project-Restrict ResultSet (12): Number of opens = 1 Rows seen = 6 Rows filtered = 0 restriction = false projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Source result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 1 Rows seen from the right = 6 Rows filtered = 0 Rows returned = 6 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Left result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 15 Rows seen from the right = 1 Rows filtered = 0 Rows returned = 1 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 6.22 Left result set: Project-Restrict ResultSet (5): Number of opens = 1 Rows seen = 15 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Source result set: Index Row to Base Row ResultSet for SYSSCHEMAS: Number of opens = 1 Rows seen = 15 Columns accessed from heap = {0, 1} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Index Scan ResultSet for SYSSCHEMAS using index SYSSCHEMAS_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 15 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=2 Number of deleted rows visited=12 Number of pages visited=1 Number of rows qualified=15 Number of rows visited=27 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: None optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Right result set: Project-Restrict ResultSet (8): Number of opens = 15 Rows seen = 13 Rows filtered = 12 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Source result set: Index Row to Base Row ResultSet for SYSTABLES: Number of opens = 15 Rows seen = 13 Columns accessed from heap = {0, 1, 3} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Index Scan ResultSet for SYSTABLES using index SYSTABLES_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 15 Rows seen = 13 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=3 Number of deleted rows visited=120 Number of pages visited=15 Number of rows qualified=13 Number of rows visited=330 Scan type=btree Tree height=1 start position: >= on first 2 column(s). Ordered null semantics on the following columns: 1 stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: Column[0][0] Id: 1 Operator: = Ordered nulls: false Unknown return value: false Negate comparison result: false optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Right result set: Project-Restrict ResultSet (11): Number of opens = 1 Rows seen = 6 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 Source result set: Index Row to Base Row ResultSet for SYSCOLUMNS: Number of opens = 1 Rows seen = 6 Columns accessed from heap = {0, 1, 2, 3, 4, 7, 8} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 Index Scan ResultSet for SYSCOLUMNS using index SYSCOLUMNS_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 6 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=3 Number of deleted rows visited=0 Number of pages visited=2 Number of rows qualified=6 Number of rows visited=7 Scan type=btree Tree height=2 start position: >= on first 2 column(s). Ordered null semantics on the following columns: 0 stop position: >= on first 2 column(s). Ordered null semantics on the following columns: 0 qualifiers: None optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 2008-05-18 19:24:52.891 GMT Thread[btpool0-4,5,main] (XID = 8148), (SESSIONID = 3), SELECT CONSTRAINTNAME FROM SYS.SYSCONSTRAINTS ******* Index Scan ResultSet for SYSCONSTRAINTS using index SYSCONSTRAINTS_INDEX2 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 24 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched={0} Number of columns fetched=1 Number of deleted rows visited=20 Number of pages visited=3 Number of rows qualified=24 Number of rows visited=44 Scan type=btree Tree height=-1 start position: None stop position: None qualifiers: None optimizer estimated row count: 43.00 optimizer estimated cost: 61.46 ========================== 2008-05-18 19:40:06.154 GMT Thread[btpool0-4,5,main] (XID = 8189), (SESSIONID = 2), EXECUTE STATEMENT SYS."getTables" ******* Sort ResultSet: Number of opens = 1 Rows input = 13 Rows returned = 13 Eliminate duplicates = false In sorted order = false Sort information: Number of rows input=13 Number of rows output=13 Sort type=internal constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Source result set: Project-Restrict ResultSet (20): Number of opens = 1 Rows seen = 13 Rows filtered = 0 restriction = false projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Source result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 13 Rows seen from the right = 13 Rows filtered = 0 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 5.71 Left result set: Nested Loop Exists Join ResultSet: Number of opens = 1 Rows seen from the left = 13 Rows seen from the right = 13 Rows filtered = 0 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.71 Left result set: Project-Restrict ResultSet (5): Number of opens = 1 Rows seen = 32 Rows filtered = 19 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Source result set: Index Row to Base Row ResultSet for SYSTABLES: Number of opens = 1 Rows seen = 32 Columns accessed from heap = {1, 2, 3} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Index Scan ResultSet for SYSTABLES using index SYSTABLES_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 32 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched={0, 2} Number of columns fetched=2 Number of deleted rows visited=8 Number of pages visited=1 Number of rows qualified=32 Number of rows visited=40 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: None optimizer estimated row count: 0.06 optimizer estimated cost: 5.43 Right result set: Project-Restrict ResultSet (8): Number of opens = 13 Rows seen = 13 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Source result set: Index Row to Base Row ResultSet for SYSSCHEMAS: Number of opens = 13 Rows seen = 13 Columns accessed from heap = {1} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Index Scan ResultSet for SYSSCHEMAS using index SYSSCHEMAS_INDEX2 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 13 Rows seen = 13 Rows filtered = 0 Fetch Size = 1 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=2 Number of deleted rows visited=0 Number of pages visited=13 Number of rows qualified=13 Number of rows visited=13 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: 0 stop position: > on first 1 column(s). Ordered null semantics on the following columns: 0 qualifiers: None optimizer estimated row count: 0.06 optimizer estimated cost: 0.27 Right result set: Project-Restrict ResultSet (19): Number of opens = 13 Rows seen = 52 Rows filtered = 39 restriction = true projection = false constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Source result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 39 Rows seen from the right = 13 Rows returned = 52 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Left result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 26 Rows seen from the right = 13 Rows returned = 39 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 0.00 Left result set: Union ResultSet: Number of opens = 13 Rows seen from the left = 13 Rows seen from the right = 13 Rows returned = 26 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.12 optimizer estimated cost: 0.00 Left result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.12 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 Right result set: Normalize ResultSet: Number of opens = 13 Rows seen = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.24 optimizer estimated cost: 0.00 Source result set: Row ResultSet: Number of opens = 13 Rows returned = 13 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.06 optimizer estimated cost: 0.00 2008-05-18 19:40:06.201 GMT Thread[btpool0-4,5,main] (XID = 8191), (SESSIONID = 2), EXECUTE STATEMENT SYS."getColumns" ******* Sort ResultSet: Number of opens = 1 Rows input = 6 Rows returned = 6 Eliminate duplicates = false In sorted order = false Sort information: Number of rows input=6 Number of rows output=6 Sort type=internal constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Source result set: Project-Restrict ResultSet (12): Number of opens = 1 Rows seen = 6 Rows filtered = 0 restriction = false projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Source result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 1 Rows seen from the right = 6 Rows filtered = 0 Rows returned = 6 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 7.30 Left result set: Nested Loop Join ResultSet: Number of opens = 1 Rows seen from the left = 15 Rows seen from the right = 1 Rows filtered = 0 Rows returned = 1 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 6.22 Left result set: Project-Restrict ResultSet (5): Number of opens = 1 Rows seen = 15 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Source result set: Index Row to Base Row ResultSet for SYSSCHEMAS: Number of opens = 1 Rows seen = 15 Columns accessed from heap = {0, 1} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Index Scan ResultSet for SYSSCHEMAS using index SYSSCHEMAS_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 15 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=2 Number of deleted rows visited=12 Number of pages visited=1 Number of rows qualified=15 Number of rows visited=27 Scan type=btree Tree height=1 start position: >= on first 1 column(s). Ordered null semantics on the following columns: stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: None optimizer estimated row count: 0.43 optimizer estimated cost: 4.99 Right result set: Project-Restrict ResultSet (8): Number of opens = 15 Rows seen = 13 Rows filtered = 12 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Source result set: Index Row to Base Row ResultSet for SYSTABLES: Number of opens = 15 Rows seen = 13 Columns accessed from heap = {0, 1, 3} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Index Scan ResultSet for SYSTABLES using index SYSTABLES_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 15 Rows seen = 13 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=3 Number of deleted rows visited=120 Number of pages visited=15 Number of rows qualified=13 Number of rows visited=330 Scan type=btree Tree height=1 start position: >= on first 2 column(s). Ordered null semantics on the following columns: 1 stop position: >= on first 1 column(s). Ordered null semantics on the following columns: qualifiers: Column[0][0] Id: 1 Operator: = Ordered nulls: false Unknown return value: false Negate comparison result: false optimizer estimated row count: 0.05 optimizer estimated cost: 1.23 Right result set: Project-Restrict ResultSet (11): Number of opens = 1 Rows seen = 6 Rows filtered = 0 restriction = true projection = true constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 restriction time (milliseconds) = 0 projection time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 Source result set: Index Row to Base Row ResultSet for SYSCOLUMNS: Number of opens = 1 Rows seen = 6 Columns accessed from heap = {0, 1, 2, 3, 4, 7, 8} constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 Index Scan ResultSet for SYSCOLUMNS using index SYSCOLUMNS_INDEX1 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 6 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched=All Number of columns fetched=3 Number of deleted rows visited=0 Number of pages visited=3 Number of rows qualified=6 Number of rows visited=7 Scan type=btree Tree height=2 start position: >= on first 2 column(s). Ordered null semantics on the following columns: 0 stop position: >= on first 2 column(s). Ordered null semantics on the following columns: 0 qualifiers: None optimizer estimated row count: 0.18 optimizer estimated cost: 1.08 2008-05-18 19:40:06.219 GMT Thread[btpool0-4,5,main] (XID = 8193), (SESSIONID = 3), SELECT CONSTRAINTNAME FROM SYS.SYSCONSTRAINTS ******* Index Scan ResultSet for SYSCONSTRAINTS using index SYSCONSTRAINTS_INDEX2 at read uncommitted isolation level using share row locking chosen by the optimizer Number of opens = 1 Rows seen = 24 Rows filtered = 0 Fetch Size = 16 constructor time (milliseconds) = 0 open time (milliseconds) = 0 next time (milliseconds) = 0 close time (milliseconds) = 0 next time in milliseconds/row = 0 scan information: Bit set of columns fetched={0} Number of columns fetched=1 Number of deleted rows visited=24 Number of pages visited=3 Number of rows qualified=24 Number of rows visited=48 Scan type=btree Tree height=-1 start position: None stop position: None qualifiers: None optimizer estimated row count: 26.00 optimizer estimated cost: 59.49 > StackOverflowException in deadlock trace > ---------------------------------------- > > Key: DERBY-3678 > URL: https://issues.apache.org/jira/browse/DERBY-3678 > Project: Derby > Issue Type: Bug > Affects Versions: 10.3.2.1 > Environment: (this is actually in version 10.3.2.2) > MacOS 10, JDK 1.6 > Reporter: geoff hendrey > > I am getting a deadlock in SYSTABLE. When I turn on Dderby.locks.deadlockTrace=true, I get a StackOverflowException > Derby version The Apache Software Foundation - Apache Derby - 10.3.2.2 > - (618335): instance 80220011-0119-f93f-b912-00000000bced > on database directory /db/domains/geoff > Database Class Loader started - derby.database.classpath='' > 2008-05-17 23:44:36.380 > GMT Thread[btpool0-2,5,main] (XID = 7556), (SESSIONID = 4), (DATABASE = > domains/geoff), (DRDAID = null), Cleanup action starting > java.lang.StackOverflowError > at org.apache.derby.impl.sql.execute.GenericExecutionFactory.getValueRow(Unknown Source) > at org.apache.derby.impl.sql.catalog.SYSCONGLOMERATESRowFactory.makeRow(Unknown Source) > at org.apache.derby.impl.sql.catalog.SYSCONGLOMERATESRowFactory.makeEmptyRow(Unknown > Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.hashAllConglomerateDescriptorsByNumber(Unknown > Source) > at org.apache.derby.impl.services.locks.TableNameInfo.(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.buildLockTableString(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source) > at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source) > at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source) > at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source) > at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForRead(Unknown Source) > at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source) > at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown > Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown > Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown > Source) > at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source) > at org.apache.derby.impl.store.access.btree.BTreeScan.next(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIndex(Unknown > Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.locateSchemaRow(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getSchemaDescriptor(Unknown > Source) > at org.apache.derby.impl.sql.catalog.SYSTABLESRowFactory.buildDescriptor(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.hashAllTableDescriptorsByTableId(Unknown > Source) > at org.apache.derby.impl.services.locks.TableNameInfo.(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.buildLockTableString(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.createException(Unknown Source) > at org.apache.derby.impl.services.locks.Timeout.buildException(Unknown Source) > at org.apache.derby.impl.services.locks.ConcurrentLockSet.lockObject(Unknown Source) > at org.apache.derby.impl.services.locks.AbstractPool.lockObject(Unknown Source) > at org.apache.derby.impl.services.locks.ConcurrentPool.lockObject(Unknown Source) > at org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForRead(Unknown Source) > at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source) > at org.apache.derby.impl.store.access.heap.HeapController.lockRow(Unknown Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3.lockRowOnPage(Unknown > Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLocking3._lockScanRow(Unknown > Source) > at org.apache.derby.impl.store.access.btree.index.B2IRowLockingRR.lockScanRow(Unknown > Source) > at org.apache.derby.impl.store.access.btree.BTreeForwardScan.fetchRows(Unknown Source) > at org.apache.derby.impl.store.access.btree.BTreeScan.next(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getDescriptorViaIndex(Unknown > Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.locateSchemaRow(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getSchemaDescriptor(Unknown > Source) > at org.apache.derby.impl.sql.catalog.SYSTABLESRowFactory.buildDescriptor(Unknown Source) > at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.hashAllTableDescriptorsByTableId(Unknown > Source) -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online.