Bug 855674

Summary: search for operation schedule: PageList was passed an empty collection but 'totalSize' was 1
Product: [JBoss] JBoss Operations Network Reporter: Libor Zoubek <lzoubek>
Component: CLI, OperationsAssignee: Lukas Krejci <lkrejci>
Status: CLOSED CURRENTRELEASE QA Contact: Mike Foley <mfoley>
Severity: medium Docs Contact:
Priority: medium    
Version: JON 3.1.1, JON 3.1.0CC: hrupp, lkrejci, lzoubek, mazz, myarboro, theute, vlad.craciunoiu
Target Milestone: Alpha-x   
Target Release: JON 3.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-01-02 20:33:18 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
server.log
none
reproducer script none

Description Libor Zoubek 2012-09-09 21:04:34 UTC
Description of problem: I have a CLI script that calls an operation on resource and then it immediately starts querying for operation schedule id to check the result. From time to time my it fails.


Version-Release number of selected component (if applicable):
JON 3.1.1.CR2

How reproducible: 5-10%


Steps to Reproduce:
1. run a CLI script, that invokes "discovery" operation and starts checking operation result
  
Actual results:

This is what I get in CLI:

Exception in thread "main" org.rhq.enterprise.client.script.CLIScriptException: javax.script.ScriptException: sun.org.mozilla.javascript.internal.WrappedException: Wrapped javax.ejb.EJBException: [Warning] java.lang.IllegalArgumentException: PageList was passed an empty collection but 'totalSize' was 1, PageControl[page=0, size=1, sort[startTime DESC]] (<Unknown source>#980) in <Unknown source> at line number 980
	at org.rhq.enterprise.client.commands.ScriptCommand.executeScriptFile(ScriptCommand.java:298)
	at org.rhq.enterprise.client.commands.ScriptCommand.execute(ScriptCommand.java:108)
	at org.rhq.enterprise.client.ClientMain$StartupConfiguration.process(ClientMain.java:141)
	at org.rhq.enterprise.client.ClientMain.main(ClientMain.java:161)
Caused by: javax.script.ScriptException: sun.org.mozilla.javascript.internal.WrappedException: Wrapped javax.ejb.EJBException: [Warning] java.lang.IllegalArgumentException: PageList was passed an empty collection but 'totalSize' was 1, PageControl[page=0, size=1, sort[startTime DESC]]





Expected results: No exception


Additional info:

Comment 1 Libor Zoubek 2012-09-09 22:40:37 UTC
Created attachment 611285 [details]
server.log

Comment 3 Charles Crouch 2012-09-17 19:04:10 UTC
Targeting for consideration in jon312. If we have an automated way to cause this to fail 5-10% of the time, that's hopefully sufficient to give us some insight.

Comment 4 vlad crc 2013-05-24 12:30:40 UTC
I think is related to https://bugzilla.redhat.com/show_bug.cgi?id=773626.

Comment 5 John Mazzitelli 2013-07-03 13:16:53 UTC
Libor - can you attach your script that you used?

Comment 6 Heiko W. Rupp 2013-08-09 15:49:55 UTC
Seems virtually the same as Bug 972756

Comment 7 Libor Zoubek 2013-08-19 13:42:01 UTC
Created attachment 788074 [details]
reproducer script

Here is a repro-script. It does not retrieve operation history, but just asks for resources instead. When using "retrieve operation history" test I was not able to reproduce it even on JON 3.1.2 (we're randomly hitting this issue on this version).

Test works the way that it:
creates a new resource (network interface on as7)
and very often (with 10ms sleep time) asks server for createResourceHistory
and then for new child resource presence => here it fails

That file is large because it contains whole rhqapi.js, important part is at the bottom.

I am able to hit this bug with this script on RHQ 4.8 anytime when I run it around attempt 3-6.

Comment 8 Heiko W. Rupp 2013-08-27 10:36:24 UTC
I can reproduce (after fixing Bug 972756, which seems to be completely independent, even if the symptoms are similar) it with the supplied script, thanks Libor.

I think the underlying issue is a design problem, as the org.rhq.enterprise.server.util.CriteriaQueryRunner#execute method is not transactional and does this:

    results = new PageList<T>(getCollection(), getCount(), pageControl);

which means it first fires a query for the collection and then another one for the count.
When now a resource creation/deletion/... report is coming in after the SQL for getCollection() was fired and before getCount() has started, then the results may differ.

So basically we should either
- use a more clever query to return count and collection in one go
or
- use a transaction, so that the database keeps the state consistent.

This may not be enough for other cases of this "PageList .. " error

--- server log ---

Caused by: java.lang.IllegalArgumentException: PageList was passed an empty collection but 'totalSize' was 1, PageControl[page=0, size=-1]
	at org.rhq.core.domain.util.PageList.<init>(PageList.java:87) [rhq-core-domain-ejb3.jar:4.9.0-SNAPSHOT]
	at org.rhq.enterprise.server.util.CriteriaQueryRunner.execute(CriteriaQueryRunner.java:70) [rhq-server.jar:4.9.0-SNAPSHOT]
	at org.rhq.enterprise.server.resource.ResourceManagerBean.findResourcesByCriteria(ResourceManagerBean.java:2595) [rhq-server.jar:4.9.0-SNAPSHOT]

Comment 9 Lukas Krejci 2013-08-27 13:24:03 UTC
The org.rhq.enterprise.server.util.CriteriaQueryRunner#execute is not transactional in and of itself, because the runner is not an EJB. That said, the runner is called from SLSBs. The SLSB method in question for the repro script is ResourceManagerBean#findResourcesByCriteria, which doesn't specify a transaction attribute and therefore defaults to "REQUIRED". Hence the criteria DOES run in a transaction.

The problem is that our datasource, RHQDS, specifies the transaction isolation level as TRANSACTION_READ_COMMITTED. That isolation level allows for "phantom reads", i.e. a single select can return different number of rows depending on other concurrently committed transactions.

Therefore I cannot see many ways forward with this. I'd argue against upping the transaction isolation, because that has high performance cost and has to be set datasource-wide.

The only other option is to detect this particular error inside the criteria runner and re-run the getCollection() and getCount() until the sizes match or somehow cleverly rewrite the queries such that they return the count and the results within 1 query.

Comment 10 Lukas Krejci 2013-09-02 11:24:34 UTC
commit dc6a1fedea3bfa9efdfde446d1712d353a591778
Author: Lukas Krejci <lkrejci>
Date:   Thu Aug 29 18:34:45 2013 +0200

    [BZ 855674] - Get rid of the dreaded "PageList was passed an empty collection but 'totalSize' was X" exception.
    
    The main part of the fix is just the realization that the "error"
    condition for which the exception was thrown is actually no error but can
    be triggered by the mere fact that we use READ_COMMITTED isolation level.
    The fact that a user can go past the last page of a result is actually also
    not an error and can be triggered by for example a massive change in the
    available data between the user asking for first and second page.
    
    I think it is better to stop treating all such conditions as errors and
    instead provide the user with means of detecting such states.
    
    For that a new method on pagelist was introduced:
    PageList.isConsistent(), which calls out to PageControl.isConsistentWith()
    that check if the data and total size of the page list are consistent with
    the page control.
    
    This in turn is used by the CriteriaQueryRunner to re-attempt the queries
    if it finds the inconsistency (which is most possibly caused by the phantom
    read due to our transaction isolation level).

Comment 11 Lukas Krejci 2013-09-03 16:44:45 UTC
commit e82330bd6af45fe519f2eb85e81ca02a97b1eb04
Author: Lukas Krejci <lkrejci>
Date:   Tue Sep 3 18:42:50 2013 +0200

    [BZ 855674] - Refactored the phantom-read detection out of CriteriaQueryRunner
    
    This was to make it testable but more importantly reusable by ordinary SLSB
    methods (that don't use criteria queries).
    
    Also added unit tests for the phantom-read detection (now placed in
    QueryUtility in server jar) and for PageControl in domain jar.

Comment 12 Libor Zoubek 2013-09-24 13:10:52 UTC
repro script does not hit this issue anymore on JON 3.2.ER1