Re: [Geoserver-users] Geoserver/Geofence issue - very slow response time

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

Hi Cesar,
two quick feedbacks:

   - The control flow timeout is for requests sitting in queue, waiting to
   be executed. There is no way to stop a request that's in progress, all the
   code in GeoServer should periodically check for the timeout and willingly
   give up. I hope it's clear that's impossible to implement, against an
   application as large and as deep as GeoServer.
   - The behavior makes me wonder about the connection pool used by
   GeoFence and the target database... is the database part of the compose (so
   all local), or is it remote? If it's remote, the connections in the pool
   might get stale and might have to wait for a network timeout to get
   purged... which can take minutes.

If the database is external, see this documentation about connection
validation and timeout
<https://docs.geoserver.geo-solutions.it/edu/en/adv_gsconfig/db_pooling.html>,
which should be applicable to the GeoFence connection pool as well.

Regards,

Andrea Aime

==
GeoServer Professional Services from the experts!

Visit http://bit.ly/gs-services-us for more information.
==

Ing. Andrea Aime
@geowolf
Technical Lead

GeoSolutions Group
phone: +39 0584 962313

fax:     +39 0584 1660272

mob:   +39  339 8844549

https://www.geosolutionsgroup.com/

http://twitter.com/geosolutions_it

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

Con riferimento alla normativa sul trattamento dei dati personali (Reg. UE
2016/679 - Regolamento generale sulla protezione dei dati “GDPR”), si
precisa che ogni circostanza inerente alla presente email (il suo
contenuto, gli eventuali allegati, etc.) è un dato la cui conoscenza è
riservata al/i solo/i destinatario/i indicati dallo scrivente. Se il
messaggio Le è giunto per errore, è tenuta/o a cancellarlo, ogni altra
operazione è illecita. Le sarei comunque grato se potesse darmene notizia.

This email is intended only for the person or entity to which it is
addressed and may contain information that is privileged, confidential or
otherwise protected from disclosure. We remind that - as provided by
European Regulation 2016/679 “GDPR” - copying, dissemination or use of this
e-mail or the information herein by anyone other than the intended
recipient is prohibited. If you have received this email by mistake, please
notify us immediately by telephone or e-mail

On Fri, May 17, 2024 at 12:51 PM Cesar Rafael Lopes <ces...@gm...>
wrote:

> Emanuele, thank you, but I don't think the groups are an issue in this
> case because we don't have any.
>
> We use a standard geonode configuration in this context. We don't have any
> LDAP providers set up.
>
> Here are the settings for the services, users/groups, roles, and
> authentication settings:
>
>
>    - Services:
>    https://drive.google.com/file/d/1TO3a2Hdu4_OEZXqq2H-Juw5xBW9RQf2J/view?usp=drive_link
>    - Users/groups:
>    https://drive.google.com/file/d/1TV4hsZGayEwLyxg0rz6mrLQXkSZ7MTx1/view?usp=drive_link
>    - Roles:
>    https://drive.google.com/file/d/1kYy29yaejQ2FacjGMfCswwznmdi1lbog/view?usp=drive_link
>    - Authentication settings:
>    https://drive.google.com/file/d/1vBapSAp5YntrC7pEf_l-Fi_Nsmit5vuE/view?usp=drive_link
>
> One thing I was wondering, shouldn't the Control Flow plugin include the
> time necessary to get the clearance from Geofence plugin in its "timeout"
> setting?
>
> I suppose this is not the case currently, otherwise the requests wouldn't
> be taking 15 minutes to process because Control Flow would have terminated
> them.
>
> In our installation, the current setting is 60 seconds. But, as mentioned
> above, this seems to apply only after the request is authorized and being
> processed by the geoserver.
>
> Thank you once again,
>
> Cesar Rafael Lopes
>
>
> Em sex., 17 de mai. de 2024 às 04:43, Emanuele Tajariol <
> ema...@ge...> escreveu:
>
>> Hi Cesar,
>>
>> Another slowness point may be the retrieval of the groups belonging to
>> the user.
>> GeoFence first identifies the groups related to the user, then performs
>> queries on the DB to find out the user's privileges according to each group.
>>
>> How are your users/groups relation retrieved? If it is made through some
>> external system (LDAP, etc) the slowness may be related to that. That also
>> would explain why the requests for some users are slower (maybe a federated
>> system?).
>>
>>    Cheers,
>>    Emanuele
>>
>>
>> On Thu, May 16, 2024 at 7:01 PM Cesar Rafael Lopes <ces...@gm...>
>> wrote:
>>
>>> Emanuele, thank you for your input!
>>>
>>> We've checked any issues regarding the database and we haven't noticed
>>> anything that could indicate symptoms of problems in the database.
>>>
>>> Suppose it was database related, should have any setting in Geofence to
>>> force a timeout in this case?
>>>
>>> Here follows the response time for an occurrence;
>>>
>>>
>>> https://drive.google.com/file/d/1ARPuOvR9DUoYHMqpjxstnMIZGRKznXfg/view?usp=drive_link
>>>
>>> Here are the database metrics for the same time windows:
>>>
>>>
>>> https://drive.google.com/file/d/1_LLo-I1TzRTuYmXK58BEfs2g2wuJvDRk/view?usp=drive_link
>>>
>>> What's puzzling is that some requests get slowed down, and others don't,
>>> as shown below (the last column is the response time).
>>>
>>> Thank you again for your help,
>>>
>>> Cesar Rafael Lopes
>>>
>>> 1498 d7b3f5e632e9 /ows GET 2024-05-13 13:07:39.435000 2024-05-13
>>> 13:07:39.044000 5
>>> 1499 d7b3f5e632e9 /ows GET 2024-05-13 13:08:39.577000 2024-05-13
>>> 13:08:39.582000 5
>>> 27432 724bcc55953c /ows GET 2024-05-13 13:08:51.098000 2024-05-13
>>> 13:08:51.984000 4
>>> 27433 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,-5009377.085697312,-9.313225746154785e-10,-9.313225746154785e-10
>>> GET 2024-05-13 13:09:26.968000 2024-05-13 13:26:13.531000 1006563
>>> 27438 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,0,-9.313225746154785e-10,5009377.085697311
>>> GET 2024-05-13 13:09:27.051000 2024-05-13 13:09:38.209000 10699
>>> 27435 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,-5009377.085697312,-9.313225746154785e-10,-9.313225746154785e-10
>>> GET 2024-05-13 13:09:27.072000 2024-05-13 13:09:38.201000 11129
>>> 27436 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,0,-9.313225746154785e-10,5009377.085697311
>>> GET 2024-05-13 13:09:27.094000 2024-05-13 13:10:23.251000 56157
>>> 27437 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,0,-9.313225746154785e-10,5009377.085697311
>>> GET 2024-05-13 13:09:27.095000 2024-05-13 13:26:13.053000 1006435
>>> 27439 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_lpm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=50832a4c-3ea2-4f7e-8158-c8731ccf3ad1&layers=geonode:trecho_lpm_validado&query_layers=geonode:trecho_lpm_validado&styles=geonode:trecho_lpm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6701020.246082203;-2237586.991208935;-5712842.344411446;-1249409.0895381765&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:09:38.393000 2024-05-13 13:09:38.413000 20
>>> 27440 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_ltm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=4f9ed1cd-9570-49c5-9d31-37f839053da6&layers=geonode:trecho_ltm_validado&query_layers=geonode:trecho_ltm_validado&styles=geonode:trecho_ltm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6701020.246082203;-2237586.991208935;-5712842.344411446;-1249409.0895381765&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:09:38.405000 2024-05-13 13:09:38.042000 15
>>> 27441 724bcc55953c WMS 1.1.1 GetFeatureInfo
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=e47b8d93-76b8-46f0-86f6-76d960eb9ee9&layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&query_layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&styles=geonode:trecho_terreno_marinha_validado96290cf4eb5f&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6701020.246082203;-2237586.991208935;-5712842.344411446;-1249409.0895381765&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:09:38.482000 2024-05-13 13:09:38.497000 15
>>> 27442 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-5009377.085697312,-5009377.085697311,-9.313225746154785e-10
>>> GET 2024-05-13 13:09:38.498000 2024-05-13 13:26:13.537000 995039
>>> 27443 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-5009377.085697312,-5009377.085697311,-9.313225746154785e-10
>>> GET 2024-05-13 13:09:38.569000 2024-05-13 13:09:38.573000 4
>>> 27444 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-5009377.085697312,-5009377.085697311,-9.313225746154785e-10
>>> GET 2024-05-13 13:09:38.665000 2024-05-13 13:10:23.025000 44585
>>> 1500 d7b3f5e632e9 /ows GET 2024-05-13 13:09:39.072000 2024-05-13
>>> 13:09:39.723000 3
>>> 27445 724bcc55953c WFS 2.0.0 GetCapabilities /ows
>>> service=WFS&acceptversions=2.0.0&request=GetCapabilities GET 2024-05-13
>>> 13:09:48.545000 2024-05-13 13:09:48.702000 157
>>> 27446 724bcc55953c /ows GET 2024-05-13 13:09:52.077000 2024-05-13
>>> 13:09:52.081000 4
>>> 1501 d7b3f5e632e9 WFS 2.0.0 GetCapabilities /ows
>>> service=WFS&acceptversions=2.0.0&request=GetCapabilities GET 2024-05-13
>>> 13:10:17.985000 2024-05-13 13:10:18.128000 143
>>> 27448 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_ltm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=4f9ed1cd-9570-49c5-9d31-37f839053da6&layers=geonode:trecho_ltm_validado&query_layers=geonode:trecho_ltm_validado&styles=geonode:trecho_ltm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-5358663.610716395;-3227721.800236652;-4370485.709045637;-2239543.8985658935&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:10:23.036000 2024-05-13 13:10:23.376000 16
>>> 27447 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_lpm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=50832a4c-3ea2-4f7e-8158-c8731ccf3ad1&layers=geonode:trecho_lpm_validado&query_layers=geonode:trecho_lpm_validado&styles=geonode:trecho_lpm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-5358663.610716395;-3227721.800236652;-4370485.709045637;-2239543.8985658935&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:10:23.348000 2024-05-13 13:10:23.368000 20
>>> 27449 724bcc55953c WMS 1.1.1 GetFeatureInfo
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=e47b8d93-76b8-46f0-86f6-76d960eb9ee9&layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&query_layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&styles=geonode:trecho_terreno_marinha_validado96290cf4eb5f&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-5358663.610716395;-3227721.800236652;-4370485.709045637;-2239543.8985658935&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:10:23.362000 2024-05-13 13:10:23.397000 35
>>> 27450 724bcc55953c WMS 1.3.0 GetMap geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,-10018754.171394622,-9.313225746154785e-10,-5009377.085697311
>>> GET 2024-05-13 13:10:23.425000 2024-05-13 13:10:23.439000 14
>>> 27451 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,-10018754.171394622,-9.313225746154785e-10,-5009377.085697311
>>> GET 2024-05-13 13:10:23.435000 2024-05-13 13:26:13.565000 950130
>>> 27452 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-5009377.085697312,-10018754.171394622,-9.313225746154785e-10,-5009377.085697311
>>> GET 2024-05-13 13:10:23.468000 2024-05-13 13:10:23.496000 28
>>> 27453 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-10018754.171394622,-5009377.085697311,-5009377.085697311
>>> GET 2024-05-13 13:10:23.515000 2024-05-13 13:26:13.056000 950045
>>> 27454 724bcc55953c WMS 1.3.0 GetMap geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-10018754.171394622,-5009377.085697311,-5009377.085697311
>>> GET 2024-05-13 13:10:23.564000 2024-05-13 13:10:23.578000 14
>>> 27455 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,-10018754.171394622,-5009377.085697311,-5009377.085697311
>>> GET 2024-05-13 13:10:23.649000 2024-05-13 13:10:23.663000 14
>>> 27456 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,0,-5009377.085697311,5009377.085697311
>>> GET 2024-05-13 13:10:23.746000 2024-05-13 13:10:23.075000 4
>>> 27457 724bcc55953c WMS 1.3.0 GetMap geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,0,-5009377.085697311,5009377.085697311
>>> GET 2024-05-13 13:10:23.836000 2024-05-13 13:10:23.084000 4
>>> 27458 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-10018754.171394622,0,-5009377.085697311,5009377.085697311
>>> GET 2024-05-13 13:10:23.921000 2024-05-13 13:26:13.532000 949611
>>> 1502 d7b3f5e632e9 /ows GET 2024-05-13 13:10:39.864000 2024-05-13
>>> 13:10:39.868000 4
>>> 27460 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_lpm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=50832a4c-3ea2-4f7e-8158-c8731ccf3ad1&layers=geonode:trecho_lpm_validado&query_layers=geonode:trecho_lpm_validado&styles=geonode:trecho_lpm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6200053.512179188;-1334326.8068113958;-6196193.442250786;-1330466.7368829942&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:11:34.561000 2024-05-13 13:11:34.634000 73
>>> 27461 724bcc55953c WMS 1.1.1 GetFeatureInfo geonode:trecho_ltm_validado
>>> /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=4f9ed1cd-9570-49c5-9d31-37f839053da6&layers=geonode:trecho_ltm_validado&query_layers=geonode:trecho_ltm_validado&styles=geonode:trecho_ltm_validado&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6200053.512179188;-1334326.8068113958;-6196193.442250786;-1330466.7368829942&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:11:34.705000 2024-05-13 13:11:34.723000 18
>>> 27462 724bcc55953c WMS 1.1.1 GetFeatureInfo
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> service=WMS&version=1.1.1&request=GetFeatureInfo&exceptions=application/json&id=e47b8d93-76b8-46f0-86f6-76d960eb9ee9&layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&query_layers=geonode:trecho_terreno_marinha_validado96290cf4eb5f&styles=geonode:trecho_terreno_marinha_validado96290cf4eb5f&x=51&y=51&height=101&width=101&srs=EPSG:3857&bbox=-6200053.512179188;-1334326.8068113958;-6196193.442250786;-1330466.7368829942&feature_count=10&info_format=application/json&ENV=
>>> GET 2024-05-13 13:11:34.721000 2024-05-13 13:11:34.738000 17
>>> 27463 724bcc55953c WMS 1.3.0 GetMap
>>> geonode:trecho_terreno_marinha_validado96290cf4eb5f /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_terreno_marinha_validado96290cf4eb5f&STYLES=geonode:trecho_terreno_marinha_validado96290cf4eb5f&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-6261721.357121639,-1252344.271424327,-5009377.085697311,6.984919309616089e-10
>>> GET 2024-05-13 13:11:34.833000 2024-05-13 13:11:34.845000 12
>>> 27464 724bcc55953c WMS 1.3.0 GetMap   geonode:trecho_lpm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_lpm_validado&STYLES=geonode:trecho_lpm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-6261721.357121639,-1252344.271424327,-5009377.085697311,6.984919309616089e-10
>>> GET 2024-05-13 13:11:34.834000 2024-05-13 13:26:13.533000 878699
>>> 27465 724bcc55953c WMS 1.3.0 GetMap geonode:trecho_ltm_validado /ows
>>> SERVICE=WMS&VERSION=1.3.0&REQUEST=GetMap&FORMAT=image/png&TRANSPARENT=true&LAYERS=geonode:trecho_ltm_validado&STYLES=geonode:trecho_ltm_validado&SRS=EPSG:3857&CRS=EPSG:3857&TILED=true&WIDTH=512&HEIGHT=512&BBOX=-6261721.357121639,-1252344.271424327,-5009377.085697311,6.984919309616089e-10
>>> GET 2024-05-13 13:11:35.088000 2024-05-13 13:11:35.102000 14
>>> 1503 d7b3f5e632e9 /ows GET 2024-05-13 13:11:40.002000 2024-05-13
>>> 13:11:40.006000 4
>>> 1504 d7b3f5e632e9 /ows GET 2024-05-13 13:12:40.144000 2024-05-13
>>> 13:12:40.147000 3
>>> 27467 724bcc55953c WFS 2.0.0 GetCapabilities /ows
>>> service=WFS&acceptversions=2.0.0&request=GetCapabilities GET 2024-05-13
>>> 13:12:49.257000 2024-05-13 13:12:49.414000 157
>>>
>>>
>>> Em qui., 16 de mai. de 2024 às 11:15, Emanuele Tajariol <
>>> ema...@ge...> escreveu:
>>>
>>>> Hi Cesar,
>>>>
>>>> I see that in the first log,  all of the delay is in the first two log
>>>> lines:
>>>> 2024-05-13 12:54:33.000000
>>>> 2024-05-13 13:10:23.000000
>>>> Then the outcome is returned just within the same second of the second
>>>> line.
>>>> You may want to check whether in the other occasions you experiment the
>>>> issue the main delay is there.
>>>>
>>>> Selection from DB is usually immediate, so I wonder if there may by
>>>> hiccups in your DB.
>>>> You may want to monitor the DB health and the SELECTIion times.
>>>>
>>>>    Cheers,
>>>>    Emanuele
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On Thu, May 16, 2024 at 2:44 PM Cesar Rafael Lopes <ces...@gm...>
>>>> wrote:
>>>>
>>>>> Hello all,
>>>>>
>>>>> This is my first time using the mailing list. I have always been a fan
>>>>> of all the knowledge shared through this powerful tool. Also, I would like
>>>>> to thank you in advance for any time you may invest in this particular case.
>>>>>
>>>>> I'm having an issue that, after some good time invested in
>>>>> investigation, seems related to the Geofence plugin.
>>>>>
>>>>> We use a Geonode installation to serve datasets and maps.
>>>>>
>>>>> While using the maps, some users occasionally observe a kind of system
>>>>> slowdown, until it stops responding at all. On some occasions, this might
>>>>> affect all users, however, most frequently only some users are affected.
>>>>>
>>>>> After a vast analysis of any possible bottleneck regarding our
>>>>> infrastructure, we excluded that hypothesis. I will provide some details
>>>>> regarding the infrastructure later in this post.
>>>>>
>>>>> At some point we've enabled the "audit.enable" option in the
>>>>> "monitor.properties" (Monitor plugin) and also elevated the logs to VERBOSE.
>>>>>
>>>>> What we found out was that, for some reason, the Geofence plugin was
>>>>> taking a huge amount of time to get the response from
>>>>> "services.RuleReaderServiceImpl".
>>>>>
>>>>> Here is an extract from the geoserver.log:
>>>>>
>>>>> 2024-05-13 12:54:33.000000 INFO services.RuleReaderServiceImpl
>>>>> Requesting access for RuleFilter[user:"anonymous"+ role:ANY
>>>>> inst:name+:default-gs ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+
>>>>> sub:ANY ws:"geonode"+ layer:"trecho_ltm_validado"+]
>>>>> 2024-05-13 13:10:23.000000 DEBUG util.FilterUtils ADDED Rule[id:20358
>>>>> pri:14322 srv:WMS ws:geonode l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 13:10:23.000000 DEBUG util.FilterUtils ADDED Rule[id:20365
>>>>> pri:14329 ws:geonode l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 13:10:23.000000 DEBUG services.RuleReaderServiceImpl Filter
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+] is matching the following Rules:
>>>>> 2024-05-13 13:10:23.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS
>>>>> 2024-05-13 13:10:23.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS ---> Rule[id:20358 pri:14322 srv:WMS ws:geonode
>>>>> l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 13:10:23.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS ---> Rule[id:20365 pri:14329 ws:geonode
>>>>> l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 13:10:23.000000 DEBUG services.RuleReaderServiceImpl Filter
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+] on role ROLE_ANONYMOUS has access
>>>>> AccessInfoInternal[grant:ALLOW]
>>>>> 2024-05-13 13:10:23.000000 INFO services.RuleReaderServiceImpl
>>>>> Returning AccessInfo[grant:ALLOW admin:false] for
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+]
>>>>>
>>>>> The Geofence took more than 15 minutes to process the rule validation
>>>>> (from 12h54 to 13h10).
>>>>>
>>>>> However, the same request, just a second before ran just fine:
>>>>>
>>>>> 2024-05-13 12:53:15.000000 INFO services.RuleReaderServiceImpl
>>>>> Requesting access for RuleFilter[user:"anonymous"+ role:ANY
>>>>> inst:name+:default-gs ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+
>>>>> sub:ANY ws:"geonode"+ layer:"trecho_ltm_validado"+]
>>>>> 2024-05-13 12:53:15.000000 DEBUG util.FilterUtils ADDED Rule[id:20358
>>>>> pri:14322 srv:WMS ws:geonode l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 12:53:15.000000 DEBUG util.FilterUtils ADDED Rule[id:20365
>>>>> pri:14329 ws:geonode l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 12:53:15.000000 DEBUG services.RuleReaderServiceImpl Filter
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+] is matching the following Rules:
>>>>> 2024-05-13 12:53:15.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS
>>>>> 2024-05-13 12:53:15.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS ---> Rule[id:20358 pri:14322 srv:WMS ws:geonode
>>>>> l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 12:53:15.000000 DEBUG services.RuleReaderServiceImpl
>>>>> Role:ROLE_ANONYMOUS ---> Rule[id:20365 pri:14329 ws:geonode
>>>>> l:trecho_ltm_validado acc:ALLOW]
>>>>> 2024-05-13 12:53:15.000000 DEBUG services.RuleReaderServiceImpl Filter
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+] on role ROLE_ANONYMOUS has access
>>>>> AccessInfoInternal[grant:ALLOW]
>>>>> 2024-05-13 12:53:15.000000 INFO services.RuleReaderServiceImpl
>>>>> Returning AccessInfo[grant:ALLOW admin:false] for
>>>>> RuleFilter[user:"anonymous"+ role:ANY inst:name+:default-gs
>>>>> ip:"177.174.226.207"+ serv:"WMS"+ req:"GETMAP"+ sub:ANY ws:"geonode"+
>>>>> layer:"trecho_ltm_validado"+]
>>>>>
>>>>> Just to be clear, this affects not only one request per occurrence,
>>>>> but several requests endure the same issue as demonstrated above.
>>>>>
>>>>> We checked that everything that happened after the Geofence clears the
>>>>> authorization process, runs always very smoothly. The Control Flow plugin
>>>>> fires up and blocks some requests but it is only because they all got
>>>>> retained in the Geofence plugin in the first place. So, once they are all
>>>>> freed up from Geofence, the Control Flow plugin does its job.
>>>>>
>>>>> We can visualize how this is affecting user experience by inspecting
>>>>> the average response time graphic below (extracted from the Apache server
>>>>> in front of the Geonode installation). So, we might detect the date and
>>>>> time the application registered any issue, and then we proceed with the log
>>>>> investigation (geoserver.log and geoserver_audit.log). Each time, the
>>>>> pattern below was identified, the Geofence plugin was slowing down some
>>>>> requests.
>>>>>
>>>>> [image: image.png]
>>>>>
>>>>> This is happening 2 to 3 times per day, every day, with rare
>>>>> exceptions of no occurrence over weekends.
>>>>>
>>>>> There aren't that many requests processed per second, as shown below:
>>>>>
>>>>> [image: image.png]
>>>>>
>>>>> Here are some details regarding the installation and the
>>>>> infrastructure:
>>>>>
>>>>>    - GeoServer Version: 2.23.0
>>>>>    - JVM Version Oracle Corporation: 11.0.16 (OpenJDK 64-Bit Server
>>>>>    VM)
>>>>>    - Operating system (host machine): Red Hat Enterprise Linux
>>>>>    release 8.9 (Ootpa)
>>>>>
>>>>> Also, important to note that it's a Geonode "docker compose"
>>>>> installation, following Geonode best practices.
>>>>>
>>>>> The Geoserver has 82 Layers, 0 Layer groups, 11 Stores and 1
>>>>> Workspace. The Geofence plugin has 3379 Data Rules.
>>>>>
>>>>> The Geofence is running against a Postgres database, as
>>>>> recommended for a production environment. The image in the link below
>>>>> provides some of the current settings:
>>>>>
>>>>>
>>>>> https://drive.google.com/file/d/1cstSfZUMXHw113XlUFc2L-WwS0RW5l20/view?usp=sharing
>>>>>
>>>>> The host machine has 8 CPU, 32 Gb of ram and the JVM is set up to 16Gb
>>>>> of ram (set up as -Xms16G and -Xmx16G and +UseG1GC).
>>>>>
>>>>> The link below provide some logs (geoserver.log and
>>>>> geoserver_audit.log) for two of the occurrences lastly analysed:
>>>>>
>>>>> *https://drive.google.com/drive/folders/1TRkysrQmAKoB6ZeERYh5YqDjdFZ-fx9G?usp=sharing
>>>>> <https://drive.google.com/drive/folders/1TRkysrQmAKoB6ZeERYh5YqDjdFZ-fx9G?usp=sharing>*
>>>>>
>>>>> Thank you again, and any support is more than welcome.
>>>>>
>>>>> Cesar Rafael Lopes
>>>>> _______________________________________________
>>>>> Geoserver-users mailing list
>>>>>
>>>>> Please make sure you read the following two resources before posting
>>>>> to this list:
>>>>> - Earning your support instead of buying it, but Ian Turton:
>>>>> http://www.ianturton.com/talks/foss4g.html#/
>>>>> - The GeoServer user list posting guidelines:
>>>>> http://geoserver.org/comm/userlist-guidelines.html
>>>>>
>>>>> If you want to request a feature or an improvement, also see this:
>>>>> https://github.com/geoserver/geoserver/wiki/Successfully-requesting-and-integrating-new-features-and-improvements-in-GeoServer
>>>>>
>>>>>
>>>>> Geo...@li...
>>>>> https://lists.sourceforge.net/lists/listinfo/geoserver-users
>>>>>
>>>>
>>>>
>>>> --
>>>> Regards,
>>>> Emanuele Tajariol
>>>> ==
>>>> GeoServer Professional Services from the experts!
>>>> Visit http://bit.ly/gs-services-us for more information.
>>>> ==
>>>>
>>>> Ing. Emanuele Tajariol
>>>> Technical Lead
>>>>
>>>> GeoSolutions Group
>>>> mobile: +39 347 7895230
>>>> office: +39 0584 962313
>>>> fax:      +39 0584 1660272
>>>>
>>>> https://www.geosolutionsgroup.com/
>>>> http://twitter.com/geosolutions_it
>>>> -------------------------------------------------------
>>>>
>>>> Con riferimento alla normativa sul trattamento dei dati personali (Reg.
>>>> UE 2016/679 - Regolamento generale sulla protezione dei dati “GDPR”), si
>>>> precisa che ogni circostanza inerente alla presente email (il suo
>>>> contenuto, gli eventuali allegati, etc.) è un dato la cui conoscenza è
>>>> riservata al/i solo/i destinatario/i indicati dallo scrivente. Se il
>>>> messaggio Le è giunto per errore, è tenuta/o a cancellarlo, ogni altra
>>>> operazione è illecita. Le sarei comunque grato se potesse darmene notizia.
>>>>
>>>> This email is intended only for the person or entity to which it is
>>>> addressed and may contain information that is privileged, confidential or
>>>> otherwise protected from disclosure. We remind that - as provided by
>>>> European Regulation 2016/679 “GDPR” - copying, dissemination or use of this
>>>> e-mail or the information herein by anyone other than the intended
>>>> recipient is prohibited. If you have received this email by mistake, please
>>>> notify us immediately by telephone or e-mail.
>>>>
>>>>
>>
>> --
>> Regards,
>> Emanuele Tajariol
>> ==
>> GeoServer Professional Services from the experts!
>> Visit http://bit.ly/gs-services-us for more information.
>> ==
>>
>> Ing. Emanuele Tajariol
>> Technical Lead
>>
>> GeoSolutions Group
>> mobile: +39 347 7895230
>> office: +39 0584 962313
>> fax:      +39 0584 1660272
>>
>> https://www.geosolutionsgroup.com/
>> http://twitter.com/geosolutions_it
>> -------------------------------------------------------
>>
>> Con riferimento alla normativa sul trattamento dei dati personali (Reg.
>> UE 2016/679 - Regolamento generale sulla protezione dei dati “GDPR”), si
>> precisa che ogni circostanza inerente alla presente email (il suo
>> contenuto, gli eventuali allegati, etc.) è un dato la cui conoscenza è
>> riservata al/i solo/i destinatario/i indicati dallo scrivente. Se il
>> messaggio Le è giunto per errore, è tenuta/o a cancellarlo, ogni altra
>> operazione è illecita. Le sarei comunque grato se potesse darmene notizia.
>>
>> This email is intended only for the person or entity to which it is
>> addressed and may contain information that is privileged, confidential or
>> otherwise protected from disclosure. We remind that - as provided by
>> European Regulation 2016/679 “GDPR” - copying, dissemination or use of this
>> e-mail or the information herein by anyone other than the intended
>> recipient is prohibited. If you have received this email by mistake, please
>> notify us immediately by telephone or e-mail.
>>
>> _______________________________________________
> Geoserver-users mailing list
>
> Please make sure you read the following two resources before posting to
> this list:
> - Earning your support instead of buying it, but Ian Turton:
> http://www.ianturton.com/talks/foss4g.html#/
> - The GeoServer user list posting guidelines:
> http://geoserver.org/comm/userlist-guidelines.html
>
> If you want to request a feature or an improvement, also see this:
> https://github.com/geoserver/geoserver/wiki/Successfully-requesting-and-integrating-new-features-and-improvements-in-GeoServer
>
>
> Geo...@li...
> https://lists.sourceforge.net/lists/listinfo/geoserver-users
>