Adding group access makes layer public

mikefedak commented 6 years ago

2.8.x branch with Geoserver 2.13

I have noticed that if I add group viewing permissions to a layer (but not anyone), the layer becomes visible in the layer preview page of geoserver and is accessible via openlayers/ows.

afabiani commented 6 years ago

@mikefedak this is a regression. Going to fix it.

afabiani commented 6 years ago

here is the fix

https://github.com/GeoNode/geonode/pull/3996/files

I decided to get rid of the "fixgeofencerules" management command. It is old, obsolete and even incomplete since it does not take into account "groups" but only "users". Therefore it is quite dangerous to use it actually.

mikefedak commented 6 years ago

I confirm that this fixes the issue around layer visibility. However now geofence rules are per role, which would be fine if the permissions for OWS would work as expected. As of now, this completely breaks authentication to OWS services via QGIS using a geonode user/pass.

afabiani commented 6 years ago

Yes, that would be the expected behavior. If you add both a user and role you should have either rules for user and role.

Specifying just the role, you will have only the rules per role.

However, that shouldn't break the auth if you pass through the geonode proxy.

mikefedak commented 6 years ago

Ok so lets say for instance I have a user that is the member of a group, then I have a layer with viewing permissions set for that group (but no individual users). Now I go to QGIS and load up WMS via the proxy and attempt to login with the credentials of the user. The credentials are accepted but none of the layers available to the role, which the user is part of, are loaded.

afabiani commented 6 years ago

Uhm, in theory, GeoServer should ask the role to GeoNode and apply the rules accordingly. If this does not happen, that means that somehow GeoServer is not able to associate to a role to the user correctly.

Give me some time to setup a QGIS environment and check by myself if I'm able to reproduce the use case.

mikefedak commented 6 years ago

Ok,

The behaviour I am seeing is as follows; publicly available layers work without issue via OWS. Logins to accounts registered on geoserver (admin) work as well. Requests with geonode only users return a getcapabilities request as follows:

2018-10-16 16:10:00,466 INFO [geoserver.flow] - releasing flow controllers for [WMS 1.3.0 GetCapabilities] 2018-10-16 16:10:00,467 INFO [geoserver.flow] - Request completed, running requests: 0, blocked requests: 0 2018-10-16 16:10:00,639 INFO [geoserver.wms] - Request: getServiceInfo 2018-10-16 16:10:00,639 INFO [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] starting, processing through flow controllers 2018-10-16 16:10:00,639 INFO [geoserver.flow] - Request control-flow performed, running requests: 1, blocked requests: 0 2018-10-16 16:10:00,640 INFO [geoserver.wms] - Request: getCapabilities BaseUrl = http://data.lprca.ca:80/geoserver/ Get = false Namespace = geonode RawKvp = {REQUEST=GetCapabilities, SERVICE=WMS} Request = GetCapabilities RequestCharset = null UpdateSequence = null Version = 1.3.0 2018-10-16 16:10:00,642 INFO [geofence.cache] - Rules :CacheStats{hitCount=4715, missCount=384, loadSuccessCount=376, loadExceptionCount=0, totalLoadTime=2234995258, evictionCount=11} 2018-10-16 16:10:00,642 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=88, loadSuccessCount=0, loadExceptionCount=88, totalLoadTime=397135481, evictionCount=0} 2018-10-16 16:10:00,642 INFO [geofence.cache] - Auth :CacheStats{hitCount=6636, missCount=39, loadSuccessCount=30, loadExceptionCount=0, totalLoadTime=427843038, evictionCount=4} 2018-10-16 16:10:00,648 INFO [geoserver.flow] - releasing flow controllers for [WMS 1.3.0 GetCapabilities] 2018-10-16 16:10:00,648 INFO [geoserver.flow] - Request completed, running requests: 0, blocked requests: 0 2018-10-16 16:12:02,951 WARN [geofence.cache] - org.geoserver.geofence.cache.CachedRuleReader$NoAuthException: Can't auth user [admin]

afabiani commented 6 years ago

@mikefedak

So this is what I did:

Created a user "afabiani" and added to "test" group
Uploaded a Layer and modified the permissions as shown below

which produced the following GeoFence rules

Tested the request with curl curl -v -X GET -u afabiani:***** "http://localhost:8000/gs/wms?service=wms&version=1.3.0&request=GetCapabilities"

and got the correct capabilities

...
          <OnlineResource xlink:type="simple" xlink:href="http://localhost:8000/catalogue/csw?outputschema=http%3A%2F%2Fwww.opengis.net%2Fcat%2Fcsw%2Fcsdgm&amp;service=CSW&amp;request=GetRecordById&amp;version=2.0.2&amp;elementsetname=full&amp;id=6c55b8aa-d15b-11e8-89c9-2816adbf1ef8"/>
        </MetadataURL>
        <MetadataURL type="other">
          <Format>other</Format>
          <OnlineResource xlink:type="simple" xlink:href="http://localhost:8000/catalogue/csw?outputschema=http%3A%2F%2Fwww.isotc211.org%2F2005%2Fgmd&amp;service=CSW&amp;request=GetRecordById&amp;version=2.0.2&amp;elementsetname=full&amp;id=6c55b8aa-d15b-11e8-89c9-2816adbf1ef8"/>
        </MetadataURL>
        <MetadataURL type="other">
          <Format>other</Format>
          <OnlineResource xlink:type="simple" xlink:href="http://localhost:8000/showmetadata/xsl/5"/>
        </MetadataURL>
        <Style>
          <Name>geonode:DE_USNG_UTM180</Name>
          <Title>A dark yellow polygon style</Title>
          <LegendURL width="20" height="20">
            <Format>image/png</Format>
            <OnlineResource xmlns:xlink="http://www.w3.org/1999/xlink" xlink:type="simple" xlink:href="http://localhost:8000/gs/ows?service=WMS&amp;request=GetLegendGraphic&amp;format=image%2Fpng&amp;width=20&amp;height=20&amp;layer=geonode%3ADE_USNG_UTM180&amp;access_token=rp5QtxwLuKZXFK4LVyenov88ovSj2m"/>
          </LegendURL>
        </Style>
      </Layer>
    </Layer>
  </Capability>
</WMS_Capabilities>

Tested the request with curl curl -v -X GET "http://localhost:8000/gs/wms?service=wms&version=1.3.0&request=GetCapabilities"

causes 401

*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8000 (#0)
> GET /gs/wms?service=wms&version=1.3.0&request=GetCapabilities HTTP/1.1
> Host: localhost:8000
> User-Agent: curl/7.47.0
> Accept: */*
>
* HTTP 1.0, assume close after body
< HTTP/1.0 401 Unauthorized
< Date: Tue, 16 Oct 2018 16:24:30 GMT
< Server: WSGIServer/0.1 Python/2.7.12
< Content-Length: 0
< x-xss-protection: 1; mode=block
< Content-Language: en
< x-content-type-options: nosniff
< Vary: Authorization, Accept-Language, Cookie
< X-Frame-Options: DENY
< Content-Type: text/html; charset=utf-8
< WWW-Authenticate: Basic realm="GeoNode"
<
* Closing connection 0

Tested the request with curl curl -v -X GET "http://localhost:8000/gs/ows?service=wms&version=1.3.0&request=GetCapabilities"

Gives me empty capabilities

...
    </Exception>
    <Layer>
      <Title>GeoNode Local GeoServer</Title>
      <Abstract>This is a description of your Web Map Server.</Abstract>
      <!--Limited list of EPSG projections:-->
      <CRS>EPSG:4326</CRS>
      <CRS>EPSG:3785</CRS>
      <CRS>EPSG:3857</CRS>
      <CRS>EPSG:900913</CRS>
      <CRS>EPSG:32647</CRS>
      <CRS>EPSG:32736</CRS>
      <CRS>CRS:84</CRS>
      <EX_GeographicBoundingBox>
        <westBoundLongitude>0.0</westBoundLongitude>
        <eastBoundLongitude>-1.0</eastBoundLongitude>
        <southBoundLatitude>0.0</southBoundLatitude>
        <northBoundLatitude>-1.0</northBoundLatitude>
      </EX_GeographicBoundingBox>
      <BoundingBox CRS="CRS:84" minx="0.0" miny="0.0" maxx="-1.0" maxy="-1.0"/>
      <BoundingBox CRS="EPSG:4326" minx="-1.0" miny="-1.0" maxx="0.0" maxy="0.0"/>
      <BoundingBox CRS="EPSG:3785" minx="-111319.49079327357" miny="-110576.20488859876" maxx="0.0" maxy="-7.081154551613622E-10"/>
      <BoundingBox CRS="EPSG:3857" minx="-111319.49079327357" miny="-111325.14286638597" maxx="0.0" maxy="-7.081154551613622E-10"/>
      <BoundingBox CRS="EPSG:900913" minx="-111319.49079327357" miny="-111325.14286638597" maxx="0.0" maxy="-7.081154551613622E-10"/>
      <BoundingBox CRS="EPSG:32647" minx="-2.450519666009094E7" miny="-1100225.1120296645" maxx="-2.372565893197646E7" maxy="0.0"/>
      <BoundingBox CRS="EPSG:32736" minx="-3528804.3053306052" miny="9866491.669751624" maxx="-3394492.4987732894" maxy="1.0E7"/>
    </Layer>
  </Capability>
</WMS_Capabilities>

So... the behavior seems to be correct to me.

mikefedak commented 6 years ago

Ok, is the afabiani user also a member of the admin role? Because for my users to be able to get the same response, they need to be members of the admin role. If they are not they get a blank get capabilities response

Additionally, if I try the request with no user/pass specified I get a 401, but I suspect that is because I have deny from all set up.

< HTTP/1.1 401 OK < Date: Tue, 16 Oct 2018 16:36:11 GMT < Server: Apache/2.4.18 (Ubuntu) < x-xss-protection: 1; mode=block < Content-Language: en < x-content-type-options: nosniff < Vary: Authorization,Accept-Language,Cookie < X-Frame-Options: DENY < WWW-Authenticate: Basic realm="GeoNode" < Content-Length: 0 < Content-Type: text/html; charset=utf-8

afabiani commented 6 years ago

@mikefedak nope, "afabiani" is a standard user... nevertheless I just discovered a typo on the previous commit which wasn't on my local branch. Wandering if that could cause your issue. Commit on its way.

In the meantime:

Can you double check that the set of rules is similar to the screenshot I have posted before?
Double check the endpoints gs/ows against gs/wms, those have different rules.

afabiani commented 6 years ago

@mikefedak

https://github.com/GeoNode/geonode/pull/4003/files

mikefedak commented 6 years ago

applied the change.

My geofence data permissions are structured the same to yours.
gs/wms returns a blank getcapabiities while gs/ows returns a 401 from tomcat.

afabiani commented 6 years ago

@mikefedak the layer has been published also?

mikefedak commented 6 years ago

yes

afabiani commented 6 years ago

@mikefedak can you give it a try with curl requests also? (wondering if that could be maybe something related to QGIS)

mikefedak commented 6 years ago

That was with curl requests. QGIS behaves the same as before.

afabiani commented 6 years ago

Uhm, almost out of hints!!

Any chance to rise up the geoserver log level and send back to me the outcome? Let's see what GeoFence says... I need the output of the authenticated getcapabilities request.

mikefedak commented 6 years ago

ok, doing it now.

Output from the geoserver log for a sucessful get-capabilities request (verbose): 2018-10-16 17:31:17,597 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 36-1.IFormSubmitListener-form&lines=2500'; against '/web/' 2018-10-16 17:31:17,597 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 36-1.IFormSubmitListener-form&lines=2500 with /web/ 2018-10-16 17:31:17,597 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:31:17,597 DEBUG [geoserver.security] - Found 5 cookies! 2018-10-16 17:31:17,597 DEBUG [geoserver.security] - Found Custom Session cookie: 0p142pp06rs5oclhoyozk872oqxtzuto 2018-10-16 17:31:17,597 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-16 17:31:17,597 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,610 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,610 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,611 DEBUG [org.geoserver] - Thread 92 locking in mode READ 2018-10-16 17:31:17,611 DEBUG [org.geoserver] - Thread 92 got the lock in mode READ 2018-10-16 17:31:17,612 DEBUG [org.geoserver] - Thread 92 locking in mode READ 2018-10-16 17:31:17,612 DEBUG [org.geoserver] - Thread 92 releasing the lock in mode READ 2018-10-16 17:31:17,616 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-16 17:31:17,739 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=2500'; against '/web/' 2018-10-16 17:31:17,739 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=2500 with /web/ 2018-10-16 17:31:17,739 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:31:17,739 DEBUG [geoserver.security] - Found 5 cookies! 2018-10-16 17:31:17,739 DEBUG [geoserver.security] - Found Custom Session cookie: 0p142pp06rs5oclhoyozk872oqxtzuto 2018-10-16 17:31:17,739 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-16 17:31:17,739 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-16 17:31:17,752 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,752 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,752 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,752 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,752 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,752 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,753 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,753 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,753 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,753 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,753 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,753 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,753 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:31:17,753 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:31:17,753 DEBUG [org.geoserver] - Thread 510 locking in mode READ 2018-10-16 17:31:17,753 DEBUG [org.geoserver] - Thread 510 got the lock in mode READ

Get capabilities requests returning empty:

2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/web/' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/gwc/rest/web/' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_check' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_check/' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_login' 2018-10-16 17:34:14,282 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_login/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_logout' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_logout/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_logout' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_logout/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/rest/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/gwc/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/geofence/rest/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/geofence/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Request matched by universal pattern '/' 2018-10-16 17:34:14,283 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /ows, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib with /** 2018-10-16 17:34:14,365 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:34:14,365 DEBUG [geoserver.security] - Found no cookies! 2018-10-16 17:34:14,397 DEBUG [oauth2.GeoServerOAuthRemoteTokenServices] - Original map = {username=basic_test, issued_to=basic_test, user_id=1011, client_id=dRpQe54llR8O9j59ibEIziiqwoKIV9nGcCMnIknf, access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib, expires_in=8.6399868917E7, email=, access_type=online, verified_email=true} 2018-10-16 17:34:14,397 DEBUG [oauth2.GeoServerOAuthRemoteTokenServices] - Transformed = {username=basic_test, issued_to=basic_test, user_id=1011, client_id=dRpQe54llR8O9j59ibEIziiqwoKIV9nGcCMnIknf, access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib, expires_in=8.6399868917E7, email=, access_type=online, verified_email=true, user_name=basic_test} 2018-10-16 17:34:14,397 DEBUG [geoserver.security] - preAuthenticatedPrincipal = basic_test, trying to authenticate 2018-10-16 17:34:14,397 DEBUG [geoserver.security] - Setting ROLES for User [basic_test] to [ROLE_LONG-POINT-REGION-CONSERVATION-AUTHORITY] 2018-10-16 17:34:14,397 DEBUG [geoserver.monitor] - Testing /ows for monitor filtering 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/ows] 2018-10-16 17:34:14,405 DEBUG [ows.OWSHandlerMapping] - Mapping [/ows] to HandlerExecutionChain with handler [org.geoserver.ows.Dispatcher@2560b3ef] and 1 interceptor 2018-10-16 17:34:14,406 INFO [geoserver.wms] - Request: getServiceInfo 2018-10-16 17:34:14,406 INFO [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] starting, processing through flow controllers 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@4b7b18b5) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@4b7b18b5) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller org.geoserver.flow.controller.UserConcurrentFlowController@2d2d48c6 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - UserFlowController(6,GSCFLOW-5d81ebd1:16679d88b18:-6547) queue size 1 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - UserFlowController(6,GSCFLOW-5d81ebd1:16679d88b18:-6547) total queues 3 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - UserFlowController(6) purged 2 stale queues 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller org.geoserver.flow.controller.UserConcurrentFlowController@2d2d48c6 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@64207771) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@64207771) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@447f4fd1) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@447f4fd1) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@5752595b) 2018-10-16 17:34:14,406 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@5752595b) 2018-10-16 17:34:14,406 INFO [geoserver.flow] - Request control-flow performed, running requests: 1, blocked requests: 0 2018-10-16 17:34:14,406 INFO [geoserver.wms] - Request: getCapabilities BaseUrl = http://localhost:8080/geoserver/ Get = false Namespace = null RawKvp = {REQUEST=GetCapabilities, ACCESS_TOKEN=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib, VERSION=1.3.0, SERVICE=wms} Request = GetCapabilities RequestCharset = null UpdateSequence = null Version = 1.3.0 2018-10-16 17:34:14,407 DEBUG [wms.capabilities] - producing a capabilities document for GetCapabilities [service: WMS, version: 1.3.0] 2018-10-16 17:34:14,408 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-16 17:34:14,408 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-16 17:34:14,408 DEBUG [sqlserver.jtds] - Target not a string 2018-10-16 17:34:14,408 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-16 17:34:14,408 DEBUG [geoserver.geofence] - Getting access limits for Layer Assessment 2018-10-16 17:34:14,408 DEBUG [geoserver.geofence] - Getting access limits for Resource Assessment 2018-10-16 17:34:14,408 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Assessment] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Assessment and user basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Layer CGG2013_Watershed 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Resource CGG2013_Watershed 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[CGG2013_Watershed] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:CGG2013_Watershed and user basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Layer Dimensions 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Resource Dimensions 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Dimensions] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Dimensions and user basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Layer HL_Adjustment_09_07_2018 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Resource HL_Adjustment_09_07_2018 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[HL_Adjustment_09_07_2018] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:HL_Adjustment_09_07_2018 and user basic_test 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Layer HT20_Watershed 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Getting access limits for Resource HT20_Watershed 2018-10-16 17:34:14,409 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[HT20_Watershed] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:HT20_Watershed and user basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Layer LIO_Duplicates 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Resource LIO_Duplicates 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[LIO_Duplicates] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:LIO_Duplicates and user basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Layer SWOOP2010_DEM 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Resource SWOOP2010_DEM 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[SWOOP2010_DEM] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:SWOOP2010_DEM and user basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Layer cgg13aht20diff 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Resource cgg13aht20diff 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-16 17:34:14,410 INFO [geofence.cache] - Rules :CacheStats{hitCount=4914, missCount=415, loadSuccessCount=407, loadExceptionCount=0, totalLoadTime=2263517290, evictionCount=11} 2018-10-16 17:34:14,410 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=472, loadSuccessCount=0, loadExceptionCount=472, totalLoadTime=535215716, evictionCount=0} 2018-10-16 17:34:14,410 INFO [geofence.cache] - Auth :CacheStats{hitCount=6864, missCount=41, loadSuccessCount=32, loadExceptionCount=0, totalLoadTime=429833069, evictionCount=4} 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - params :CacheConfiguration[size=500000 refrMsec=6000000, expMsec=6000000] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[cgg13aht20diff] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:cgg13aht20diff and user basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Layer generic_regulation_limit_lprca_nov23_16 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Getting access limits for Resource generic_regulation_limit_lprca_nov23_16 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-16 17:34:14,410 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[generic_regulation_limit_lprca_nov23_16] 2018-10-16 17:34:14,410 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:generic_regulation_limit_lprca_nov23_16 and user basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Layer lidar_dtm_2018_cgvd13 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Resource lidar_dtm_2018_cgvd13 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[lidar_dtm_2018_cgvd13] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:lidar_dtm_2018_cgvd13 and user basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Layer lprca_ws_boundarywgs84 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Resource lprca_ws_boundarywgs84 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[lprca_ws_boundarywgs84] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:lprca_ws_boundarywgs84 and user basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Layer qgis4326 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Resource qgis4326 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[qgis4326] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:qgis4326 and user basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2006 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2006 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2006] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2006 and user basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2010 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2010 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,411 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-16 17:34:14,412 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2010] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2010 and user basic_test 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,412 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2015_0416 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2015_0416 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-16 17:34:14,412 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2015_0416] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2015_0416 and user basic_test 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,412 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,412 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,412 DEBUG [wms.capabilities] - Collecting summarized latlonbbox and common SRS... 2018-10-16 17:34:14,412 DEBUG [wms.capabilities] - Summarized LatLonBBox is Env[0.0 : -1.0, 0.0 : -1.0] 2018-10-16 17:34:14,413 INFO [geoserver.flow] - releasing flow controllers for [wms 1.3.0 GetCapabilities] 2018-10-16 17:34:14,413 INFO [geoserver.flow] - Request completed, running requests: 0, blocked requests: 0 2018-10-16 17:34:14,413 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-16 17:34:14,413 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-16 17:34:14,413 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-16 17:34:14,413 DEBUG [sqlserver.jtds] - Target not a string 2018-10-16 17:34:14,413 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/web/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/gwc/rest/web/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_check' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_check/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_login' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_login/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_logout' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_security_logout/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_logout' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/j_spring_oauth2_geonode_logout/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/rest/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/gwc/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/geofence/rest/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/geofence/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib'; against '/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Request matched by universal pattern '/' 2018-10-16 17:34:14,415 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /wms, QueryString: service=wms&version=1.3.0&request=GetCapabilities&access_token=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib with /** 2018-10-16 17:34:14,416 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:34:14,416 DEBUG [geoserver.security] - Found 2 cookies! 2018-10-16 17:34:14,416 DEBUG [geoserver.monitor] - Testing /wms for monitor filtering 2018-10-16 17:34:14,423 DEBUG [ows.OWSHandlerMapping] - Mapping [/wms] to HandlerExecutionChain with handler [org.geoserver.ows.Dispatcher@2560b3ef] and 1 interceptor 2018-10-16 17:34:14,423 INFO [geoserver.wms] - Request: getServiceInfo 2018-10-16 17:34:14,423 INFO [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] starting, processing through flow controllers 2018-10-16 17:34:14,423 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@4b7b18b5) 2018-10-16 17:34:14,423 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@4b7b18b5) 2018-10-16 17:34:14,423 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller org.geoserver.flow.controller.UserConcurrentFlowController@2d2d48c6 2018-10-16 17:34:14,423 DEBUG [geoserver.flow] - UserFlowController(6,GSCFLOW-5d81ebd1:16679d88b18:-6546) queue size 1 2018-10-16 17:34:14,423 DEBUG [geoserver.flow] - UserFlowController(6,GSCFLOW-5d81ebd1:16679d88b18:-6546) total queues 2 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller org.geoserver.flow.controller.UserConcurrentFlowController@2d2d48c6 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@64207771) 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@64207771) 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@447f4fd1) 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@447f4fd1) 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] checking flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@5752595b) 2018-10-16 17:34:14,424 DEBUG [geoserver.flow] - Request [wms 1.3.0 GetCapabilities] passed flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@5752595b) 2018-10-16 17:34:14,424 INFO [geoserver.flow] - Request control-flow performed, running requests: 1, blocked requests: 0 2018-10-16 17:34:14,424 INFO [geoserver.wms] - Request: getCapabilities BaseUrl = http://localhost:8080/geoserver/ Get = false Namespace = null RawKvp = {REQUEST=GetCapabilities, ACCESS_TOKEN=XLESlbOQOFAw4QJVXA5ZIeCkaH0aib, VERSION=1.3.0, SERVICE=wms} Request = GetCapabilities RequestCharset = null UpdateSequence = null Version = 1.3.0 2018-10-16 17:34:14,425 DEBUG [wms.capabilities] - producing a capabilities document for GetCapabilities [service: WMS, version: 1.3.0] 2018-10-16 17:34:14,425 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-16 17:34:14,425 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-16 17:34:14,425 DEBUG [sqlserver.jtds] - Target not a string 2018-10-16 17:34:14,425 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Layer Assessment 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Resource Assessment 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Assessment] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Assessment and user basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Layer CGG2013_Watershed 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Resource CGG2013_Watershed 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[CGG2013_Watershed] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:CGG2013_Watershed and user basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Layer Dimensions 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for Resource Dimensions 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-16 17:34:14,426 INFO [geofence.cache] - Rules :CacheStats{hitCount=4924, missCount=415, loadSuccessCount=407, loadExceptionCount=0, totalLoadTime=2263517290, evictionCount=11} 2018-10-16 17:34:14,426 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=472, loadSuccessCount=0, loadExceptionCount=472, totalLoadTime=535215716, evictionCount=0} 2018-10-16 17:34:14,426 INFO [geofence.cache] - Auth :CacheStats{hitCount=6874, missCount=41, loadSuccessCount=32, loadExceptionCount=0, totalLoadTime=429833069, evictionCount=4} 2018-10-16 17:34:14,426 DEBUG [geofence.cache] - params :CacheConfiguration[size=500000 refrMsec=6000000, expMsec=6000000] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Dimensions] 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Dimensions and user basic_test 2018-10-16 17:34:14,426 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Layer HL_Adjustment_09_07_2018 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Resource HL_Adjustment_09_07_2018 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[HL_Adjustment_09_07_2018] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:HL_Adjustment_09_07_2018 and user basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Layer HT20_Watershed 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Resource HT20_Watershed 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[HT20_Watershed] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:HT20_Watershed and user basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Layer LIO_Duplicates 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Resource LIO_Duplicates 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[LIO_Duplicates] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:LIO_Duplicates and user basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Layer SWOOP2010_DEM 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Resource SWOOP2010_DEM 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[SWOOP2010_DEM] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:SWOOP2010_DEM and user basic_test 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,427 DEBUG [geoserver.geofence] - Getting access limits for Layer cgg13aht20diff 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Resource cgg13aht20diff 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[cgg13aht20diff] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:cgg13aht20diff and user basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Layer generic_regulation_limit_lprca_nov23_16 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Resource generic_regulation_limit_lprca_nov23_16 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[generic_regulation_limit_lprca_nov23_16] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:generic_regulation_limit_lprca_nov23_16 and user basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Layer lidar_dtm_2018_cgvd13 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Resource lidar_dtm_2018_cgvd13 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[lidar_dtm_2018_cgvd13] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:lidar_dtm_2018_cgvd13 and user basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Layer lprca_ws_boundarywgs84 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Resource lprca_ws_boundarywgs84 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[lprca_ws_boundarywgs84] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:lprca_ws_boundarywgs84 and user basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Layer qgis4326 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Getting access limits for Resource qgis4326 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-16 17:34:14,428 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[qgis4326] 2018-10-16 17:34:14,428 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:qgis4326 and user basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2006 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2006 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-16 17:34:14,429 INFO [geofence.cache] - Rules :CacheStats{hitCount=4934, missCount=415, loadSuccessCount=407, loadExceptionCount=0, totalLoadTime=2263517290, evictionCount=11} 2018-10-16 17:34:14,429 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=472, loadSuccessCount=0, loadExceptionCount=472, totalLoadTime=535215716, evictionCount=0} 2018-10-16 17:34:14,429 INFO [geofence.cache] - Auth :CacheStats{hitCount=6884, missCount=41, loadSuccessCount=32, loadExceptionCount=0, totalLoadTime=429833069, evictionCount=4} 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - params :CacheConfiguration[size=500000 refrMsec=6000000, expMsec=6000000] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2006] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2006 and user basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2010 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2010 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2010] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2010 and user basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2015_0416 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2015_0416 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Setting user for filter: basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2015_0416] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2015_0416 and user basic_test 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false 2018-10-16 17:34:14,429 DEBUG [wms.capabilities] - Collecting summarized latlonbbox and common SRS... 2018-10-16 17:34:14,429 DEBUG [wms.capabilities] - Summarized LatLonBBox is Env[0.0 : -1.0, 0.0 : -1.0] 2018-10-16 17:34:14,430 DEBUG [geoserver.filters] - Compressing output for mimetype: text/xml 2018-10-16 17:34:14,430 INFO [geoserver.flow] - releasing flow controllers for [wms 1.3.0 GetCapabilities] 2018-10-16 17:34:14,430 INFO [geoserver.flow] - Request completed, running requests: 0, blocked requests: 0 2018-10-16 17:34:14,430 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-16 17:34:14,430 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-16 17:34:14,430 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-16 17:34:14,430 DEBUG [sqlserver.jtds] - Target not a string 2018-10-16 17:34:14,430 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-16 17:34:32,430 DEBUG [geoserver.wps] - Removing statuses matching [[[ NOT [ completionTime IS NULL ] ] AND [ completionTime Before 2018-10-16T17:14Z ]] AND [[ NOT [ lastUpdated IS NULL ] ] AND [ lastUpdated Before 2018-10-16T17:14Z ]]] 2018-10-16 17:34:39,507 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 38-1.IFormSubmitListener-form&lines=2500'; against '/web/' 2018-10-16 17:34:39,507 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 38-1.IFormSubmitListener-form&lines=2500 with /web/ 2018-10-16 17:34:39,507 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:34:39,507 DEBUG [geoserver.security] - Found 5 cookies! 2018-10-16 17:34:39,507 DEBUG [geoserver.security] - Found Custom Session cookie: 0p142pp06rs5oclhoyozk872oqxtzuto 2018-10-16 17:34:39,507 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-16 17:34:39,507 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-16 17:34:39,519 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,519 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,519 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,519 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,520 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,520 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,520 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,520 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,520 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,520 DEBUG [org.geoserver] - Thread 94 locking in mode READ 2018-10-16 17:34:39,520 DEBUG [org.geoserver] - Thread 94 got the lock in mode READ 2018-10-16 17:34:39,521 DEBUG [org.geoserver] - Thread 94 locking in mode READ 2018-10-16 17:34:39,521 DEBUG [org.geoserver] - Thread 94 releasing the lock in mode READ 2018-10-16 17:34:39,524 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-16 17:34:39,549 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=2500'; against '/web/' 2018-10-16 17:34:39,549 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=2500 with /web/ 2018-10-16 17:34:39,549 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-16 17:34:39,549 DEBUG [geoserver.security] - Found 5 cookies! 2018-10-16 17:34:39,549 DEBUG [geoserver.security] - Found Custom Session cookie: 0p142pp06rs5oclhoyozk872oqxtzuto 2018-10-16 17:34:39,549 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-16 17:34:39,549 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-16 17:34:39,561 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,561 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-16 17:34:39,562 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-16 17:34:39,562 DEBUG [org.geoserver] - Thread 95 locking in mode READ 2018-10-16 17:34:39,562 DEBUG [org.geoserver] - Thread 95 got the lock in mode READ

afabiani commented 6 years ago

@mikefedak are you sure you are passing thrgouh "http://geonode_host/gs/wms" proxy url?

From the logs I see requests scan for the user name, NOT for the role

2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Admin auth for User:basic_test Workspace:geonode: false
2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2015_0416
2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2015_0416
2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Setting user for filter: basic_test
2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+]
2018-10-16 17:34:14,429 DEBUG [geofence.cache] - Request for RuleFilter[user:"basic_test"+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+]
2018-10-16 17:34:14,429 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2015_0416]

Alternatively, it looks like you have a higher priority rule hiding the layers. I don't see anywhere in the logs a rule looking for the a role different from ANY

afabiani commented 6 years ago

@mikefedak wandering if you have a wrong GeoServer configuration.

Double check that your GEOSERVER_DATA_DIR/geofence/geofence-server.properties contains the following properties:

gwc.context.suffix=gwc
org.geoserver.rest.DefaultUserGroupServiceName=geonode REST role service

And that the default role service is -> default

See here for more details:

http://docs.geonode.org/en/master/tutorials/install_and_admin/geonode_update/26_to_27/index.html#update-from-geonode-2-6-3-to-geonode-2-7

mikefedak commented 6 years ago

Yes, the default role service is selected and the geofence properties are correct.

afabiani commented 6 years ago

@mikefedak no idea at this point.

Will try to do more tests tomorrow. I need to reproduce the issue somehow in order to understand what's going on.

mikefedak commented 6 years ago

Not sure if its relevant but when I try and look at the role service in geoserver:

I get an error:

rg.apache.wicket.WicketRuntimeException: Method onRequest of interface org.apache.wicket.behavior.IBehaviorListener targeted at org.apache.wicket.ajax.markup.html.AjaxLink$1@5843404c on component [AjaxLink [Component id = link]] threw an exception at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:268) at org.apache.wicket.RequestListenerInterface.invoke(RequestListenerInterface.java:241) at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.invokeListener(ListenerInterfaceRequestHandler.java:248) at org.apache.wicket.core.request.handler.ListenerInterfaceRequestHandler.respond(ListenerInterfaceRequestHandler.java:234) at org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:895) at org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:64) at org.apache.wicket.request.cycle.RequestCycle.execute(RequestCycle.java:265) at org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:222) at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:293) at org.apache.wicket.protocol.http.WicketFilter.processRequestCycle(WicketFilter.java:261) at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:203) at org.apache.wicket.protocol.http.WicketServlet.doGet(WicketServlet.java:137) at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) at org.springframework.web.servlet.mvc.ServletWrappingController.handleRequestInternal(ServletWrappingController.java:157) at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:174) at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861) at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:414) at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:169) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.ThreadLocalsCleanupFilter.doFilter(ThreadLocalsCleanupFilter.java:26) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:69) at org.geoserver.flow.controller.IpBlacklistFilter.doFilter(IpBlacklistFilter.java:89) at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:66) at org.geoserver.wms.animate.AnimatorFilter.doFilter(AnimatorFilter.java:73) at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:66) at org.geoserver.monitor.MonitorFilter.doFilter(MonitorFilter.java:83) at org.geoserver.filters.SpringDelegatingFilter$Chain.doFilter(SpringDelegatingFilter.java:66) at org.geoserver.filters.SpringDelegatingFilter.doFilter(SpringDelegatingFilter.java:41) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.platform.AdvancedDispatchFilter.doFilter(AdvancedDispatchFilter.java:37) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:316) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:70) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:126) at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:74) at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:70) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:74) at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.filter.GeoServerAnonymousAuthenticationFilter.doFilter(GeoServerAnonymousAuthenticationFilter.java:51) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:70) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:205) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:74) at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91) at org.geoserver.security.filter.GeoServerUserNamePasswordAuthenticationFilter.doFilter(GeoServerUserNamePasswordAuthenticationFilter.java:112) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:70) at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:157) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:74) at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.oauth2.GeoServerOAuthAuthenticationFilter.doFilter(GeoServerOAuthAuthenticationFilter.java:172) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:70) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:91) at org.geoserver.security.filter.GeoServerSecurityContextPersistenceFilter$1.doFilter(GeoServerSecurityContextPersistenceFilter.java:52) at org.geoserver.security.filter.GeoServerCompositeFilter$NestedFilterChain.doFilter(GeoServerCompositeFilter.java:74) at org.geoserver.security.filter.GeoServerCompositeFilter.doFilter(GeoServerCompositeFilter.java:91) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:213) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:176) at org.geoserver.security.GeoServerSecurityFilterChainProxy.doFilter(GeoServerSecurityFilterChainProxy.java:141) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.LoggingFilter.doFilter(LoggingFilter.java:90) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.GZIPFilter.doFilter(GZIPFilter.java:42) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.SessionDebugFilter.doFilter(SessionDebugFilter.java:46) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.geoserver.filters.FlushSafeFilter.doFilter(FlushSafeFilter.java:42) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:475) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:651) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:500) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:754) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1376) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.reflect.InvocationTargetException at sun.reflect.GeneratedMethodAccessor453.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.wicket.RequestListenerInterface.internalInvoke(RequestListenerInterface.java:258) ... 121 more Caused by: java.lang.RuntimeException: Not extistend role: ROLE_LONG-POINT-REGION-CONSERVATION-AUTHORITY at org.geoserver.security.impl.RoleHierarchyHelper.checkRole(RoleHierarchyHelper.java:136) at org.geoserver.security.impl.RoleHierarchyHelper.getDescendants(RoleHierarchyHelper.java:100) at org.geoserver.security.web.role.AbstractRolePage$ParentRolesModel.computeAllowableParentRoles(AbstractRolePage.java:131) at org.geoserver.security.web.role.AbstractRolePage$ParentRolesModel.(AbstractRolePage.java:116) at org.geoserver.security.web.role.AbstractRolePage.(AbstractRolePage.java:62) at org.geoserver.security.web.role.EditRolePage.(EditRolePage.java:23) at org.geoserver.security.web.role.RolePanel$3.onClick(RolePanel.java:153) at org.geoserver.web.wicket.SimpleAjaxLink$1.onClick(SimpleAjaxLink.java:47) at org.apache.wicket.ajax.markup.html.AjaxLink$1.onEvent(AjaxLink.java:85) at org.apache.wicket.ajax.AjaxEventBehavior.respond(AjaxEventBehavior.java:155) at org.apache.wicket.ajax.AbstractDefaultAjaxBehavior.onRequest(AbstractDefaultAjaxBehavior.java:601)

afabiani commented 6 years ago

Yes, most likely this could be a potential issue. At least it is a very good candidate.

mikefedak commented 6 years ago

Long story short.

This is an error related to how QGIS handles OWS. I tried using the services with ArcGIS Desktop 10.6 and encountered no issues.

I think this can be closed. Thank you for all of your help!

Below is the testing I did:

I noticed that if an account on geonode has the same account in geoserver, these issues are avoided. But that is not a good solution.

I've tried both QGIS 2.18 and 3.2, the behaviour is the same.

On a development machine running Ubuntu 18.04 and up to date with the latest 2.8.x and GS 2.13. Using paver, everything works as expected, until I shut down and restart the server. Added user, added to group, set permissions based only on group and then accessed via QGIS (3.2) then stopped paver.

Upon restarting paver, I am unable to access layers via OWS in QGIS with a non-superuser account, Curl returns a blank getcapabilities request. However if I make the request via a superuser account, the response is not blank and both accounts begin working as expected.

This is not the same as the 'Host Requires Authentication' error that is happening with layers on the production machine, here is the error in QGIS: 2018-10-17T12:41:09 WARNING Map request failed [error: Host requires authentication url: http://data.lprca.ca:80/gs/ows?access_token=m9OiZBSR0MdiNu3PFf0k6jV3pgO976&SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&BBOX=42.52624118634268768,-80.95130137281456939,43.10972400793487225,-79.70963563780229322&CRS=EPSG:4326&WIDTH=63&HEIGHT=30&LAYERS=geonode:swoop2006&STYLES=&FORMAT=image/png&DPI=96&MAP_RESOLUTION=96&FORMAT_OPTIONS=dpi:96&TRANSPARENT=TRUE]

If you curl (or use your browser) the link above it succeeds. So the user is definitely being given a valid token and being authenticated. But for some reason, GetMap requests are triggering a 401.

Next I tried the link in postman with basic authentication (access token omitted). Here I managed to get a 401 unauthorized response. It seems that if you try and use the ows getmap endpoint with basic auth; you are unauthorized, at least on that server. On the dev server, I can make the same request with a rest client and have no issue. But then I logged out of geonode and tried the same request again; not so successful this time:

<?xml version="1.0" encoding="UTF-8"?> Could not find layer geonode:greatlakes_subbasins

Just to make sure, I logged back in. And it is successful again. Likewise, QGIS can no longer load layers either unless a superuser is logged into geonode or has submitted a valid getcapabilities request.

So as far as I can tell, the OAuth process is working to retrieve a valid token, on the production machine. However the machine is not accepting requests made with the token + basic_auth, only requests with just the token. The dev paver machine does not seem to care whether you use basic auth or not but it has the quirk of either needing to make a get capabilities request with a super user account outside of qgis or logging into geonode with a super user account before it will display layers.

On both the paver and the production sites, the roles page in geoserver gives the same error as above.

capooti commented 6 years ago

@mikefedak regarding your last comment, note that I am still hit by this: https://lists.osgeo.org/pipermail/geonode-users/2018-October/004848.html

There must be a relation with the two problems.

mikefedak commented 6 years ago

@mikefedak regarding your last comment, note that I am still hit by this: https://lists.osgeo.org/pipermail/geonode-users/2018-October/004848.html

There must be a relation with the two problems.

I think there is. I had another person test and they could not login via ArcGIS.

I decided to continue trying to replicate so I went into the admin interface and deleted all access tokens then attempted to use the WMS via Arc/Q. Attempting to access via ArcGIS creates no new access token in GeoNode, instead it tries to authenticate using an old access token. The Geoserver log looks like this:

2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/web/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/gwc/rest/web/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_security_check' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_security_check/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_oauth2_geonode_login' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_oauth2_geonode_login/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_security_logout' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_security_logout/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_oauth2_geonode_logout' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/j_spring_oauth2_geonode_logout/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/rest/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/gwc/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/geofence/rest/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/geofence/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ'; against '/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Request matched by universal pattern '/' 2018-10-18 01:00:30,563 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /wms, QueryString: SERVICE=WMS&VERSION=1.3.0&REQUEST=GetCapabilities&access_token=qDqcDP5FiMddfLS0R7dtlp1D99NELQ with /** 2018-10-18 01:00:30,640 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-18 01:00:30,640 DEBUG [geoserver.security] - Found 4 cookies! 2018-10-18 01:00:30,640 DEBUG [geoserver.security] - Found Custom Session cookie: swsllpt9ffsajawpk3fsfco9trva7r80 2018-10-18 01:00:30,670 DEBUG [geoserver.security] - preAuthenticatedPrincipal = null, trying to authenticate 2018-10-18 01:00:30,670 DEBUG [geoserver.monitor] - Testing /wms for monitor filtering 2018-10-18 01:00:30,677 DEBUG [ows.OWSHandlerMapping] - Mapping [/wms] to HandlerExecutionChain with handler [org.geoserver.ows.Dispatcher@160a777d] and 1 interceptor 2018-10-18 01:00:30,677 INFO [geoserver.wms] - Request: getServiceInfo 2018-10-18 01:00:30,677 INFO [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] starting, processing through flow controllers 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@2a8f51e4) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wfs.getfeature.=application/msexcel,org.geoserver.flow.controller.SimpleThreadBlocker@2a8f51e4) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] checking flow controller org.geoserver.flow.controller.UserConcurrentFlowController@f2b1a09 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - UserFlowController(6,GS_CFLOW_1966cd53:1667f786208:-7e03) queue size 1 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - UserFlowController(6,GS_CFLOW_1966cd53:1667f786208:-7e03) total queues 5 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - UserFlowController(6) purged 4 stale queues 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] passed flow controller org.geoserver.flow.controller.UserConcurrentFlowController@f2b1a09 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] checking flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@276f80a6) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] passed flow controller BasicOWSController(wms.getmap,org.geoserver.flow.controller.SimpleThreadBlocker@276f80a6) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] checking flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@70c33d10) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] passed flow controller BasicOWSController(gwc,org.geoserver.flow.controller.SimpleThreadBlocker@70c33d10) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] checking flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@3148668) 2018-10-18 01:00:30,677 DEBUG [geoserver.flow] - Request [WMS 1.3.0 GetCapabilities] passed flow controller GlobalFlowController(org.geoserver.flow.controller.SimpleThreadBlocker@3148668) 2018-10-18 01:00:30,677 INFO [geoserver.flow] - Request control-flow performed, running requests: 1, blocked requests: 0 2018-10-18 01:00:30,678 INFO [geoserver.wms] - Request: getCapabilities BaseUrl = http://localhost:8080/geoserver/ Get = false Namespace = null RawKvp = {REQUEST=GetCapabilities, ACCESS_TOKEN=qDqcDP5FiMddfLS0R7dtlp1D99NELQ, VERSION=1.3.0, SERVICE=WMS} Request = GetCapabilities RequestCharset = null UpdateSequence = null Version = 1.3.0 2018-10-18 01:00:30,679 DEBUG [wms.capabilities] - producing a capabilities document for GetCapabilities [service: WMS, version: 1.3.0] 2018-10-18 01:00:30,679 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-18 01:00:30,679 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-18 01:00:30,679 DEBUG [sqlserver.jtds] - Target not a string 2018-10-18 01:00:30,679 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Layer Assessment 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Resource Assessment 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Assessment"+] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Assessment] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Assessment and user 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Layer CGG2013_Watershed 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Resource CGG2013_Watershed 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"CGG2013_Watershed"+] 2018-10-18 01:00:30,680 INFO [geofence.cache] - Rules :CacheStats{hitCount=10081, missCount=218, loadSuccessCount=202, loadExceptionCount=0, totalLoadTime=2537522188, evictionCount=99} 2018-10-18 01:00:30,680 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=487, loadSuccessCount=0, loadExceptionCount=486, totalLoadTime=885781721, evictionCount=0} 2018-10-18 01:00:30,680 INFO [geofence.cache] - Auth :CacheStats{hitCount=15133, missCount=32, loadSuccessCount=14, loadExceptionCount=0, totalLoadTime=6992073785, evictionCount=6} 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - params :CacheConfiguration[size=500000 refrMsec=6000000, expMsec=6000000] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[CGG2013_Watershed] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.INCLUDE, mode=HIDE] for layer geonode:CGG2013_Watershed and user 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Layer Dimensions 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Resource Dimensions 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"Dimensions"+] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[Dimensions] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:Dimensions and user 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Layer HL_Adjustment_09_07_2018 2018-10-18 01:00:30,680 DEBUG [geoserver.geofence] - Getting access limits for Resource HL_Adjustment_09_07_2018 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HL_Adjustment_09_07_2018"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[HL_Adjustment_09_07_2018] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:HL_Adjustment_09_07_2018 and user 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Layer HT20_Watershed 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Resource HT20_Watershed 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"HT20_Watershed"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[HT20_Watershed] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.INCLUDE, mode=HIDE] for layer geonode:HT20_Watershed and user 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Layer LIO_Duplicates 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Resource LIO_Duplicates 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"LIO_Duplicates"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[LIO_Duplicates] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:LIO_Duplicates and user 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Layer SWOOP2010_DEM 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Resource SWOOP2010_DEM 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"SWOOP2010_DEM"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[SWOOP2010_DEM] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:SWOOP2010_DEM and user 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Layer cgg13aht20diff 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Resource cgg13aht20diff 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"cgg13aht20diff"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[cgg13aht20diff] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.INCLUDE, mode=HIDE] for layer geonode:cgg13aht20diff and user 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Layer generic_regulation_limit_lprca_nov23_16 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Getting access limits for Resource generic_regulation_limit_lprca_nov23_16 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-18 01:00:30,681 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"generic_regulation_limit_lprca_nov23_16"+] 2018-10-18 01:00:30,681 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[generic_regulation_limit_lprca_nov23_16] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.INCLUDE, readFilter=Filter.INCLUDE, mode=HIDE] for layer geonode:generic_regulation_limit_lprca_nov23_16 and user 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Layer lidar_dtm_2018_cgvd13 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Resource lidar_dtm_2018_cgvd13 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lidar_dtm_2018_cgvd13"+] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[lidar_dtm_2018_cgvd13] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:lidar_dtm_2018_cgvd13 and user 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Layer lprca_ws_boundarywgs84 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Resource lprca_ws_boundarywgs84 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"lprca_ws_boundarywgs84"+] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[lprca_ws_boundarywgs84] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.INCLUDE, readFilter=Filter.INCLUDE, mode=HIDE] for layer geonode:lprca_ws_boundarywgs84 and user 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Layer qgis4326 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Resource qgis4326 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"qgis4326"+] 2018-10-18 01:00:30,682 INFO [geofence.cache] - Rules :CacheStats{hitCount=10091, missCount=218, loadSuccessCount=202, loadExceptionCount=0, totalLoadTime=2537522188, evictionCount=99} 2018-10-18 01:00:30,682 INFO [geofence.cache] - Users :CacheStats{hitCount=0, missCount=487, loadSuccessCount=0, loadExceptionCount=486, totalLoadTime=885781721, evictionCount=0} 2018-10-18 01:00:30,682 INFO [geofence.cache] - Auth :CacheStats{hitCount=15143, missCount=32, loadSuccessCount=14, loadExceptionCount=0, totalLoadTime=6992073785, evictionCount=6} 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - params :CacheConfiguration[size=500000 refrMsec=6000000, expMsec=6000000] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning mode HIDE for resource FeatureTypeInfoImpl[qgis4326] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning VectorAccessLimits [readAttributes=null, writeAttributes=null, writeFilter=Filter.EXCLUDE, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:qgis4326 and user 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2006 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2006 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2006"+] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2006] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2006 and user 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2010 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2010 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-18 01:00:30,682 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2010"+] 2018-10-18 01:00:30,682 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2010] 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2010 and user 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,683 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting access limits for Layer swoop2015_0416 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting access limits for Resource swoop2015_0416 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Setting user for filter: 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - ResourceInfo filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-18 01:00:30,683 DEBUG [geofence.cache] - Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:"WMS"+ req:"GETCAPABILITIES"+ ws:"geonode"+ layer:"swoop2015_0416"+] 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Returning mode HIDE for resource CoverageInfoImpl[swoop2015_0416] 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Returning CoverageAccessLimits [params=null, rasterFilter=null, readFilter=Filter.EXCLUDE, mode=HIDE] for layer geonode:swoop2015_0416 and user 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting access limits for workspace geonode 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Getting admin auth for Workspace geonode 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - AdminAuth filter: RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,683 DEBUG [geofence.cache] - AdminAuth Request for RuleFilter[user:(empty)+ role:ANY inst:name+:default-gs ip:"0:0:0:0:0:0:0:1"+ serv:ANY req:ANY ws:"geonode"+ layer:ANY] 2018-10-18 01:00:30,683 DEBUG [geoserver.geofence] - Admin auth for User: Workspace:geonode: false 2018-10-18 01:00:30,683 DEBUG [wms.capabilities] - Collecting summarized latlonbbox and common SRS... 2018-10-18 01:00:30,683 DEBUG [wms.capabilities] - Summarized LatLonBBox is Env[-80.9705650949935 : -79.69918452094274, 42.488737851779284 : 43.1182794736872] 2018-10-18 01:00:30,684 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,685 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,686 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,687 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,688 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,688 DEBUG [wms.capabilities] - Adding GetLegendGraphic call as LegendURL 2018-10-18 01:00:30,689 DEBUG [geoserver.filters] - Compressing output for mimetype: text/xml 2018-10-18 01:00:30,689 INFO [geoserver.flow] - releasing flow controllers for [WMS 1.3.0 GetCapabilities] 2018-10-18 01:00:30,689 INFO [geoserver.flow] - Request completed, running requests: 0, blocked requests: 0 2018-10-18 01:00:30,690 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-18 01:00:30,690 DEBUG [geotools.util] - CRSConverterFactory can be applied from Strings to CRS only. 2018-10-18 01:00:30,690 DEBUG [geotools.util] - InterpolationConverterFactory can be applied from Strings to Interpolation only. 2018-10-18 01:00:30,690 DEBUG [sqlserver.jtds] - Target not a string 2018-10-18 01:00:30,690 TRACE [sqlserver.jtds] - Target is not a Date 2018-10-18 01:00:40,701 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 7-1.IFormSubmitListener-form&lines=1000'; against '/web/' 2018-10-18 01:00:40,701 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: 7-1.IFormSubmitListener-form&lines=1000 with /web/ 2018-10-18 01:00:40,701 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-18 01:00:40,702 DEBUG [geoserver.security] - Found 4 cookies! 2018-10-18 01:00:40,702 DEBUG [geoserver.security] - Found Custom Session cookie: k8rdyf04j7qcigf5xbded3okgne6cazs 2018-10-18 01:00:40,702 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-18 01:00:40,702 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,714 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,714 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,715 DEBUG [org.geoserver] - Thread 92 locking in mode READ 2018-10-18 01:00:40,715 DEBUG [org.geoserver] - Thread 92 got the lock in mode READ 2018-10-18 01:00:40,716 DEBUG [org.geoserver] - Thread 92 locking in mode READ 2018-10-18 01:00:40,716 DEBUG [org.geoserver] - Thread 92 releasing the lock in mode READ 2018-10-18 01:00:40,719 DEBUG [filter.GeoServerSecurityContextPersistenceFilter$1] - SecurityContextHolder now cleared, as request processing completed 2018-10-18 01:00:40,755 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Checking match of request : 'Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=1000'; against '/web/' 2018-10-18 01:00:40,755 DEBUG [security.IncludeQueryStringAntPathRequestMatcher] - Matched Path: /web/wicket/bookmarkable/org.geoserver.web.admin.logpage, QueryString: lines=1000 with /web/ 2018-10-18 01:00:40,756 DEBUG [geoserver.security] - Inspecting the http request looking for the Custom Session ID. 2018-10-18 01:00:40,756 DEBUG [geoserver.security] - Found 4 cookies! 2018-10-18 01:00:40,756 DEBUG [geoserver.security] - Found Custom Session cookie: k8rdyf04j7qcigf5xbded3okgne6cazs 2018-10-18 01:00:40,756 DEBUG [geoserver.monitor] - Testing /web/wicket/bookmarkable/org.geoserver.web.admin.LogPage for monitor filtering 2018-10-18 01:00:40,756 DEBUG [geoserver.monitor] - /geoserver/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage was filtered from monitoring 2018-10-18 01:00:40,766 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,766 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,766 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,766 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,766 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,766 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,767 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,767 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,767 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,767 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,767 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,767 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,767 DEBUG [geoserver.ows] - Could not a layer group named web 2018-10-18 01:00:40,767 TRACE [ows.OWSHandlerMapping] - No handler mapping found for [/web/wicket/bookmarkable/org.geoserver.web.admin.LogPage] 2018-10-18 01:00:40,767 DEBUG [org.geoserver] - Thread 96 locking in mode READ 2018-10-18 01:00:40,767 DEBUG [org.geoserver] - Thread 96 got the lock in mode READ

mikefedak commented 6 years ago

With QGIS , a new access token is created every time a request is made for a layer and a bad credentials error is thrown. This generates the error: Host requires authentication url error (see below).

I know that if I keep trying to access these services in various ways, eventually ArcGIS works as intended. QGIS though continues with the authentication errors; for all users who are not the admin or not duplicated on geoserver.

afabiani commented 6 years ago

This should be improved/fixed (hopefully) by this commit

https://github.com/GeoNode/geonode/commit/b77962ab7bfdcf903f98035214ee28891ab9d5e1

GeoNode / geonode

Adding group access makes layer public #3993