You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "somebody (JIRA)" <ji...@apache.org> on 2016/01/21 12:03:39 UTC

[jira] [Created] (DERBY-6858) Apache Derby simple update statement performance becomes 1500% worse when adding one byte to a column

somebody created DERBY-6858:
-------------------------------

             Summary: Apache Derby simple update statement performance becomes 1500% worse when adding one byte to a column
                 Key: DERBY-6858
                 URL: https://issues.apache.org/jira/browse/DERBY-6858
             Project: Derby
          Issue Type: Bug
    Affects Versions: 10.12.1.1, 10.11.1.1
         Environment: windows 7 64 bit
            Reporter: somebody
            Priority: Blocker


I have 2 tables as follows:

ParentUpdate
name varchar(255)
value int not null

primary key: name

ChildUpdate
parentName varchar(255)
name varchar(255)
value int
data varchar(1000)

primary key: name foreign key: parentName to ParentUpdate.name

When I run the statement "update ChildUpdate set parentName = 'Parent 2' where parentName = 'Parent 1'" with 2500 records in the ChildUpdate table and 1 record in the ParentUpdate table with only a single byte difference in data size in the ChildUpdate table, the performance decreases by 15 times.

When the ChildUpdate data column has exactly 14 bytes of the same character the runtime of the above query is about 500 milliseconds. When I add one more byte to the data column of ChildUpdate the performance all of a sudden becomes about 7500 milliseconds.

If i then decrease the data size back to 14 from 15 it's fast again. When i put it back to 15 it's slow again. This is reproducible every time.

Can you please help me figure out how to get the same fast performance without such seemingly random behaviour.

The query plans are below for both cases.

        projection = true
            constructor time (milliseconds) = 0
            open time (milliseconds) = 0
            next time (milliseconds) = 16
            close time (milliseconds) = 16
            restriction time (milliseconds) = 0
            projection time (milliseconds) = 0
            optimizer estimated row count: 51.50
            optimizer estimated cost: 796.12
        Source result set:
            Table Scan ResultSet for CHILDUPDATE at read committed isolation level using exclusive row locking chosen by the optimizer
            Number of opens = 1
            Rows seen = 2500
            Rows filtered = 0
            Fetch Size = 1
                constructor time (milliseconds) = 0
                open time (milliseconds) = 15
                next time (milliseconds) = 16
                close time (milliseconds) = 16
                next time in milliseconds/row = 0

            scan information:
                Bit set of columns fetched={0, 1}
                Number of columns fetched=2
                Number of pages visited=41
                Number of rows qualified=2500
                Number of rows visited=2500
                Scan type=heap
                start position:
                    null
                stop position:
                    null
                qualifiers:
                    Column[0][0] Id: 0
                    Operator: =
                    Ordered nulls: false
                    Unknown return value: false
                    Negate comparison result: false
                optimizer estimated row count: 51.50
                optimizer estimated cost: 796.12
total time: ~500 milliseconds

and the slow version

   Statement Name: 
    null
Statement Text: 
    update ChildUpdate set parentName = 'Parent 2' where parentName = 'Parent 1'
Parse Time: 0
Bind Time: 0
Optimize Time: 0
Generate Time: 0
Compile Time: 0
Execute Time: -1453199485700
Begin Compilation Timestamp : 2016-01-19 05:31:25.684
End Compilation Timestamp : 2016-01-19 05:31:25.684
Begin Execution Timestamp : 2016-01-19 05:31:25.7
End Execution Timestamp : 2016-01-19 05:31:33.141
Statement Execution Plan Text: 
Update ResultSet using row locking:
deferred: true
Rows updated = 2500
Indexes updated = 2
Execute Time = -1453199485747
    Normalize ResultSet:
    Number of opens = 1
    Rows seen = 2500
        constructor time (milliseconds) = 0
        open time (milliseconds) = 0
        next time (milliseconds) = 47
        close time (milliseconds) = 0
        optimizer estimated row count: 51.50
        optimizer estimated cost: 810.94
    Source result set:
        Project-Restrict ResultSet (3):
        Number of opens = 1
        Rows seen = 2500
        Rows filtered = 0
        restriction = false
        projection = true
            constructor time (milliseconds) = 0
            open time (milliseconds) = 0
            next time (milliseconds) = 32
            close time (milliseconds) = 0
            restriction time (milliseconds) = 0
            projection time (milliseconds) = 0
            optimizer estimated row count: 51.50
            optimizer estimated cost: 810.94
        Source result set:
            Project-Restrict ResultSet (2):
            Number of opens = 1
            Rows seen = 2500
            Rows filtered = 0
            restriction = false
            projection = true
                constructor time (milliseconds) = 0
                open time (milliseconds) = 0
                next time (milliseconds) = 32
                close time (milliseconds) = 0
                restriction time (milliseconds) = 0
                projection time (milliseconds) = 0
                optimizer estimated row count: 51.50
                optimizer estimated cost: 810.94
            Source result set:
                Index Scan ResultSet for CHILDUPDATE using index TESTINDEX at read committed isolation level using exclusive row locking chosen by the optimizer
                Number of opens = 1
                Rows seen = 2500
                Rows filtered = 0
                Fetch Size = 1
                    constructor time (milliseconds) = 0
                    open time (milliseconds) = 0
                    next time (milliseconds) = 32
                    close time (milliseconds) = 0
                    next time in milliseconds/row = 0

                scan information:
                    Bit set of columns fetched={0, 1, 2}
                    Number of columns fetched=3
                    Number of deleted rows visited=0
                    Number of pages visited=42
                    Number of rows qualified=2500
                    Number of rows visited=2500
                    Scan type=btree
                    Tree height=2
                    start position:
                        None
                    stop position:
                        None
                    qualifiers:
                        Column[0][0] Id: 1
                        Operator: =
                        Ordered nulls: false
                        Unknown return value: false
                        Negate comparison result: false
                    optimizer estimated row count: 51.50
                    optimizer estimated cost: 810.94
total time: ~7 seconds 500 milliseconds

please also see post:
http://stackoverflow.com/questions/34874762/apache-derby-simple-update-statement-performance-becomes-1500-worse-when-adding



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)