I’m trying to debug what looks like a proxy issue with setting up a cascading WMS datastore and I think I’ve found an issue with the way GeoServer requests capabilties documents.
If you follow this log (where I’ve added extra logging to try to see what happens):
27 Aug 16:42:56 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.SimpleHttpClient@anonymised.com
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:43:02 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:43:28 DEBUG [org.geotools.data.ows] - Executed request to URL: http://172.30.2.1:8080/geoserver/ows?REQUEST=GetCapabilities&VERSION=1.1.1&SERVICE=WMS
27 Aug 16:43:28 TRACE [org.geotools.data.ows] - got response to getCapabilities with version=1.1.1
27 Aug 16:43:28 TRACE [org.geotools.data.ows] - got good capabilities version
27 Aug 16:44:10 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.SimpleHttpClient@anonymised.com
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:44:23 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:44:24 DEBUG [org.geotools.data.ows] - Executed request to URL: http://172.30.2.1:8080/geoserver/ows?REQUEST=GetCapabilities&VERSION=1.1.1&SERVICE=WMS
27 Aug 16:44:24 TRACE [org.geotools.data.ows] - got response to getCapabilities with version=1.1.1
27 Aug 16:44:24 TRACE [org.geotools.data.ows] - got good capabilities version
27 Aug 16:45:00 DEBUG [org.geotools.data.ows] - Found ‘http.proxyHost’ Java System property. Using it as proxy server. Port: 80
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.MultithreadedHttpClient@anonymised.com
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:45:12 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:45:13 ERROR [net.refractions.xml.sax] - FATAL Content is not allowed in prolog.
27 Aug 16:45:13 ERROR [net.refractions.xml.sax] - col 1, line 1
27 Aug 16:45:13 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.0
You’ll see that hitting save on the WMS store page triggers three requests for a 1.1.1 getcapabiltities - the first two come from the validator (not sure why it does it twice yet) which uses a SimpleHttpClient that works and then org.geoserver.catalog.ResourcePool.getWebMapServer tries to fetch them using a MultithreadedHttpClient (which has picked up the proxy environment variable) and then fails - as my proxy seems to break the xml.
So obviously I need to fix the proxy - but it seems to me that all those tests should use the same HttpClient and probably cache the result as it can take some time to make the request.
Am I right in this analysis and should I raise a bug/enhancement? or am I completely missunderstanding how this works?
I see, so a trouble with version negotiation at the gt-wms client level?
I did add a constructor that allow you to feed in a cached capabilities document ( so uDig could avoid making multiple requests and cache between runs ).
I’m trying to debug what looks like a proxy issue with setting up a cascading WMS datastore and I think I’ve found an issue with the way GeoServer requests capabilties documents.
If you follow this log (where I’ve added extra logging to try to see what happens):
27 Aug 16:42:56 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.SimpleHttpClient@anonymised.com
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:43:01 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:43:02 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:43:28 DEBUG [org.geotools.data.ows] - Executed request to URL: http://172.30.2.1:8080/geoserver/ows?REQUEST=GetCapabilities&VERSION=1.1.1&SERVICE=WMS
27 Aug 16:43:28 TRACE [org.geotools.data.ows] - got response to getCapabilities with version=1.1.1
27 Aug 16:43:28 TRACE [org.geotools.data.ows] - got good capabilities version
27 Aug 16:44:10 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.SimpleHttpClient@anonymised.com
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:44:22 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:44:23 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:44:24 DEBUG [org.geotools.data.ows] - Executed request to URL: http://172.30.2.1:8080/geoserver/ows?REQUEST=GetCapabilities&VERSION=1.1.1&SERVICE=WMS
27 Aug 16:44:24 TRACE [org.geotools.data.ows] - got response to getCapabilities with version=1.1.1
27 Aug 16:44:24 TRACE [org.geotools.data.ows] - got good capabilities version
27 Aug 16:45:00 DEBUG [org.geotools.data.ows] - Found ‘http.proxyHost’ Java System property. Using it as proxy server. Port: 80
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - Requesting http://172.30.2.1:8080/geoserver/ows?service=wms&version=1.1.1&request=GetCapabilities using org.geotools.data.ows.MultithreadedHttpClient@anonymised.com
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - About to negotiate 4 versions
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - checking for supplied version
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - found existing version 1.1.1
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - existing version 1.1.1 matches spec number 2
27 Aug 16:45:10 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.1
27 Aug 16:45:12 TRACE [org.geotools.data.wms.response.WMSGetCapabilities] - trying to get a WMS Capabilities
27 Aug 16:45:13 ERROR [net.refractions.xml.sax] - FATAL Content is not allowed in prolog.
27 Aug 16:45:13 ERROR [net.refractions.xml.sax] - col 1, line 1
27 Aug 16:45:13 TRACE [org.geotools.data.ows] - looking up capabilities for 1.1.0
You’ll see that hitting save on the WMS store page triggers three requests for a 1.1.1 getcapabiltities - the first two come from the validator (not sure why it does it twice yet) which uses a SimpleHttpClient that works and then org.geoserver.catalog.ResourcePool.getWebMapServer tries to fetch them using a MultithreadedHttpClient (which has picked up the proxy environment variable) and then fails - as my proxy seems to break the xml.
So obviously I need to fix the proxy - but it seems to me that all those tests should use the same HttpClient and probably cache the result as it can take some time to make the request.
Am I right in this analysis and should I raise a bug/enhancement? or am I completely missunderstanding how this works?
Ian
–
Ian Turton
Learn the latest–Visual Studio 2012, SharePoint 2013, SQL 2012, more!
Discover the easy way to master current and previous Microsoft technologies
and advance your career. Get an incredible 1,500+ hours of step-by-step
tutorial videos with LearnDevNow. Subscribe today and save! http://pubads.g.doubleclick.net/gampad/clk?id=58040911&iu=/4140/ostg.clktrk
On Thu, Aug 29, 2013 at 2:19 AM, Jody Garnett <jody.garnett@anonymised.com>wrote:
I see, so a trouble with version negotiation at the gt-wms client level?
I did add a constructor that allow you to feed in a cached capabilities
document ( so uDig could avoid making multiple requests and cache between
runs ).
On 29 August 2013 07:28, Andrea Aime <andrea.aime@anonymised.com> wrote:
On Thu, Aug 29, 2013 at 2:19 AM, Jody Garnett <jody.garnett@anonymised.com>wrote:
I see, so a trouble with version negotiation at the gt-wms client level?
I did add a constructor that allow you to feed in a cached capabilities
document ( so uDig could avoid making multiple requests and cache between
runs ).
GeoServer caches and reuses the whole WebMapServer object, achieving a
similar effect:
Creating a WMS store doesn't seem to use that path (or doesn't populate the
cache) - I'll see if I can find time to debug further tonight.
On a related note, might it be that the many requests are due to the proxy
ruining the xml document contents?
The proxy only comes into play on the third request (with the
multihttpclient) - The first two requests are from the page validator,
while the final one goes through the cache (which is empty).
On Thu, Aug 29, 2013 at 10:09 AM, Ian Turton <ijturton@anonymised.com> wrote:
On 29 August 2013 07:28, Andrea Aime <andrea.aime@anonymised.com> wrote:
On Thu, Aug 29, 2013 at 2:19 AM, Jody Garnett <jody.garnett@anonymised.com>wrote:
I see, so a trouble with version negotiation at the gt-wms client level?
I did add a constructor that allow you to feed in a cached capabilities
document ( so uDig could avoid making multiple requests and cache between
runs ).
GeoServer caches and reuses the whole WebMapServer object, achieving a
similar effect:
Creating a WMS store doesn't seem to use that path (or doesn't populate
the cache) - I'll see if I can find time to debug further tonight.
I believe it's normal, the first creation is not to be cached since we
don't yet know if the store will be saved or not (we first create to
validate, then save the store)
On a related note, might it be that the many requests are due to the
proxy ruining the xml document contents?
The proxy only comes into play on the third request (with the
multihttpclient) - The first two requests are from the page validator,
while the final one goes through the cache (which is empty).