finch crashes when trying to extract ERA5 data

[richardarsenault]

In a notebook on the pavics.ouranos.ca server, running the following code results in an error:

from birdy import WPSClient
import xarray as xr
import os
import datetime as dt

# ERA5 reanalysis data, used as the observations for the bias-correction step.
observations = 'https://pavics.ouranos.ca/twitcher/ows/proxy/thredds/dodsC/datasets/reanalyses/era5.ncml'

# Extract the data for historical ERA5 pseudo-observations
start = dt.datetime(1980,1,1)
stop = dt.datetime(1989,12,31)

finch_url = os.environ.get("FINCH_WPS_URL", "https://pavics.ouranos.ca/twitcher/ows/proxy/finch/wps")
finch = WPSClient(finch_url)

era5_resp = finch.subset_polygon(resource=observations, shape='input.geojson', start_date=start, end_date=stop)

After about 10-15 seconds, I get the following error:

ServiceException: <?xml version="1.0" encoding="utf-8"?>
<ExceptionReport version="1.0.0"
    xmlns="http://www.opengis.net/ows/1.1"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://www.opengis.net/ows/1.1 http://schemas.opengis.net/ows/1.1.0/owsExceptionReport.xsd">
    <Exception exceptionCode="NoApplicableCode" locator="NotAcceptable">
        <ExceptionText>Request failed: (&#x27;Connection aborted.&#x27;, RemoteDisconnected(&#x27;Remote end closed connection without response&#x27;))</ExceptionText>
    </Exception>
</ExceptionReport>

Any help on how to make this work is appreciated!

[richardarsenault]

Adding info: It does the same thing when trying to extract data from a climate model, such as :
https://pavics.ouranos.ca/twitcher/ows/proxy/thredds/dodsC/datasets/simulations/cmip5_multirun/atmos/day_MPI-ESM-LR_historical+rcp85.ncml

Looking like a timeout problem?

[cjauvin]

@aulemahal ou @tlvu vous avez une idée par rapport à ça?

[aulemahal]

Salut! @richardarsenault J'ai pas étudié la chose encore, mais qu'est-ce qu'il y a dans input.geojson? C'est gros comment?

[richardarsenault]

Salut! C'est très petit, quelques kb. Le input.geojson est en p-j. Le bassin versant en entier fait quelque chose comme 1500km2. J'en ai essayé des plus gros et des plus petits, mais toujours la même finalité.

input.zip

Merci pour le coup de main!

[aulemahal]

@richardarsenault Vraiment désolé du délai!
Après avoir étudié la chose, je pense que le problème est du côté de ERA5.
@huard je sais que tu as déjà vu ça, non? Des timeouts à cause de la lourdeur de ERA5 sur thredds?

[richardarsenault]

Salut, merci pour le suivi et pas de problème, je sais que c'est compliqué ces choses là!!

C'est vrai que ERA5 est lourd, mais même quand on ne prend qu'une seule année ça plante assez rapidement. J'avais aussi testé avec des données de modèle de climat, même problème:
https://pavics.ouranos.ca/twitcher/ows/proxy/thredds/dodsC/datasets/simulations/cmip5_multirun/atmos/day_MPI-ESM-LR_historical+rcp85.ncml

Et ici les données sont pas mal moins lourdes pourtant.

Je sais que je n'apporte pas vraiment de solution ici, désolé!

Et merci du suivi!

[aulemahal]

Si tu réessayes plusieurs fois et que ça plante très rapidement, regarde le message d'erreur, s'il contient "Maximum number of parallel running processes reached", c'est un autre problème. Un vieux bogue de pyWPS/finch qui paralyse finch en entier après un certain nombre de "timeout".

De mon bord, avec les données MPI-ESM_LR, une erreur survient parce qu'aucun des points de grille ne tombe dans le polygone (qui est tout de même petit au final!).

[richardarsenault]

@aulemahal Salut! Merci pour le suivi. Je viens de faire un test avec les données du modèle climatique avec un nouveau fichier de contours d'un bassin versant de 17000km2, et j'ai la même erreur. Le fichier de inputs est dispo ici: https://pavics.ouranos.ca/wpsoutputs/28e87efa-c33d-11eb-a61e-0242ac120003/input.geojson

Après environ 15-20 secondes de calcul, j'obtiens l'erreur suivante:

---------------------------------------------------------------------------
ServiceException                          Traceback (most recent call last)
<ipython-input-4-5b725e87f804> in <module>
      6     shape='input.geojson',
      7     start_date=start,
----> 8     end_date=stop
      9 )

</opt/conda/envs/birdy/lib/python3.7/site-packages/birdy/client/base.py-619> in average_polygon(self, resource, shape, tolerance, start_date, end_date, variable, output_formats)

/opt/conda/envs/birdy/lib/python3.7/site-packages/birdy/client/base.py in _execute(self, pid, **kwargs)
    345         try:
    346             wps_response = self._wps.execute(
--> 347                 pid, inputs=wps_inputs, output=wps_outputs, mode=mode
    348             )
    349 

/opt/conda/envs/birdy/lib/python3.7/site-packages/owslib/wps.py in execute(self, identifier, inputs, output, mode, lineage, request, response)
    357         # submit the request to the live server
    358         if response is None:
--> 359             response = execution.submitRequest(request)
    360         else:
    361             response = etree.fromstring(response)

/opt/conda/envs/birdy/lib/python3.7/site-packages/owslib/wps.py in submitRequest(self, request)
    910         reader = WPSExecuteReader(verbose=self.verbose, timeout=self.timeout, auth=self.auth)
    911         response = reader.readFromUrl(
--> 912             self.url, request, method='Post', headers=self.headers)
    913         self.response = response
    914         return response

/opt/conda/envs/birdy/lib/python3.7/site-packages/owslib/wps.py in readFromUrl(self, url, data, method, username, password, headers, verify, cert)
    601 
    602         return self._readFromUrl(url, data, self.timeout, method, username=username, password=password,
--> 603                                  headers=headers, verify=verify, cert=cert)
    604 
    605 

/opt/conda/envs/birdy/lib/python3.7/site-packages/owslib/wps.py in _readFromUrl(self, url, data, timeout, method, username, password, headers, verify, cert)
    513             u = openURL(url, data, method='Post',
    514                         username=self.auth.username, password=self.auth.password,
--> 515                         headers=headers, verify=self.auth.verify, cert=self.auth.cert, timeout=timeout)
    516             return etree.fromstring(u.read())
    517 

/opt/conda/envs/birdy/lib/python3.7/site-packages/owslib/util.py in openURL(url_base, data, method, cookies, username, password, timeout, headers, verify, cert, auth)
    209 
    210     if req.status_code in [400, 401]:
--> 211         raise ServiceException(req.text)
    212 
    213     if req.status_code in [404, 500, 502, 503, 504]:    # add more if needed

ServiceException: <?xml version="1.0" encoding="utf-8"?>
<ExceptionReport version="1.0.0"
    xmlns="http://www.opengis.net/ows/1.1"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://www.opengis.net/ows/1.1 http://schemas.opengis.net/ows/1.1.0/owsExceptionReport.xsd">
    <Exception exceptionCode="NoApplicableCode" locator="NotAcceptable">
        <ExceptionText>Request failed: (&#x27;Connection aborted.&#x27;, RemoteDisconnected(&#x27;Remote end closed connection without response&#x27;))</ExceptionText>
    </Exception>
</ExceptionReport>

[aulemahal]

Ok après des tests reliés, ma conclusion est la suivante: l'attente est normale parce que les dataset dont on parle ici sont très grands. Le problème réside dans le fait que le "timeout" par défaut de gunicorn, ce qui "sert" finch, est de 30s.

La vraie solution c'est de passer par async, mais ce travail est encore en cours. J'explores présentement d'autres solutions partielles pour accélérer finch là où je peux.

Entre-temps on pourrait augmenter le timeout à 1 min...

@tlvu @huard

[cjauvin]

Je pense qu'on ne devrait tout simplement pas avoir des tests automatisés qui demandent de jouer avec un timeout parce qu'on est pas certain du temps que prendra la requête.

…

On Thu, Jun 3, 2021 at 4:59 PM Pascal Bourgault ***@***.***> wrote: Ok après des tests reliés, ma conclusion est la suivante: l'attente est normale parce que les dataset dont on parle ici sont très grands. Le problème réside dans le fait que le "timeout" par défaut de gunicorn, ce qui "sert" finch, est de 30s. La *vraie* solution c'est de passer par async, mais ce travail est encore en cours. J'explores présentement d'autres solutions partielles pour accélérer finch là où je peux. Entre-temps on pourrait augmenter le timeout à 1 min... @tlvu <https://github.com/tlvu> @huard <https://github.com/huard> — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#391 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AADXMIHFLHTHPMJ2UM55AFLTQ7UMNANCNFSM45IFXJMQ> .

[richardarsenault]

@cjauvin D'accord pour les tests, mais ce problème survient en déploiement/prod.

[aulemahal]

@huard @tlvu

Pris sur la doc de "gunicorn" (https://docs.gunicorn.org/en/latest/design.html#choosing-a-worker-type)

Some examples of behavior requiring asynchronous workers:

    * Applications making long blocking calls (Ie, external web services)
    * Serving requests directly to the internet
    * Streaming requests and responses
    * Long polling
    * Web sockets
    * Comet

Il me semble qu'on est dans le premier, non?

En tout cas, avec une timeout de 0 (infini), ça fonctionne : le subset de ERA5 prends 2m15s, donc ~2mn dans subset_shape donc sans aucun feedback dans le log. J'ai aussi essayé d'utiliser le worker "gthread", même chose, ça fonctionne parce que le "timeout" est compté si le worker est "idle" seulement (AFAIU). Là ça m'a pris 2m53s.

À noter que de faire ça directement dans PAVICS prends 36s. @richardarsenault si jamais ça peut être une alternative d'ici un fix:

import xarray as xr
from clisops.core import subset

ds = xr.open_dataset("https://pavics.ouranos.ca/twitcher/ows/proxy/thredds/dodsC/datasets/reanalyses/era5.ncml")
sub = subset.subset_shape(ds, 'input.geojson')

[huard]

Oui, bien joué !

Je suis étonné de la différence de performance entre finch et un call direct à clisops. Dans ma tête ça devrait être presque identique.

[aulemahal]

Je me rends compte qu'il y a une différence majeure ici : finch va systématiquement charger les données en dask.. Mon example ici ne le fait pas. On est dans un cas (sans calcul) où dask est un boulet.

[richardarsenault]

Salut,

Le workaround marche parfaitement en utilisant clisops.core.subset! Je me demande donc quel avantage on a à utiliser Finch par rapport à ce package qui ne nécessite pas l'appel à un serveur? J'imagine qu'il doit y en avoir mais je ne connais pas assez la mécanique derrière ni les avantages.

Merci!

[aulemahal]

En effet, finch est dédié à un genre de traitement quand même spécifique! Le but c'est de pouvoir fournir les services lorsque la machine "client" n'a PAS les ressources qu'il faut. Genre même pas python et tout. Exemple : les données personalisées qu'on peut télécharger sur climatedata.ca (donc n'importe qui depuis son navigateur web peut faire des appels finch). Si on travaille sur PAVICS ou autre, y a jamais vraiment de besoins pour finch!

Je ferme cette issue, la discussion technique peut continuer ici : bird-house/finch#190.

[richardarsenault]

OK super, merci pour l'info, ça a plein de bon sens!