Mailing-List: contact derby-user-help@db.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Derby Discussion" <derby-user@db.apache.org>
Received-SPF: neutral (nike.apache.org: local policy)
Message-ID: <515B2DE1.2080906@sbcglobal.net>
Date: Tue, 02 Apr 2013 12:13:37 -0700
From: Mike Matrigali <mikem_app@sbcglobal.net>
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64;
 rv:17.0) Gecko/20130307 Thunderbird/17.0.4
MIME-Version: 1.0
To: Derby Discussion <derby-user@db.apache.org>
Subject: Re: Peculiar sorting behaviour?
References: <515AA74D.3030507@gmail.com> <87d2ud0wvn.fsf@oracle.com>
 <515B0D01.3020804@gmail.com> <515B0FD3.8080903@sbcglobal.net>
 <515B25D2.10508@gmail.com>
In-Reply-To: <515B25D2.10508@gmail.com>
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

need ddl for both item_usage (i think you posted this in 1st posting) 
and tests (don't see this one) tables, to read the query plan.
I read them bottom up, so first thing is to see what ordering is 
expected from the index scan, so looking for TESTS ddl and TEST_1 
constraint:
Index Scan ResultSet for TESTS using constraint TESTS_1 at read
 > uncommitted isolation level using share row locking chosen by the 
optimizer
On 4/2/2013 11:39 AM, John English wrote:
> On 02/04/2013 20:05, Katherine Marsden wrote:
>> In derby.properties set:
>>
>> derby.language.logStatementText=true
>> derby.language.logQueryPlan=true
>>      If you can post  the two plans, someone might be able to give you
>> the
>> optimizer overrides to force the plan with incorrect sorting.
>
> Here it is (long!). It starts with the incorrect query; I then change
> the ORDER BY clause and reload the page, which then gives the correct
> results. There are some other queries mixed in, but I wasn't sure what
> would be relevant so I left it uncut.
>
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID =
> 7222148), (SESSIONID = 26), (DATABASE = ../db/db_copy), (DRDAID = null),
> Executing prepared statement: SELECT tests.id,tests.item,title FROM
> tests,item_usage WHERE username=? AND user_role>=3 AND
> item_usage.item=tests.item ORDER BY tests.item,title :End prepared
> statement with 1 parameters begin parameter #1: TAMMY :end parameter
> Tue Apr 02 21:14:23 IDT 2013 Thread[qtp31568925-37,5,main] (XID =
> 7222148), (SESSIONID = 26), SELECT tests.id,tests.item,title FROM
> tests,item_usage WHERE username=? AND user_role>=3 AND
> item_usage.item=tests.item ORDER BY tests.item,title ******* Scroll
> Insensitive ResultSet:
> Number of opens = 1
> Rows seen = 30
> Number of reads from hash table = 30
> Number of writes to hash table = 30
>    constructor time (milliseconds) = 0
>    open time (milliseconds) = 0
>    next time (milliseconds) = 0
>    close time (milliseconds) = 0
>    optimizer estimated row count: 19.34
>    optimizer estimated cost: 5186.92
> Source result set:
>    Project-Restrict ResultSet (7):
>    Number of opens = 1
>    Rows seen = 30
>    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: 19.34
>      optimizer estimated cost: 5186.92
>    Source result set:
>      Nested Loop Join ResultSet:
>      Number of opens = 1
>      Rows seen from the left = 5
>      Rows seen from the right = 30
>      Rows filtered = 0
>      Rows returned = 30
>        constructor time (milliseconds) = 0
>        open time (milliseconds) = 0
>        next time (milliseconds) = 0
>        close time (milliseconds) = 0
>        optimizer estimated row count: 19.34
>        optimizer estimated cost: 5186.92
>      Left result set:
>        Project-Restrict ResultSet (4):
>        Number of opens = 1
>        Rows seen = 5
>        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: 1.80
>          optimizer estimated cost: 17.01
>        Source result set:
>          Index Row to Base Row ResultSet for ITEM_USAGE:
>          Number of opens = 1
>          Rows seen = 5
>          Columns accessed from heap = {0, 1, 2}
>            constructor time (milliseconds) = 0
>            open time (milliseconds) = 0
>            next time (milliseconds) = 0
>            close time (milliseconds) = 0
>            optimizer estimated row count: 1.80
>            optimizer estimated cost: 17.01
>            Index Scan ResultSet for ITEM_USAGE using constraint
> ITEM_USAGE_1 at read uncommitted isolation level using share row locking
> chosen by the optimizer
>            Number of opens = 1
>            Rows seen = 5
>            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=2
>              Number of rows qualified=5
>              Number of rows visited=6
>              Scan type=btree
>              Tree height=2
>              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: 1.80
>              optimizer estimated cost: 17.01
>
>      Right result set:
>        Index Row to Base Row ResultSet for TESTS:
>        Number of opens = 5
>        Rows seen = 30
>        Columns accessed from heap = {0, 1, 2}
>          constructor time (milliseconds) = 0
>          open time (milliseconds) = 0
>          next time (milliseconds) = 0
>          close time (milliseconds) = 0
>          optimizer estimated row count: 19.34
>          optimizer estimated cost: 5169.91
>          Index Scan ResultSet for TESTS using constraint TESTS_1 at read
> uncommitted isolation level using share row locking chosen by the optimizer
>          Number of opens = 5
>          Rows seen = 30
>          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={0, 2}
>            Number of columns fetched=2
>            Number of deleted rows visited=9
>            Number of pages visited=5
>            Number of rows qualified=30
>            Number of rows visited=43
>            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: 19.34
>            optimizer estimated cost: 5169.91
>
>
>