Error [6099] in Matrix-Calculation with HGV-Profile

Hello everyone,

I’m back with another issue trying to calculate matrices using the HGV-Profile. The starting point is the same as mentioned here (Win10-System, WSL2, Docker Desktop):

  1. Download and extract ORS-Github-Repo, clean folder and create reguired folders
  2. Adapt pbf to use Germany-2018 (“ARG OSM_FILE=./germany-180101.osm.pbf”)
  3. Change Dockerfile to keep profiles “car” and “hgv” (“del(.ors.services.routing.profiles.active[2,3,4,5,6,7,8])”)
  4. Build image and run

docker build -t ors-test .

docker run -dt -u "${UID}:${GID}" --name ors-hgv -p 8080:8080 -v $PWD/graphs:/ors-core/data/graphs -v $PWD/elevation_cache:/ors-core/data/elevation_cache -v $PWD/conf:/ors-conf -e "JAVA_OPTS=-Djava.awt.headless=true -server -XX:TargetSurvivorRatio=75 -XX:SurvivorRatio=64 -XX:MaxTenuringThreshold=3 -XX:+UseG1GC -XX:+ScavengeBeforeFullGC -XX:ParallelGCThreads=4 -Xms4g -Xmx10g" -e "CATALINA_OPTS=-Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9001 -Dcom.sun.management.jmxremote.rmi.port=9001 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=localhost" ors-test

Docker starts up without issues or warnings and seems to work fine. Now, to give you an overview of my problem:

  1. I have a bunch of points in Saarland, which is part of the pbf.
  2. I can calculate routes between any of these points using the HGV-profile and get a time and distance.
  3. I can calculate a matrix between these points using the car-profile and get times and distances.
    [4. I can fire a matrix request with these points against the online-ORS-API using the HGV-profile and get times and distances.]

If I send a matrix request with these points using the HGV-profile against my own setup, I get an “Error : Openrouteservice API request failed. [6099] Unable to compute a distance/duration matrix.” This even remains when I limit the request to one origin and one destination, meaning my ORS-setup calculates a route between points A and B when requested via the routing-API, but not when requested via the matrix-API. On the other hand, the matrix-API seems to work fine when using the car-profile, but not when using the HGV-profile. I’ve tried a variety of settings in the profiles and the matrix-configuration of the ors-config.json to no avail; the problem persists even after blankly copying the car-profile into the hgv-profile (i.e., they have same settings).

Any help as to what’s going on here and how to solve it would be appreciated!
Best regards

Hey,

First, what might be helpful is the log of the docker container for the failing request.

Second, could you provide the requests from 1 through 4, maybe in a stripped-down version only containing three or four locations exposing the problem?

What version of the ors are you using when stating “download and extract ORS-Github-Repo”?
Does this problem persist with this saarland osm.pbf - it’s way smaller than the whole of germany and thus builds way quicker :slight_smile:

Best regards

Hey,
thanks for your fast answer!

  1. Please let me know where to find this! The log-folder remains empty, and docker container logs shows the same output as Docker Desktop, i.e. the Startup, which runs fine. A quick hint what to look at (or what to activate) would be great.

  2. Here are the four requests based on just two points:

Request 1: Route from A to B, HGV-Profile (No Issue)
curl -X POST \
  'http://localhost:8080/ors/v2/directions/driving-hgv' \
  -H 'Content-Type: application/json; charset=utf-8' \
  -H 'Accept: application/json, application/geo+json, application/gpx+xml, img/png; charset=utf-8' \
  -d '{"coordinates":[[6.710510,49.25539],[6.755597,49.32754]]}'
Request 2: Matrix between A and B, Car-Profile (No Issue)
curl -X POST \
  'http://localhost:8080/ors/v2/matrix/driving-car' \
  -H 'Content-Type: application/json; charset=utf-8' \
  -H 'Accept: application/json, application/geo+json, application/gpx+xml, img/png; charset=utf-8' \
  -d '{"locations":[[6.71051,49.25539],[6.755597,49.32754]]}'
Request 3: Matrix between A and B, HGV-Profile (Problem)
curl -X POST \
  'http://localhost:8080/ors/v2/matrix/driving-hgv' \
  -H 'Content-Type: application/json; charset=utf-8' \
  -H 'Accept: application/json, application/geo+json, application/gpx+xml, img/png; charset=utf-8' \
  -d '{"locations":[[6.71051,49.25539],[6.755597,49.32754]]}'
Request 4: One-to-One Matrix from A to B, HGV-Profile (Still a Problem, even though should be identical to Request 1)
curl -X POST \
  'http://localhost:8080/ors/v2/matrix/driving-hgv' \
  -H 'Content-Type: application/json; charset=utf-8' \
  -H 'Accept: application/json, application/geo+json, application/gpx+xml, img/png; charset=utf-8' \
  -d '{"locations":[[6.71051,49.25539],[6.755597,49.32754]],"sources":[0],"destinations":[1]}'
Request 5: Matrix between A and B, HGV-Profile, against ORS-Online-API (No Issue)
curl -X POST \
  'https://api.openrouteservice.org/v2/matrix/driving-hgv' \
  -H 'Content-Type: application/json; charset=utf-8' \
  -H 'Accept: application/json, application/geo+json, application/gpx+xml, img/png; charset=utf-8' \
  -H 'Authorization: %%KEY%%' \
  -d '{"locations":[[6.71051,49.25539],[6.755597,49.32754]]}'
  1. That’s the current content of the Repo (i.e., as of last Thursday).

  2. There is no issue using the Saarland-data, everything works as expected. That’s where this issue reminded me a bit of my last one, where also everything worked well with the Saarland, but not with the German data. I completely agree that this behavior makes it annoying to deal with, as it takes quite a while every time one recalculates the graphs…

Best regards

Hey,

thanks for your info!
Regarding 1., something like docker logs -f ors-hgv should work.
If that doesn’t give enough output, have a look at the logs/ folder you created or docker exec -it ors-hgv bash into your container and tail -f /var/log/ors/ors.log or something along those lines.

Best regard

Thanks for the instructions! The logs/ folder stays empty, and the logs reported are identical using docker logs an docker exec -it bash. This is the total log I get from either one, but it doesn’t include anything related to individual requests:

Log
### openrouteservice configuration ###
No ors-config.json in ors-conf folder. Copy config from /ors-core/openrouteservice/src/main/resources/ors-config.json
### Package openrouteservice and deploy to Tomcat ###
Using CATALINA_BASE:   /usr/local/tomcat
Using CATALINA_HOME:   /usr/local/tomcat
Using CATALINA_TMPDIR: /usr/local/tomcat/temp
Using JRE_HOME:        /usr/local/openjdk-11
Using CLASSPATH:       /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar
Using CATALINA_OPTS:   -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=9001 -Dcom.sun.management.jmxremote.rmi.port=9001 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.rmi.server.hostname=localhost
NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
30-Jun-2022 13:38:41.820 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/8.5.69
30-Jun-2022 13:38:41.821 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Jun 30 2021 18:00:00 UTC
30-Jun-2022 13:38:41.821 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 8.5.69.0
30-Jun-2022 13:38:41.821 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.10.102.1-microsoft-standard-WSL2
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/local/openjdk-11
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.15+10
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
30-Jun-2022 13:38:41.822 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
30-Jun-2022 13:38:41.824 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
30-Jun-2022 13:38:41.824 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
30-Jun-2022 13:38:41.824 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
30-Jun-2022 13:38:41.825 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
30-Jun-2022 13:38:41.825 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
30-Jun-2022 13:38:41.825 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
30-Jun-2022 13:38:41.825 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:TargetSurvivorRatio=75
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:SurvivorRatio=64
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:MaxTenuringThreshold=3
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseG1GC
30-Jun-2022 13:38:41.826 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+ScavengeBeforeFullGC
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:ParallelGCThreads=4
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms4g
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx10g
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
30-Jun-2022 13:38:41.827 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
30-Jun-2022 13:38:41.828 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote
30-Jun-2022 13:38:41.828 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.port=9001
30-Jun-2022 13:38:41.828 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.rmi.port=9001
30-Jun-2022 13:38:41.828 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
30-Jun-2022 13:38:41.828 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.ssl=false
30-Jun-2022 13:38:41.829 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.rmi.server.hostname=localhost
30-Jun-2022 13:38:41.829 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
30-Jun-2022 13:38:41.829 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
30-Jun-2022 13:38:41.829 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
30-Jun-2022 13:38:41.829 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
30-Jun-2022 13:38:41.830 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib]
30-Jun-2022 13:38:41.864 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
30-Jun-2022 13:38:41.874 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
30-Jun-2022 13:38:41.886 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 4145 ms
30-Jun-2022 13:38:41.934 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
30-Jun-2022 13:38:41.934 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/8.5.69]
30-Jun-2022 13:38:41.962 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/local/tomcat/webapps/ors.war]
30-Jun-2022 13:38:59.460 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
13:39:02.224 [localhost-startStop-1] INFO  org.heigit.ors.config.AppConfig - Default path of 'ors-config.json' used for configuration
13:39:02.336 [localhost-startStop-1] INFO  org.heigit.ors.config.AppConfig - Loading configuration from /usr/local/tomcat/webapps/ors/WEB-INF/classes/ors-config.json

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.5.RELEASE)

30 Jun 13:39:07 INFO [ors.Application] - Starting Application v6.7.0 on f8a1613d2e5f with PID 139 (/usr/local/tomcat/webapps/ors/WEB-INF/classes started by root in /ors-core)
30 Jun 13:39:07 DEBUG [ors.Application] - Running with Spring Boot v2.3.5.RELEASE, Spring v5.2.10.RELEASE
30 Jun 13:39:07 INFO [ors.Application] - No active profile set, falling back to default profiles: default
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
30 Jun 13:39:19 INFO [ors.Application] - Started Application in 18.618 seconds (JVM running for 41.278)
<?xml version="1.0" ?><Configuration><Properties><Property name="filename">/var/log/ors/ors-logs.log</Property></Properties></Configuration>30 Jun 13:39:19 INFO [routing.RoutingProfileManager] -  Total - 4.00 GB, Free - 3.85 GB, Max: 10 GB, Used - 161.98 MB
30 Jun 13:39:19 INFO [routing.RoutingProfileManager] -       
30 Jun 13:39:19 INFO [routing.RoutingProfileManager] - ====> Initializing profiles from 'data/osm_file.pbf' (1 threads) ...
30 Jun 13:39:19 INFO [routing.RoutingProfileManager] -                               
30 Jun 13:39:19 INFO [routing.RoutingProfileManager] -                
30-Jun-2022 13:39:19.619 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/ors.war] has finished in [37,657] ms
30-Jun-2022 13:39:19.621 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/manager]
30 Jun 13:39:19 INFO [routing.RoutingProfile] - [1] Profiles: 'driving-car', location: 'data/graphs/car'.
30-Jun-2022 13:39:20.319 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/manager] has finished in [698] ms
30-Jun-2022 13:39:20.319 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/examples]
30-Jun-2022 13:39:20.433 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/examples] has finished in [114] ms
30-Jun-2022 13:39:20.434 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/docs]
30-Jun-2022 13:39:20.444 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/docs] has finished in [11] ms
30-Jun-2022 13:39:20.444 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
30-Jun-2022 13:39:20.459 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [15] ms
30-Jun-2022 13:39:20.459 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/host-manager]
30-Jun-2022 13:39:20.473 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/host-manager] has finished in [14] ms
30-Jun-2022 13:39:20.481 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
30-Jun-2022 13:39:20.492 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 37677 ms
30 Jun 13:40:25 INFO [routing.RoutingProfile] - [1] FlagEncoders: 1, bits used [UNKNOWN]/64.
30 Jun 13:40:25 INFO [routing.RoutingProfile] - [1] Capacity: [UNKNOWN]. (edges - 11258298, nodes - 8890966)
30 Jun 13:40:25 INFO [routing.RoutingProfile] - [1] Total time: 65.428s.
30 Jun 13:40:25 INFO [routing.RoutingProfile] - [1] Finished at: 2022-06-30 13:40:25.
30 Jun 13:40:25 INFO [routing.RoutingProfile] -                               
30 Jun 13:40:25 INFO [routing.RoutingProfile] - [2] Profiles: 'driving-hgv', location: 'data/graphs/hgv'.
30 Jun 13:41:05 INFO [routing.RoutingProfile] - [2] FlagEncoders: 1, bits used [UNKNOWN]/64.
30 Jun 13:41:05 INFO [routing.RoutingProfile] - [2] Capacity: [UNKNOWN]. (edges - 9759447, nodes - 7756140)
30 Jun 13:41:05 INFO [routing.RoutingProfile] - [2] Total time: 40.207s.
30 Jun 13:41:05 INFO [routing.RoutingProfile] - [2] Finished at: 2022-06-30 13:41:05.
30 Jun 13:41:05 INFO [routing.RoutingProfile] -                               
30 Jun 13:41:05 INFO [routing.RoutingProfileManager] - Total time: 105.709s.
30 Jun 13:41:05 INFO [routing.RoutingProfileManager] - ========================================================================
30 Jun 13:41:05 INFO [routing.RoutingProfileManager] - ====> Recycling garbage...
30 Jun 13:41:05 INFO [routing.RoutingProfileManager] - Before:  Total - 9.82 GB, Free - 8.26 MB, Max: 10 GB, Used - 9.81 GB
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - After:  Total - 10 GB, Free - 262.30 MB, Max: 10 GB, Used - 9.74 GB
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - ========================================================================
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - ====> Memory usage by profiles:
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - [1] 2.11 GB (21.7%)
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - [2] 1.73 GB (17.7%)
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - Total: 3.84 GB (39.4%)
30 Jun 13:41:10 INFO [routing.RoutingProfileManager] - ========================================================================
30 Jun 13:47:05 INFO [util.SystemMessage] - SystemMessage loaded 0 messages.

And just for information, these are the Logging settings in the standard config:

Settings
    "logging": {
      "enabled": true,
      "level_file": "DEBUG_LOGGING.json",
      "location": "/var/log/ors",
      "stdout": true

Is there a way to access this “DEBUG_LOGGING.json” mentioned here, and would that help?

Best regards

Hey,

I can reproduce the issue, but am also at a loss as to why this might happen.
I’ll link this in an issue - I can imagine that this is only a configuration issue, but it might as well be a bug in the code.

Best regards,

1 Like

Thanks for the info! Good to know that at least it’s not (only) my system and I’m not at a complete loss.

1 Like

@jschnell, as the issue has been open for three weeks now with no further progress: Is there any way to get things moving or any way I can further contribute? It would be good to at least have the feeling that someone will have a look at the issue eventually… :slight_smile: