performance issues with GeoServer SQLView

[bartvde]

If you haven't already, it might be good to put heads together (Rob, Martin, and/or Ian) on this.

Ian put together some notes some time ago on investigating our previous "oracle running amok" issues. I pasted them here (lacking that OpenGeo knowledge base we've talked about): http://projects.opengeo.org/suite/wiki/Oracle#DebuggingRunawayProcesses

The runaway process we were seeing before may have been a very different issue, but it might be interesting to trace the process to see what SQL is being executed during your 3 minute wait.

And, I may be inventing things, but I recall Martin commenting previously on the outlandish (perhaps too strong) number of connections created with Oracle.

Tim

Thanks Rob for upgrading to 2.5, I was able to use the CITATION_OPPORTUNITY_VW just fine now.

However wrt the SQL View [1], the same issue is also present on Suite 2.5 unfortunately.

So this needs further investigation, actually if you wait long enough a GetFeature request comes back, it just takes too much time (almost 3 minutes for 10 features/entries).

Request: getServiceInfo 2012-06-05 11:21:42,922 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:22:30,117 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:22:30,117 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:22:30,117 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:22:30,118 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:22:30,118 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:22:30,118 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:22:30,118 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:23:22,410 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:23:22,410 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:24:15,410 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:24:15,410 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:24:15,410 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:24:15,410 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:24:15,410 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:24:15,411 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:24:15,412 INFO [org.geoserver.wfs] - Request: getFeature service = WFS version = 1.0.0 baseUrl = http://sfpark.demo.opengeo.org:80/geoserver/ query[0]: typeName[0] = {http://www.sfpark.org/SFenforce}DISPOSITION_CODES outputFormat = GML2 resultType = results 2012-06-05 11:24:15,442 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:24:15,442 DEBUG [org.geotools.jdbc] - SELECT * FROM (SELECT VALUE,DESCRIPTION FROM (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE) WHERE ROWNUM <= 1000000 2012-06-05 11:24:15,459 DEBUG [org.geotools.gml] - closing reader org.geotools.data.store.ContentFeatureCollection$WrappingFeatureIterator@670b4920 2012-06-05 11:24:15,459 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION

Publishing the SQL view already takes a long time and creates a lot of database connections, I am not sure what's going on, this is the log from saving the SQL view:

bartvde@sfpark:/usr/share/opengeo-suite-data/geoserver_data/user_projections$ tail -f /usr/share/opengeo-suite-data/geoserver_data/logs/geoserver.log 2012-06-05 11:15:18,505 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:15:48,094 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:15:48,382 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:15:48,383 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:15:48,383 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:15:48,383 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:15:48,384 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:15:48,387 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:16:20,895 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:16:20,896 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:16:52,910 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:16:52,910 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:16:52,910 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:16:52,910 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:16:52,910 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:16:52,911 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:16:52,954 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:17:27,418 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:17:27,418 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:18:05,327 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:18:05,327 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:18:05,327 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:18:05,327 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:18:05,327 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:18:05,328 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:18:05,328 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:18:44,369 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:18:44,369 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:19:26,834 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:19:26,834 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:19:26,834 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:19:26,834 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:19:26,835 DEBUG [org.geotools.jdbc] - Gathering sql view result structure: select * from (select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1) VTABLE where 1 = 0 2012-06-05 11:19:26,835 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:20:25,405 INFO [org.geoserver.gwc.layer] - Saving SFenforce:DISPOSITION_CODES 2012-06-05 11:20:25,563 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:20:25,573 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:20:25,617 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION 2012-06-05 11:20:25,618 DEBUG [org.geotools.jdbc] - CREATE CONNECTION 2012-06-05 11:20:25,661 DEBUG [org.geotools.jdbc] - CLOSE CONNECTION

[1] select to_number(COLUMN_VALUE) AS VALUE, DESCRIPTION from ALLOWED_VALUES where TABLE_NAME = 'RT_CITATION_OPPORTUNITY' and COLUMN_NAME = 'DISPOSITION_CODE' order by 1

Best regards, Bart

[rmarianski]

Hey @bartvde, would it it be possible to remove the assignment to me here?

[bartvde]

sure seems you've just done it yourself?

[rmarianski]

Weird, it wasn't letting me but the the activity stream suggests that I did it? In any case, thanks!