[Geoserver-users] "Failed to unwrap connection using java 6 facilities" - Oracle

Hi List,
I’m using Java 6 and GeoServer 2.5. Logging is set to “Geotools_Developer”.

Whenever I make a query to an Oracle layer (regular “Oracle NG” store) my log file gets an entry:

2014-04-11 16:09:19,894 DEBUG [org.geotools.jdbc] - Failed to unwrap connection using java 6 facilities
java.lang.AbstractMethodError: org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.isWrapperFor(Ljava/lang/Class;)Z
at org.geotools.data.oracle.OracleDialect.unwrapConnection(OracleDialect.java:557)
at org.geotools.data.oracle.OracleDialect.setGeometryValue(OracleDialect.java:520)
at org.geotools.jdbc.JDBCDataStore.setPreparedFilterValues(JDBCDataStore.java:3300)
at org.geotools.jdbc.JDBCDataStore.selectSQLPS(JDBCDataStore.java:3220)
at org.geotools.jdbc.JDBCFeatureSource.getReaderInternal(JDBCFeatureSource.java:593)
at org.geotools.data.store.ContentFeatureSource.getReader(ContentFeatureSource.java:563)
at org.geotools.data.store.ContentFeatureCollection.features(ContentFeatureCollection.java:165)
at org.geotools.data.store.ContentFeatureCollection.features(ContentFeatureCollection.java:59)
at org.geotools.renderer.lite.StreamingRenderer.drawPlain(StreamingRenderer.java:2496)
at org.geotools.renderer.lite.StreamingRenderer.processStylers(StreamingRenderer.java:2066)
at org.geotools.renderer.lite.StreamingRenderer.paint(StreamingRenderer.java:837)
at org.geoserver.wms.map.RenderedImageMapOutputFormat.produceMap(RenderedImageMapOutputFormat.java:483)
at org.geoserver.wms.map.RenderedImageMapOutputFormat.produceMap(RenderedImageMapOutputFormat.java:251)
at org.geoserver.wms.map.RenderedImageMapOutputFormat.produceMap(RenderedImageMapOutputFormat.java:123)
at org.geoserver.wms.GetMap.executeInternal(GetMap.java:509)
at org.geoserver.wms.GetMap.run(GetMap.java:253)
at org.geoserver.wms.GetMap.run(GetMap.java:124)
at org.geoserver.wms.DefaultWebMapService.getMap(DefaultWebMapService.java:328)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:319)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.geoserver.kml.WebMapServiceKmlInterceptor.invoke(WebMapServiceKmlInterceptor.java:34)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.geoserver.gwc.wms.CacheSeedingWebMapService.invoke(CacheSeedingWebMapService.java:61)
at org.geoserver.gwc.wms.CacheSeedingWebMapService.invoke(CacheSeedingWebMapService.java:35)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.geoserver.gwc.wms.CachingWebMapService.invoke(CachingWebMapService.java:73)
at org.geoserver.gwc.wms.CachingWebMapService.invoke(CachingWebMapService.java:54)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.geoserver.ows.util.RequestObjectLogger.invoke(RequestObjectLogger.java:54)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy62.getMap(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.geoserver.ows.Dispatcher.execute(Dispatcher.java:774)
at org.geoserver.ows.Dispatcher.handleRequestInternal(Dispatcher.java:272)
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:923)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.ThreadLocalsCleanupFilter.doFilter(ThreadLocalsCleanupFilter.java:27)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:74)
at org.geoserver.wms.animate.AnimatorFilter.doFilter(AnimatorFilter.java:70)
at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:70)
at org.geoserver.flow.controller.IpBlacklistFilter.doFilter(IpBlacklistFilter.java:92)
at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:70)
at org.geoserver.filters.SpringDelegatingFilter.doFilter(SpringDelegatingFilter.java:45)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.platform.AdvancedDispatchFilter.doFilter(AdvancedDispatchFilter.java:49)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:311)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:68)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:116)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:72)
at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:68)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:72)
at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323)
at org.geoserver.security.filter.GeoServerAnonymousAuthenticationFilter.doFilter(GeoServerAnonymousAuthenticationFilter.java:53)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:68)
at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:72)
at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91)
at org.geoserver.security.filter.GeoServerBasicAuthenticationFilter.doFilter(GeoServerBasicAuthenticationFilter.java:82)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:68)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
at org.geoserver.security.filter.GeoServerSecurityContextPersistenceFilter$1.doFilter(GeoServerSecurityContextPersistenceFilter.java:52)
at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:72)
at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:323)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:173)
at org.geoserver.security.GeoServerSecurityFilterChainProxy.doFilter(GeoServerSecurityFilterChainProxy.java:134)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.LoggingFilter.doFilter(LoggingFilter.java:75)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.GZIPFilter.doFilter(GZIPFilter.java:42)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.SessionDebugFilter.doFilter(SessionDebugFilter.java:47)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.geoserver.filters.FlushSafeFilter.doFilter(FlushSafeFilter.java:43)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.vfny.geoserver.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:109)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:879)
at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:600)
at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1703)
at java.lang.Thread.run(Unknown Source)

However, there are a lot of these entries. As in, it writes 10-20MB of log file a second filled almost exclusively with these!
I don’t remember seeing these before (I’d almost certainly have noticed the log-files instantly filling up for even a simple query) - what is this?

I know it’s a DEBUG level event and it doesn’t seem to effect the request, but thought I should ask anyway.

Cheers,
Jonathan

This transmission is intended for the named addressee(s) only and may contain sensitive or protectively marked material up to RESTRICTED and should be handled accordingly. Unless you are the named addressee (or authorised to receive it for the addressee) you may not copy or use it, or disclose it to anyone else. If you have received this transmission in error please notify the sender immediately. All email traffic sent to or from us, including without limitation all GCSX traffic, may be subject to recording and/or monitoring in accordance with relevant legislation.

On Fri, Apr 11, 2014 at 6:13 PM, Jonathan Moules <
jonathanmoules@anonymised.com> wrote:

Hi List,
I'm using Java 6 and GeoServer 2.5. Logging is set to "Geotools_Developer".

Whenever I make a query to an Oracle layer (regular "Oracle NG" store) my
log file gets an entry:

2014-04-11 16:09:19,894 DEBUG [org.geotools.jdbc] - Failed to unwrap

connection using java 6 facilities
java.lang.AbstractMethodError:
org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.isWrapperFor(Ljava/lang/Class;)Z

This normally happens if you have put the oracle jdbc driver in both
GeoServer web-inf/lib and the container
own shared libs directory.
If you use geoserver connection pools, put it only in geoserver, if you use
jndi connection pools, only
in the web container share libs

Cheers
Andrea

--

Meet us at GEO Business 2014! in London! Visit http://goo.gl/fES3aK
for more information.

Ing. Andrea Aime
@geowolf
Technical Lead

GeoSolutions S.A.S.
Via Poggio alle Viti 1187
55054 Massarosa (LU)
Italy
phone: +39 0584 962313
fax: +39 0584 1660272
mob: +39 339 8844549

http://www.geo-solutions.it
http://twitter.com/geosolutions_it

-------------------------------------------------------

Hi Andrea,
I don’t think it’s that. I don’t know which is the “container own shared list directory” - I only put it into the web-inf/lib dir.
I’m not using JNDI or connection pools to the best of my knowledge.

The only files that contain the word “Oracle” in my install are all here:
Inline images 1

This transmission is intended for the named addressee(s) only and may contain sensitive or protectively marked material up to RESTRICTED and should be handled accordingly. Unless you are the named addressee (or authorised to receive it for the addressee) you may not copy or use it, or disclose it to anyone else. If you have received this transmission in error please notify the sender immediately. All email traffic sent to or from us, including without limitation all GCSX traffic, may be subject to recording and/or monitoring in accordance with relevant legislation.

···

Any thoughts?

Cheers,
Jonathan

On 11 April 2014 18:32, Andrea Aime <andrea.aime@anonymised.com> wrote:

On Fri, Apr 11, 2014 at 6:13 PM, Jonathan Moules <jonathanmoules@anonymised.com> wrote:

Hi List,
I’m using Java 6 and GeoServer 2.5. Logging is set to “Geotools_Developer”.

Whenever I make a query to an Oracle layer (regular “Oracle NG” store) my log file gets an entry:

2014-04-11 16:09:19,894 DEBUG [org.geotools.jdbc] - Failed to unwrap connection using java 6 facilities
java.lang.AbstractMethodError: org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.isWrapperFor(Ljava/lang/Class;)Z

This normally happens if you have put the oracle jdbc driver in both GeoServer web-inf/lib and the container
own shared libs directory.
If you use geoserver connection pools, put it only in geoserver, if you use jndi connection pools, only
in the web container share libs

Cheers
Andrea

==
Meet us at GEO Business 2014! in London! Visit http://goo.gl/fES3aK
for more information.

Ing. Andrea Aime

@geowolf
Technical Lead

GeoSolutions S.A.S.
Via Poggio alle Viti 1187
55054 Massarosa (LU)
Italy
phone: +39 0584 962313
fax: +39 0584 1660272
mob: +39 339 8844549

http://www.geo-solutions.it
http://twitter.com/geosolutions_it


On Mon, Apr 14, 2014 at 12:19 PM, Jonathan Moules <
jonathanmoules@anonymised.com> wrote:

Hi Andrea,
I don't think it's that. I don't know which is the "container own shared
list directory" - I only put it into the web-inf/lib dir.
I'm not using JNDI or connection pools to the best of my knowledge.

The only files that contain the word "Oracle" in my install are all here:
!image.png|800x214

Any thoughts?

None, completely clueless...
Actually, let me re-read the initial mail... that message was at _DEBUG_
level, nothing strange about it, it's meant for
developers to look at and verify one of the various methods for connection
unwrapping.
Why are you even caring about it, you should not run GeoServer at that
logging level to start with (I mean, DEBUG
is really for developers, if you are running a server like that, you're
doing it wrong).

Cheers
Andrea

--

Meet us at GEO Business 2014! in London! Visit http://goo.gl/fES3aK
for more information.

Ing. Andrea Aime
@geowolf
Technical Lead

GeoSolutions S.A.S.
Via Poggio alle Viti 1187
55054 Massarosa (LU)
Italy
phone: +39 0584 962313
fax: +39 0584 1660272
mob: +39 339 8844549

http://www.geo-solutions.it
http://twitter.com/geosolutions_it

-------------------------------------------------------

This transmission is intended for the named addressee(s) only and may contain sensitive or protectively marked material up to RESTRICTED and should be handled accordingly. Unless you are the named addressee (or authorised to receive it for the addressee) you may not copy or use it, or disclose it to anyone else. If you have received this transmission in error please notify the sender immediately. All email traffic sent to or from us, including without limitation all GCSX traffic, may be subject to recording and/or monitoring in accordance with relevant legislation.

···

Two reasons:

  1. Because I don’t think I’ve seen it before.
  2. More importantly, because there are so many that it floods out any actually useful log entries and in fact because the logs cycle, they get deleted. I wasn’t exaggerating when I said that it writes 10’s of MB for each request. So I’m pre-empting if/when there is something that stops working and requires me to use Debug level logging - because if that happens the logs will be useless being filled only with this event.

(This is on my test server - I leave it on debug by default because when I’m using it I’m often trying to find stuff that’s gone wrong).

Hope that clears up my interest.
Cheers,
Jonathan

Why are you even caring about it, you should not run GeoServer at that logging level to start with (I mean, DEBUG
is really for developers, if you are running a server like that, you’re doing it wrong).