db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "geoff hendrey (JIRA)" <j...@apache.org>
Subject [jira] Commented: (DERBY-3678) StackOverflowException in deadlock trace
Date Mon, 19 May 2008 14:23:58 GMT

    [ 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.<init>(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.<init>(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.


Mime
View raw message