[ https://issues.apache.org/jira/browse/DERBY-6858?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Brett Bergquist updated DERBY-6858: ----------------------------------- Attachment: profile.nps jvisualvm profiler snapshot > 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.11.1.1, 10.12.1.1 > Environment: windows 7 64 bit > Reporter: somebody > Priority: Blocker > Attachments: profile.nps, repro.java, repro.java, repro.java > > > 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)