search

Open-EO / openeo-opensearch-client

Simple opensearch client for openeo.
Apache License 2.0
0 stars 0 forks source link

include error details for failed catalog requests #34

Closed bossie closed 2 months ago

bossie commented 8 months ago

A CDSE catalog request failed but the ERROR message nor its stack trace contain any details with regards to the root cause, making analysis unnecessarily difficult:

OpenEO batch job failed: java.io.IOException: Exception while evaluating catalog request https://catalogue.dataspace.copernicus.eu/resto/api/collections/Sentinel2/search.json?box=4.511304606053353%2C3.617657965285189E-4%2C4.511394442071769%2C4.5220726449395955E-4&sortParam=startDate&sortOrder=ascending&page=1&maxRecords=100&status=ONLINE&dataset=ESA-DATASET&productType=L2A&startDate=2018-06-06T00%3A00%3A00Z&completionDate=2020-10-22T00%3A00%3A00Z: 

Traceback (most recent call last):
  File "/opt/openeo/lib64/python3.8/site-packages/openeogeotrellis/deploy/batch_job.py", line 1347, in <module>
    main(sys.argv)
  File "/opt/openeo/lib64/python3.8/site-packages/openeogeotrellis/deploy/batch_job.py", line 1014, in main
    run_driver()
  File "/opt/openeo/lib64/python3.8/site-packages/openeogeotrellis/deploy/batch_job.py", line 985, in run_driver
    run_job(
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/utils.py", line 56, in memory_logging_wrapper
    return function(*args, **kwargs)
  File "/opt/openeo/lib64/python3.8/site-packages/openeogeotrellis/deploy/batch_job.py", line 1078, in run_job
    result = ProcessGraphDeserializer.evaluate(process_graph, env=env, do_dry_run=tracer)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 377, in evaluate
    result = convert_node(result_node, env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 402, in convert_node
    process_result = apply_process(process_id=process_id, args=processGraph.get('arguments', {}),
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in apply_process
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in <dictcomp>
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 416, in convert_node
    return convert_node(processGraph['node'], env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 402, in convert_node
    process_result = apply_process(process_id=process_id, args=processGraph.get('arguments', {}),
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in apply_process
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in <dictcomp>
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 416, in convert_node
    return convert_node(processGraph['node'], env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 402, in convert_node
    process_result = apply_process(process_id=process_id, args=processGraph.get('arguments', {}),
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in apply_process
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1570, in <dictcomp>
    args = {name: convert_node(expr, env=env) for (name, expr) in sorted(args.items())}
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 416, in convert_node
    return convert_node(processGraph['node'], env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 402, in convert_node
    process_result = apply_process(process_id=process_id, args=processGraph.get('arguments', {}),
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 1602, in apply_process
    return process_function(args=ProcessArgs(args, process_id=process_id), env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo_driver/ProcessGraphDeserializer.py", line 585, in load_collection
    return env.backend_implementation.catalog.load_collection(collection_id, load_params=load_params, env=env)
  File "/opt/openeo/lib/python3.8/site-packages/openeo/util.py", line 361, in wrapper
    return f(*args, **kwargs)
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/layercatalog.py", line 138, in load_collection
    return self._load_collection_cached(collection_id, load_params, WhiteListEvalEnv(env,WHITELIST))
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/layercatalog.py", line 635, in _load_collection_cached
    pyramid = file_s2_pyramid()
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/layercatalog.py", line 341, in file_s2_pyramid
    return file_pyramid(pyramid_factory)
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/layercatalog.py", line 397, in file_pyramid
    return create_pyramid(factory)
  File "/opt/openeo/lib/python3.8/site-packages/openeogeotrellis/layercatalog.py", line 361, in create_pyramid
    return factory.datacube_seq(
  File "/usr/local/spark/python/lib/py4j-0.10.9.7-src.zip/py4j/java_gateway.py", line 1322, in __call__
    return_value = get_return_value(
  File "/usr/local/spark/python/lib/py4j-0.10.9.7-src.zip/py4j/protocol.py", line 326, in get_return_value
    raise Py4JJavaError(
py4j.protocol.Py4JJavaError: An error occurred while calling o1700.datacube_seq.
: java.io.IOException: Exception while evaluating catalog request https://catalogue.dataspace.copernicus.eu/resto/api/collections/Sentinel2/search.json?box=4.511304606053353%2C3.617657965285189E-4%2C4.511394442071769%2C4.5220726449395955E-4&sortParam=startDate&sortOrder=ascending&page=1&maxRecords=100&status=ONLINE&dataset=ESA-DATASET&productType=L2A&startDate=2018-06-06T00%3A00%3A00Z&completionDate=2020-10-22T00%3A00%3A00Z:  
    at org.openeo.opensearch.OpenSearchClient.$anonfun$execute$1(OpenSearchClient.scala:146)
    at org.openeo.opensearch.package$.attempt$1(package.scala:46)
    at org.openeo.opensearch.package$.withRetries(package.scala:58)
    at org.openeo.opensearch.OpenSearchClient.execute(OpenSearchClient.scala:134)
    at org.openeo.opensearch.backends.CreodiasClient.getProductsFromPage(CreodiasClient.scala:124)
    at org.openeo.opensearch.backends.CreodiasClient.from$1(CreodiasClient.scala:52)
    at org.openeo.opensearch.backends.CreodiasClient.getProducts(CreodiasClient.scala:56)
    at org.openeo.opensearch.OpenSearchClient.getProducts(OpenSearchClient.scala:96)
    at org.openeo.geotrellis.layers.FileLayerProvider.loadRasterSourceRDD(FileLayerProvider.scala:1293)
    at org.openeo.geotrellis.layers.FileLayerProvider.readKeysToRasterSources(FileLayerProvider.scala:754)
    at org.openeo.geotrellis.layers.FileLayerProvider.readMultibandTileLayer(FileLayerProvider.scala:957)
    at org.openeo.geotrellis.file.PyramidFactory.datacube(PyramidFactory.scala:134)
    at org.openeo.geotrellis.file.PyramidFactory.datacube_seq(PyramidFactory.scala:91)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at py4j.reflection.MethodInvoker.invoke(MethodInvoker.java:244)
    at py4j.reflection.ReflectionEngine.invoke(ReflectionEngine.java:374)
    at py4j.Gateway.invoke(Gateway.java:282)
    at py4j.commands.AbstractCommand.invokeMethod(AbstractCommand.java:132)
    at py4j.commands.CallCommand.execute(CallCommand.java:79)
    at py4j.ClientServerConnection.waitForCommands(ClientServerConnection.java:182)
    at py4j.ClientServerConnection.run(ClientServerConnection.java:106)
    at java.base/java.lang.Thread.run(Thread.java:829)

There is an INFO log earlier that at least tells us that it's a 504 error:

https://catalogue.dataspace.copernicus.eu/resto/api/collections/Sentinel2/search.json?box=4.511304606053353%2C3.617657965285189E-4%2C4.511394442071769%2C4.5220726449395955E-4&sortParam=startDate&sortOrder=ascending&page=1&maxRecords=100&status=ONLINE&dataset=ESA-DATASET&productType=L2A&startDate=2018-06-06T00%3A00%3A00Z&completionDate=2020-10-22T00%3A00%3A00Z returned 504

The response to that request was actually this:

{
  "detail": {
    "ErrorMessage": "The request took too long to process. Please add a filter for Collection and startDate.",
    "ErrorCode": 504
  }
}
bossie commented 8 months ago

For reference, and for reproducing purposes, the process graph in question:

{
  "process_graph": {
    "loadcollection1": {
      "process_id": "load_collection",
      "arguments": {
        "bands": [
          "B02"
        ],
        "id": "SENTINEL2_L2A",
        "spatial_extent": null,
        "temporal_extent": null
      }
    },
    "filterbbox1": {
      "process_id": "filter_bbox",
      "arguments": {
        "data": {
          "from_node": "loadcollection1"
        },
        "extent": {
          "west": 11.279182434082033,
          "east": 11.406898498535158,
          "north": 46.522729291844286,
          "south": 46.464349400461145,
          "crs": 32632
        }
      }
    },
    "filtertemporal1": {
      "process_id": "filter_temporal",
      "arguments": {
        "data": {
          "from_node": "filterbbox1"
        },
        "extent": [
          "2018-06-06",
          "2020-10-22"
        ]
      }
    },
    "saveresult1": {
      "process_id": "save_result",
      "arguments": {
        "data": {
          "from_node": "filtertemporal1"
        },
        "format": "GTiff",
        "options": {}
      },
      "result": true
    }
  }
}
jdries commented 3 months ago

committed something for the relevant error handler, which was not looking for 'ErrorMessage'.

jdries commented 2 months ago

Fix should be live, but hard to reproduce because we also have now a solution in place that avoids this error.