[Geoserver-users] getfeatureinfo exception

GeoServer GeoServer User
1

Response from running a getfeatureinfo says…

Unable to generate feature information java.lang.RuntimeException: java.io.IOException
no features were found.

The following is appended to the error log.

This happens intermittently, but at least a few times a day. Restarting seems to resolve the issue. Any ideas?

2009-05-13 09:11:21,181 WARN [geotools.jdbc] - Error occurred closing connection
2009-05-13 09:11:21,181 WARN [wms.featureinfo] - Error generating getFeaturInfo, HTML format
java.lang.RuntimeException: java.io.IOException
at org.geotools.data.store.ContentFeatureCollection.features(ContentFeatureCollection.java:229)
at org.geotools.data.crs.ForceCoordinateSystemFeatureResults.openIterator(ForceCoordinateSystemFeatureResults.java:93)
at org.geotools.feature.collection.AbstractFeatureCollection.features(AbstractFeatureCollection.java:64)
at org.vfny.geoserver.wms.responses.featureInfo.TextFeatureInfoResponse.writeTo(TextFeatureInfoResponse.java:97)
at org.vfny.geoserver.wms.responses.GetFeatureInfoResponse.writeTo(GetFeatureInfoResponse.java:175)
at org.geoserver.ows.adapters.ResponseAdapter.write(ResponseAdapter.java:60)
at org.geoserver.ows.Dispatcher.response(Dispatcher.java:712)
at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:216)
at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
at org.vfny.geoserver.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:108)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:264)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107)
at org.acegisecurity.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.ui.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.ui.basicauth.BasicProcessingFilter.doFilter(BasicProcessingFilter.java:178)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:229)
at org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
at org.acegisecurity.util.FilterChainProxy.doFilter(FilterChainProxy.java:148)
at org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.geoserver.filters.LoggingFilter.doFilter(LoggingFilter.java:73)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.geoserver.filters.ReverseProxyFilter.doFilter(ReverseProxyFilter.java:163)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.geoserver.filters.GZIPFilter.doFilter(GZIPFilter.java:41)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:726)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:206)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:324)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:505)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:828)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:514)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:380)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:395)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:450)
Caused by: java.io.IOException
at org.geotools.jdbc.JDBCFeatureSource.getReaderInternal(JDBCFeatureSource.java:526)
at org.geotools.data.store.ContentFeatureSource.getReader(ContentFeatureSource.java:508)
at org.geotools.data.store.ContentFeatureCollection.features(ContentFeatureCollection.java:226)
… 56 more
Caused by: java.sql.SQLException: Io exception: Socket closed
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:146)
at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:255)
at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:977)
at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1060)
at oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:839)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1132)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3316)
at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3361)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
at org.geotools.jdbc.JDBCFeatureReader.(JDBCFeatureReader.java:153)
at org.geotools.jdbc.JDBCFeatureSource.getReaderInternal(JDBCFeatureSource.java:514)
… 58 more

2

Aaron_Gundel@anonymised.com ha scritto:

Response from running a getfeatureinfo says...

Unable to generate feature information java.lang.RuntimeException: java.io.IOException
no features were found.

The following is appended to the error log.

This happens intermittently, but at least a few times a day. Restarting seems to resolve the issue. Any ideas?

It seems Oracle is closing the connection the store is using
forcibly.
Do you have any hard timeout on the database connections that would
make Oracle destroy them even if a client is using them?
GeoServer is using a connection pool, so the connections are long
lived (reopening a connection for each request would make GeoServer
crawl, getting a new connection with Oracle is incredibly expensive)

Cheers
Andrea

--
Andrea Aime
OpenGeo - http://opengeo.org
Expert service straight from the developers.

3

Hi Andrea,

I sent your note off to my DBA to see if we’re imposing a connection timeout on the geoserver user. He replied in the negative; the geoserver user is under our default profile, and there is no timeout imposed under that profile. He sent the a screenshot of the profile to confirm. Is there anything else it could be?

Aaron

Andrea Aime aaime@anonymised.com

05/13/2009 09:21 AM

To
Aaron_Gundel@anonymised.com

cc
geoserver-users@lists.sourceforge.net

Subject
Re: [Geoserver-users] getfeatureinfo exception

Aaron_Gundel@anonymised.com ha scritto:
>
> Response from running a getfeatureinfo says...
>
> Unable to generate feature information java.lang.RuntimeException:
> java.io.IOException
> no features were found.
>
> The following is appended to the error log.
>
> This happens intermittently, but at least a few times a day. Restarting
> seems to resolve the issue. Any ideas?

It seems Oracle is closing the connection the store is using
forcibly.
Do you have any hard timeout on the database connections that would
make Oracle destroy them even if a client is using them?
GeoServer is using a connection pool, so the connections are long
lived (reopening a connection for each request would make GeoServer
crawl, getting a new connection with Oracle is incredibly expensive)

Cheers
Andrea

--
Andrea Aime
OpenGeo - http://opengeo.org
Expert service straight from the developers.

oracle_profile.gif

4

Aaron_Gundel@anonymised.com ha scritto:

Hi Andrea,

I sent your note off to my DBA to see if we're imposing a connection timeout on the geoserver user. He replied in the negative; the geoserver user is under our default profile, and there is no timeout imposed under that profile. He sent the a screenshot of the profile to confirm. Is there anything else it could be?

Network hiccups, at the hardware level maybe.

If we look at the stack trace:

Caused by: java.sql.SQLException: Io exception: Socket closed
         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:146)
         at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:255)
         at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:977)
         at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1060)
         at oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:839)
         at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1132)
         at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3316)
         at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3361)
         at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
         at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
         at org.geotools.jdbc.JDBCFeatureReader.<init>(JDBCFeatureReader.java:153)
         at org.geotools.jdbc.JDBCFeatureSource.getReaderInternal(JDBCFeatureSource.java:514)

it's quite evident the socket got closed when the prepared statement execution was attempted. But before that there are other communications with the database that were successful, such as, preparing the statement itself.

Hmmm... the prepared statements are cached by DBCP, and as far as I remember a prepared statement in Oracle keeps an open cursor on the server side. Is there anything related to cursor management, maybe those
are timing out?

Another thing that you can try out is enabling connection validation
in the datastore setup. This will issue an extra query when the connection is borrowed from the pool to ensure it's still alive.
Not sure it will help in your case.

I did a quick search around for instances of the same error with Google
and most of the time the questions about that error either
do not get a response, or it turns about there is something
wrong with the dbms/networks. Sometimes changing the setup
of the pool seems to fix the problem, but I did not find any
convincing explanation of what the real problem may be.

Cheers
Andrea

--
Andrea Aime
OpenGeo - http://opengeo.org
Expert service straight from the developers.

5

On Wed, May 13, 2009 at 1:27 PM, <Aaron_Gundel@anonymised.com> wrote:

Hi Andrea,

I sent your note off to my DBA to see if we're imposing a connection timeout
on the geoserver user. He replied in the negative; the geoserver user is
under our default profile, and there is no timeout imposed under that
profile. He sent the a screenshot of the profile to confirm. Is there
anything else it could be?

By any chance is there a firewall between the geoserver machine and
the Oracle machine? A lot of firewalls will shut down idle connections
after a period of time and this could be causing you to lose your DBMS
connections after a while. For example where I work some of our
firewalls have a timeout of about 15 minutes.

--
This message brought to you by Speed of Light Beer
When you're approaching infinite mass
It's Speed of Light time!

6

Hi Andrea,

Thanks for the suggestions – I tried them out, but it still doesn’t seem to be effective. I noticed some other interesting behavior though. I don’t know how relevant any of it is, so I’ll just list it all…

The following warning is being generated frequently before the actual stack below pops out.
2009-05-14 08:19:57,928 WARN [geotools.jdb] - There is code leaving feature readers/iterators open, this is leaking

Also, I’m noticing that the error occurs much more frequently and consistently when I’m zoomed out on the map and working with one particualar layer. When I zoom in and click on wms features in the map, I actually get results back. But when I’m zoomed out, I’ll get the exception. Right now this issue seems to be occurring pretty consistently. If you need more data, I’m happy to provide it.

Aaron

Andrea Aime aaime@anonymised.com

05/13/2009 11:24 AM

To
Aaron_Gundel@anonymised.com

cc
geoserver-users@lists.sourceforge.net

Subject
Re: [Geoserver-users] getfeatureinfo exception

Aaron_Gundel@anonymised.com ha scritto:
>
> Hi Andrea,
>
> I sent your note off to my DBA to see if we're imposing a connection
> timeout on the geoserver user. He replied in the negative; the
> geoserver user is under our default profile, and there is no timeout
> imposed under that profile. He sent the a screenshot of the profile to
> confirm. Is there anything else it could be?

Network hiccups, at the hardware level maybe.

If we look at the stack trace:

Caused by: java.sql.SQLException: Io exception: Socket closed
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:146)
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:255)
at
oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:977)
at
oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1060)
at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:839)
at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1132)
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3316)
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3361)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
at
org.geotools.jdbc.JDBCFeatureReader.<init>(JDBCFeatureReader.java:153)
at
org.geotools.jdbc.JDBCFeatureSource.getReaderInternal(JDBCFeatureSource.java:514)

it's quite evident the socket got closed when the prepared statement
execution was attempted. But before that there are other communications
with the database that were successful, such as, preparing the statement
itself.

Hmmm... the prepared statements are cached by DBCP, and as far as I
remember a prepared statement in Oracle keeps an open cursor on the
server side. Is there anything related to cursor management, maybe those
are timing out?

Another thing that you can try out is enabling connection validation
in the datastore setup. This will issue an extra query when the
connection is borrowed from the pool to ensure it's still alive.
Not sure it will help in your case.

I did a quick search around for instances of the same error with Google
and most of the time the questions about that error either
do not get a response, or it turns about there is something
wrong with the dbms/networks. Sometimes changing the setup
of the pool seems to fix the problem, but I did not find any
convincing explanation of what the real problem may be.

Cheers
Andrea

--
Andrea Aime
OpenGeo - http://opengeo.org
Expert service straight from the developers.

7

Aaron_Gundel@anonymised.com ha scritto:

Hi Andrea,

Thanks for the suggestions -- I tried them out, but it still doesn't seem to be effective. I noticed some other interesting behavior though. I don't know how relevant any of it is, so I'll just list it all...

The following warning is being generated frequently before the actual stack below pops out. 2009-05-14 08:19:57,928 WARN [geotools.jdb] - There is code leaving feature readers/iterators open, this is leaking

Also, I'm noticing that the error occurs much more frequently and consistently when I'm zoomed out on the map and working with one particualar layer. When I zoom in and click on wms features in the map, I actually get results back. But when I'm zoomed out, I'll get the exception. Right now this issue seems to be occurring pretty consistently. If you need more data, I'm happy to provide it.

I think I can use a data dump that I can reload in Oracle XE plus
your datastore configuration (a screenshot would do).
If you can share the data publicly the best way is to open
a bug report at jira.codehaus.org and attach the dump there,
otherwise, if you can't, a private mail would do.

Cheers
Andrea

--
Andrea Aime
OpenGeo - http://opengeo.org
Expert service straight from the developers.