Docker-entrypoint.sh 89 killed when using large, merged .pbf-File

openrouteservice
1

Hello, sorry to bother but i’m stuck with setting up docker for a few days now.
So my goal is to host ORS on my local machine with some OSM.PBF-Files I merged myself.

Here are the steps I have taken so far:

  1. clone the git repo

  2. move to docker directory in CMD and execute “docker-compose up” without doing any changes.

  3. Merge my .pbf Files with osmconvert with the following commands:
    "osmconvert <germany-latest.osm.pbf> -o=<germany.o5m> "
    “osmconvert <france.osm.pbf> -o=<france.o5m>”
    “osmconvert <germany.o5m> <france.o5m> -o=D_FR.osm.pbf”
    Basically I merged 2 files from geofabrik which resulted in a filesize of 6.9GB (GER,FR) and then moved it to .data/D_FR.osm.pbf

  4. I adapted my docker-compose.yml file like this:

    version: ‘2.4’
    services:
    ors-app:
    container_name: ors-app
    ports:

    • 8080:8080
    • 9001:9001
      image: openrouteservice/openrouteservice:latest
      build:
      context: …/ (note that filesystem and inline-editor only show 2 dots, so must be something with the preformatter here)
      args:
      APP_CONFIG: ./openrouteservice/docker/conf/app.config
      OSM_FILE: ./openrouteservice/docker/data/D_FR.osm.pbf
      volumes:
    • ./graphs:/ors-core/data/graphs
    • ./elevation_cache:/ors-core/data/elevation_cache
    • ./logs/ors:/var/log/ors
    • ./logs/tomcat:/usr/local/tomcat/logs
    • ./conf:/ors-conf
    • ./data/D_FR.osm.pbf:/ors-core/data/osm_file.pbf
      environment:
    • BUILD_GRAPHS=True # Forces the container to rebuild the graphs, e.g. when PBF is changed
    • “JAVA_OPTS=-Djava.awt.headless=true -server -XX:TargetSurvivorRatio=75 -XX:SurvivorRatio=64 -XX:MaxTenuringThreshold=3 -XX:+UseG1GC -XX:+ScavengeBeforeFullGC -XX:ParallelGCThreads=4 -Xms14g -Xmx14g”
    • “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”

  5. I didn’t change my app.config file, so it’s the same as in git repo.

  6. Then i ran docker-compose up which gives me the following logs:

ors.log:

2020-08-10 13:46:06,470 INFO [ors.Application] - Starting Application v6.2.0 on c5ae09721f11 with PID 8 (/usr/local/tomcat/webapps/ors/WEB-INF/classes started by root in /ors-core)
2020-08-10 13:46:06,473 DEBUG [ors.Application] - Running with Spring Boot v2.0.4.RELEASE, Spring v5.0.8.RELEASE
2020-08-10 13:46:06,480 INFO [ors.Application] - No active profile set, falling back to default profiles: default
2020-08-10 13:46:09,485 INFO [ors.Application] - Started Application in 4.06 seconds (JVM running for 8.639)
2020-08-10 13:46:09,617 INFO [routing.RoutingProfileManager] -  Total - 14 GB, Free - 13.43 GB, Max: 14 GB, Used - 586.81 MB
2020-08-10 13:46:09,619 INFO [routing.RoutingProfileManager] -       
2020-08-10 13:46:09,652 INFO [routing.RoutingProfileManager] - ====> Initializing profiles from 'data/osm_file.pbf' (1 threads) ...
2020-08-10 13:46:09,656 INFO [routing.RoutingProfileManager] -                               
2020-08-10 13:46:09,662 INFO [routing.RoutingProfileManager] -                
2020-08-10 13:46:09,713 INFO [routing.RoutingProfile] - [1] Profiles: 'driving-car', location: 'data/graphs/car'.

catalina.log

10-Aug-2020 13:55:59.052 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.39
10-Aug-2020 13:55:59.059 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Mar 14 2019 11:24:26 UTC
10-Aug-2020 13:55:59.059 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.39.0
10-Aug-2020 13:55:59.060 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
10-Aug-2020 13:55:59.061 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.19.76-linuxkit
10-Aug-2020 13:55:59.062 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
10-Aug-2020 13:55:59.063 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/local/openjdk-11
10-Aug-2020 13:55:59.063 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.8+10
10-Aug-2020 13:55:59.064 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
10-Aug-2020 13:55:59.064 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
10-Aug-2020 13:55:59.065 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
10-Aug-2020 13:55:59.066 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
10-Aug-2020 13:55:59.067 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
10-Aug-2020 13:55:59.069 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
10-Aug-2020 13:55:59.072 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
10-Aug-2020 13:55:59.074 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
10-Aug-2020 13:55:59.075 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.awt.headless=true
10-Aug-2020 13:55:59.079 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:TargetSurvivorRatio=75
10-Aug-2020 13:55:59.082 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:SurvivorRatio=64
10-Aug-2020 13:55:59.083 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:MaxTenuringThreshold=3
10-Aug-2020 13:55:59.084 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+UseG1GC
10-Aug-2020 13:55:59.086 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:+ScavengeBeforeFullGC
10-Aug-2020 13:55:59.087 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -XX:ParallelGCThreads=4
10-Aug-2020 13:55:59.088 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms14g
10-Aug-2020 13:55:59.089 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx14g
10-Aug-2020 13:55:59.090 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
10-Aug-2020 13:55:59.091 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
10-Aug-2020 13:55:59.091 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
10-Aug-2020 13:55:59.092 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote
10-Aug-2020 13:55:59.093 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.port=9001
10-Aug-2020 13:55:59.094 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.rmi.port=9001
10-Aug-2020 13:55:59.095 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.authenticate=false
10-Aug-2020 13:55:59.098 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcom.sun.management.jmxremote.ssl=false
10-Aug-2020 13:55:59.100 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.rmi.server.hostname=localhost
10-Aug-2020 13:55:59.100 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
10-Aug-2020 13:55:59.101 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
10-Aug-2020 13:55:59.102 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
10-Aug-2020 13:55:59.103 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
10-Aug-2020 13:55:59.104 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib]
10-Aug-2020 13:55:59.159 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
10-Aug-2020 13:55:59.172 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
10-Aug-2020 13:55:59.186 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
10-Aug-2020 13:55:59.188 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
10-Aug-2020 13:55:59.190 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 525 ms
10-Aug-2020 13:55:59.240 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
10-Aug-2020 13:55:59.240 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.39
10-Aug-2020 13:55:59.286 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/usr/local/tomcat/webapps/ors.war]
10-Aug-2020 13:56:06.683 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.
10-Aug-2020 13:56:06.788 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/ors.war] has finished in [7,500] ms
10-Aug-2020 13:56:06.794 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/examples]
10-Aug-2020 13:56:07.107 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/examples] has finished in [313] ms
10-Aug-2020 13:56:07.114 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/host-manager]
10-Aug-2020 13:56:07.170 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/host-manager] has finished in [55] ms
10-Aug-2020 13:56:07.170 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
10-Aug-2020 13:56:07.187 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [17] ms
10-Aug-2020 13:56:07.189 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/docs]
10-Aug-2020 13:56:07.228 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/docs] has finished in [39] ms
10-Aug-2020 13:56:07.228 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/manager]
10-Aug-2020 13:56:07.280 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/manager] has finished in [52] ms
10-Aug-2020 13:56:07.296 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
10-Aug-2020 13:56:07.356 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
10-Aug-2020 13:56:07.398 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 8207 ms

and finally in docker-desktop itself:

ors-app | 10 Aug 13:46:06 INFO [ors.Application] - Starting Application v6.2.0 on c5ae09721f11 with PID 8 (/usr/local/tomcat/webapps/ors/WEB-INF/classes started by root in /ors-core)
ors-app | 10 Aug 13:46:06 DEBUG [ors.Application] - Running with Spring Boot v2.0.4.RELEASE, Spring v5.0.8.RELEASE
ors-app | 10 Aug 13:46:06 INFO [ors.Application] - No active profile set, falling back to default profiles: default
ors-app | SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
ors-app | SLF4J: Defaulting to no-operation (NOP) logger implementation
ors-app | SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
ors-app | 10 Aug 13:46:09 INFO [ors.Application] - Started Application in 4.06 seconds (JVM running for 8.639)
ors-app | 10-Aug-2020 13:46:09.559 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.
ors-app | <?xml version="1.0" ?>
ors-app | <Configuration>
ors-app | <Properties>
ors-app | <Property name="filename">/var/log/ors/ors-logs.log</Property>
ors-app | </Properties>
ors-app | </Configuration>
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfileManager] - Total - 14 GB, Free - 13.43 GB, Max: 14 GB, Used - 586.81 MB
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfileManager] -
ors-app | 10-Aug-2020 13:46:09.654 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployWAR Deployment of web application archive [/usr/local/tomcat/webapps/ors.war] has finished in [7,317] ms
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfileManager] - ====> Initializing profiles from 'data/osm_file.pbf' (1 threads) ...
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfileManager] -
ors-app | 10-Aug-2020 13:46:09.657 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/examples]
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfileManager] -
ors-app | 10 Aug 13:46:09 INFO [routing.RoutingProfile] - [1] Profiles: 'driving-car', location: 'data/graphs/car'.
ors-app | 10-Aug-2020 13:46:09.923 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/examples] has finished in [266] ms
ors-app | 10-Aug-2020 13:46:09.923 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/host-manager]
ors-app | 10-Aug-2020 13:46:09.972 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/host-manager] has finished in [49] ms
ors-app | 10-Aug-2020 13:46:09.972 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
ors-app | 10-Aug-2020 13:46:10.001 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [29] ms
ors-app | 10-Aug-2020 13:46:10.001 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/docs]
ors-app | 10-Aug-2020 13:46:10.023 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/docs] has finished in [21] ms
ors-app | 10-Aug-2020 13:46:10.024 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/manager]
ors-app | 10-Aug-2020 13:46:10.060 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/manager] has finished in [37] ms
ors-app | 10-Aug-2020 13:46:10.073 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
ors-app | 10-Aug-2020 13:46:10.102 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
ors-app | 10-Aug-2020 13:46:10.120 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 7916 ms
ors-app | /docker-entrypoint.sh: line 32: 8 Killed /usr/local/tomcat/bin/catalina.sh run
ors-app exited with code 0

Additional infos:
After running the command above nothing happens anymore of course. I didn’t change my docker-entrypoint.sh -File (which is in root folder of git repo). I get a folder in ./docker/graphs called “car” with a file containing “gh.lock”. I can also exclude network problems. Couldn’t find anything regarding this topic in this forum so I hope you could help me. Please just tell me if you need any more info.

Just checked with the exact same setup with the map of liechtenstein, works like a charm. May there be something wrong with my merging or can the filesize be a problem?

BR

2

Hi @peznan,

I’m not sure what could be causing the issue as there are no explicit errors given by openrouteservice, which suggests that it is some other issue. The file size shouldn’t be a problem as you have set the RAM as you have set the limits in the JAVA_OPTS line correctly.

A couple of things you could try is to delete the graphs folder on the host and change the BUILD_GRAPHS value to be false - this would tell it only to rebuild the graphs if there is nothing present in the graphs folder… This would help if it was a file permission issue

The other one as you said Leichenstein was ok would be to try using osmosis for the merging as I have used that in the past without problems. Once installed, the command for that would be osmosis --rb germany.osm.pbf --rb france.osm.pbf --merge --wb D_FR.osm.pbf… That would help if the osmconvert tool is making things strange.

The other question that might help is how long it takes before it exits? Is it straight away or after some time?

3

Hi @adam !

I just tried

docker-compose up

with graphs deleted and rebuild option set to false with the germany.osm.pbf file straight from Geofabrik. Then im stuck for a pretty long time (~2min) at this part after docker-compose down:

C:\ORS\openrouteservice\docker>docker-compose up
Creating network "docker_default" with the default driver
Creating ors-app ... done                                                                                                                                                                                                                    Attaching to ors-app
ors-app    | ### Package openrouteservice and deploy to Tomcat ###
ors-app    | WARNING: An illegal reflective access operation has occurred
ors-app    | WARNING: Illegal reflective access by com.google.inject.internal.cglib.core.$ReflectUtils$1 (file:/usr/share/maven/lib/guice.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
ors-app    | WARNING: Please consider reporting this to the maintainers of com.google.inject.internal.cglib.core.$ReflectUtils$1
ors-app    | WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
ors-app    | WARNING: All illegal access operations will be denied in a future release

Then later on at said part:

ors-app    | 11-Aug-2020 07:43:10.596 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 10050 ms
ors-app    | /docker-entrypoint.sh: line 32:    88 Killed                  /usr/local/tomcat/bin/catalina.sh run
ors-app exited with code 0

This takes about 1-2 seconds from the server startup-statement until it exits!
Thanks for your help, I’ll try with osmosis again.

4

The 2 minute wait is normally because of building openrouteservice itself within the container so that is nothing to be concerned about. The fact that it exits straight away though without any error message indicates that it is either something to do with tomcat/java itself on the container, or something extremely early in the build process.

Can you double check that your machine has 14GB of free ram available (not total RAM but RAM that is not being used by any other process)? Also, docker itself will take some of the free RAM when it fires up the container as well. Normally an error from the jdk should show that up though.

Also, can you run docker logs ors-app to see if there is any extra information there as to why it crashed?