Bug 58489

Summary: QueryStatsComparator throws IllegalArgumentException: Comparison method violates its general contract!
Product: Tomcat Modules Reporter: Jan Havel <havelj1>
Component: jdbc-poolAssignee: Tomcat Developers Mailing List <dev>
Status: REOPENED ---    
Severity: major CC: bill_t_wang, c.webb, d.france, havelj1, ns142e, spiffy2man
Priority: P2    
Version: unspecified   
Target Milestone: ---   
Hardware: All   
OS: All   
Attachments: JUnit test to show the exception
Tomcat-7.0.68 - Caused by: java.lang.IllegalArgumentException: Comparison method violates its general contract!
extract the information to sort on from the QueryStats and sort on that information

Description Jan Havel 2015-10-08 14:08:49 UTC
Created attachment 33177 [details]
JUnit test to show the exception

Overview: 

QueryStatsComparator may throw java.lang.IllegalArgumentException: Comparison method violates its general contract! 
This happens in specific situations depending on the data in the reported queries. In our environment this occurs every time we keep the server running until the maxCapacity (1000 items) is reached and the removeOldest method is called. I have managed to narrow down the test data from more than 1000 records to around 40 items and created a JUnit test to showcase the error. I needed to copy some parts out of the SlowQueryReport class and made some simplifications as the QueryStatsComparator is not reachable from outside.

Steps to Reproduce: 

Please use the attached JUnit source code to reproduce this error.

Additional Builds and Platforms: 

This bug seems to happen on all platforms.
We are using Tomcat 8, tomcat-dbcp 8.0.24, JDK 1.80.0_60.

Additional Information: 

It seems to be a problem of the first two lines of the QueryStatsComparator. Note that a single change in the data of the unit test may cause the Exception not to occur.

Stacktrace:

java.lang.IllegalArgumentException: Comparison method violates its general contract!
	at java.util.TimSort.mergeLo(TimSort.java:773)
	at java.util.TimSort.mergeAt(TimSort.java:510)
	at java.util.TimSort.mergeCollapse(TimSort.java:435)
	at java.util.TimSort.sort(TimSort.java:241)
	at java.util.Arrays.sort(Arrays.java:1512)
	at java.util.ArrayList.sort(ArrayList.java:1454)
	at java.util.Collections.sort(Collections.java:175)
	at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.removeOldest(SlowQueryReport.java:218)
	at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.getQueryStats(SlowQueryReport.java:205)
	at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.reportQuery(SlowQueryReport.java:119)
	at org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementProxy.invoke(AbstractQueryReport.java:254)
Comment 1 Remy Tiitre 2015-10-14 11:23:40 UTC
SlowQueryReport.java line 478 is the reason for this crash. compare(x,x) should not return 1.

if (stats1.lastInvocation == 0 && stats2.lastInvocation != 0) return 1;
Comment 2 Felix Schumacher 2015-10-15 10:42:45 UTC
Thanks for the report.

Will be fixed with 8.0.29. Maybe you could give the trunk of tomcat 8 a try?
Comment 3 Remy Tiitre 2015-10-15 10:46:12 UTC
I forgot to mention that it affects the Tomcat 7 as well. (Thats where I have this issue right now). I think the bug was introduced with 7.0.63 release.
Comment 4 Felix Schumacher 2015-10-15 10:59:01 UTC
I have ported the fix back to tomcat 7 as well. It will be in tomcat 7.0.66.

And again it would be nice, if you could test the current trunk of tomcat 7.
Comment 5 Nishan 2016-07-21 16:12:47 UTC
Created attachment 34060 [details]
Tomcat-7.0.68 - Caused by: java.lang.IllegalArgumentException: Comparison method violates its general contract!
Comment 6 Nishan 2016-07-21 16:13:24 UTC
Comment on attachment 34060 [details]
Tomcat-7.0.68 - Caused by: java.lang.IllegalArgumentException: Comparison method violates its general contract!

We are facing same exception in our env’s when we have upgraded our setup from: 

	From :
		Java : jdk1.6.0_45
		Java Apache Tomcat Version 7.0.37 
To 
		Java : jdk1.8.0_92
		Java Apache Tomcat Version 7.0.68


Sample SQL which during which this exception occurred :
SELECT DISTINCT c.comp_id AS dbkey
FROM
  equipment e,
  component c
WHERE
  e.equip_id = c.equip_id AND
((e.ptnii_equip_name = 'cl2oh406me3' AND c.beg_slot = 7) AND trunc(c.port/1000)-1 = '2') AND mod(c.port, 1000) = 0

JFYI : Result I see in TOAD by directly executing above SQL is only 1 record with value as :
		1166506

Caused by: java.lang.IllegalArgumentException: Comparison method violates its general contract!
        at java.util.TimSort.mergeLo(TimSort.java:777)
        at java.util.TimSort.mergeAt(TimSort.java:514)
        at java.util.TimSort.mergeCollapse(TimSort.java:439)
        at java.util.TimSort.sort(TimSort.java:245)
        at java.util.Arrays.sort(Arrays.java:1512)
        at java.util.ArrayList.sort(ArrayList.java:1454)
        at java.util.Collections.sort(Collections.java:175)
        at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.removeOldest(SlowQueryReport.java:213)
        at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.getQueryStats(SlowQueryReport.java:200)
        at org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport.reportQuery(SlowQueryReport.java:110)
        at org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementProxy.invoke(AbstractQueryReport.java:256)
        at com.sun.proxy.$Proxy666.executeQuery(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor4273.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tomcat.jdbc.pool.interceptor.AbstractQueryReport$StatementProxy.invoke(AbstractQueryReport.java:235)
        at com.sun.proxy.$Proxy666.executeQuery(Unknown Source)
        at com.att.lpp.pa.core.asset.dao.AssetSearchDaoImpl.findAssetDbkeys(AssetSearchDaoImpl.java:116)
Comment 7 Felix Schumacher 2016-07-24 10:30:39 UTC
I believe this can happen, when the QueryStats change while the list of stats get sorted.

I see three ways to go:
 1. add synchronization, so that the stats don't change while the list gets sorted
 2. extract the information to sort on from the QueryStats and sort on that information
 3. make QueryStats immutable and change the QueryStats instances, when the stats gets updated

The first path probably will slow down the execution of jdbc calls.
The second one will be more memory intensive, but relatively simple to implement. 
The third seems to be the one where we would have to do the most work.

I tend to go for option two. What do you think?
Comment 8 Felix Schumacher 2016-07-24 10:31:43 UTC
*** Bug 59890 has been marked as a duplicate of this bug. ***
Comment 9 Michael Osipov 2017-08-07 12:14:41 UTC
We still suffer from this on Tomcat 8.5.x. I would go for option two as Felix has proposed.
Comment 10 bill_t_wang 2020-05-13 03:51:41 UTC
Created attachment 37237 [details]
extract the information to sort on from the QueryStats and sort on that information

I resolved this bug in SlowQueryReport,using the second proposal by Felix Schumacher -- "extract the information to sort on from the QueryStats and sort on that information".

1, add a constructor in the inner class QueryStats for QueryStats clone
        /**
         * Create a new QueryStats object based on another QueryStats object.
         * For resolving Bug 58489, https://bz.apache.org/bugzilla/show_bug.cgi?id=58489
         * @param qs
         */
        QueryStats(QueryStats qs){
            this.query = qs.query;
            this.nrOfInvocations = qs.nrOfInvocations;
            this.maxInvocationTime = qs.maxInvocationTime;
            this.maxInvocationDate = qs.maxInvocationDate;
            this.minInvocationTime = qs.minInvocationTime;
            this.minInvocationDate = qs.minInvocationDate;
            this.totalInvocationTime = qs.totalInvocationTime;
            this.failures = qs.failures;
            this.prepareCount = qs.prepareCount;
            this.prepareTime = qs.prepareTime;
            this.lastInvocation = qs.lastInvocation;
        }

2, modify method removeOldest
    protected void removeOldest(ConcurrentHashMap<String,QueryStats> queries) {
        ArrayList<QueryStats> list = new ArrayList<>(queries.values());
        //For resolving Bug 58489, https://bz.apache.org/bugzilla/show_bug.cgi?id=58489
        //make a list of cloned QueryStats objects
        for(int i=0; i<list.size(); i++){
            list.set(i, new QueryStats(list.get(i)));
        }
        //
        Collections.sort(list, queryStatsComparator);
        int removeIndex = 0;
        while (queries.size() > maxQueries) {
            String sql = list.get(removeIndex).getQuery();
            queries.remove(sql);
            if (log.isDebugEnabled()) log.debug("Removing slow query, capacity reached:"+sql);
            removeIndex++;
        }
    }
Comment 11 bill_t_wang 2020-05-13 03:55:13 UTC
I resolved this bug in SlowQueryReport,using the second proposal by Felix Schumacher -- "extract the information to sort on from the QueryStats and sort on that information".

1, add a constructor in the inner class QueryStats for QueryStats clone
        /**
         * Create a new QueryStats object based on another QueryStats object.
         * For resolving Bug 58489, https://bz.apache.org/bugzilla/show_bug.cgi?id=58489
         * @param qs
         */
        QueryStats(QueryStats qs){
            this.query = qs.query;
            this.nrOfInvocations = qs.nrOfInvocations;
            this.maxInvocationTime = qs.maxInvocationTime;
            this.maxInvocationDate = qs.maxInvocationDate;
            this.minInvocationTime = qs.minInvocationTime;
            this.minInvocationDate = qs.minInvocationDate;
            this.totalInvocationTime = qs.totalInvocationTime;
            this.failures = qs.failures;
            this.prepareCount = qs.prepareCount;
            this.prepareTime = qs.prepareTime;
            this.lastInvocation = qs.lastInvocation;
        }

2, modify method removeOldest
    protected void removeOldest(ConcurrentHashMap<String,QueryStats> queries) {
        ArrayList<QueryStats> list = new ArrayList<>(queries.values());
        //For resolving Bug 58489, https://bz.apache.org/bugzilla/show_bug.cgi?id=58489
        //make a list of cloned QueryStats objects
        for(int i=0; i<list.size(); i++){
            list.set(i, new QueryStats(list.get(i)));
        }
        //
        Collections.sort(list, queryStatsComparator);
        int removeIndex = 0;
        while (queries.size() > maxQueries) {
            String sql = list.get(removeIndex).getQuery();
            queries.remove(sql);
            if (log.isDebugEnabled()) log.debug("Removing slow query, capacity reached:"+sql);
            removeIndex++;
        }
    }
Comment 12 Christopher Schultz 2020-05-13 14:45:41 UTC
*** Bug 64415 has been marked as a duplicate of this bug. ***
Comment 13 Christopher Schultz 2020-05-13 14:47:23 UTC
There is some good information (IMHO) in bug #64415 about this.

My method is essentially the same, except that I don't copy the whole QueryStats object - only what is required to perform the evaluation.

I also protect against the data being updated during the copy/sort with an additional check.

Let me know what you think.