Every hour ORS is shutting down. This is the same in docker or maven.
Three seconds after the hour, every hour the service is shut down. I cannot see what is shutting it down, but it is obviously something on an hourly poll. I saw somewhere that log rotation might cause this. Any help gratefully received.
11 Oct 16:00:03 INFO SpringApplicationShutdownHook [ o.h.o.a.s.l.ORSInitContextListener ] Shutting down ORS and releasing resources.
More info. In docker, below is the exit code 143. I could just set Docker to automatically restart, but the service is not available during the reload period and I want to solve what is causing it to exit every hour.
State
Dead false
Error
ExitCode 143
FinishedAt 2023-10-11T17:00:03.859331463Z
OOMKilled false
Paused false
Pid 0
Restarting false
Running false
StartedAt 2023-10-11T16:54:10.645157361Z
Status exited
Hi @aggsmart and thanks for reporting. Please add some more information on what image/ors version you use, your config file and if possible the osm base data.
Please remember to remove personal content from your config file.
It is the latest version and the standard settings. Something is causing ors to shut down on the hour every hour. I have other dicker containers working fine which do not shut down. I have tried 3 different ors configs running together and they all get shut down on the hour. I am running on CentOS with docker. Logs below:
ors-config.json
{
"ors": {
"info": {
"base_url": "https://openrouteservice.org/",
"swagger_documentation_url": "https://api.openrouteservice.org/",
"support_mail": "support@openrouteservice.org",
"author_tag": "openrouteservice",
"content_licence": "LGPL 3.0"
},
"api_settings": {
"cors": {
"allowed": {
"origins": [
"*"
],
"headers": [
"Content-Type",
"X-Requested-With",
"accept",
"Origin",
"Access-Control-Request-Method",
"Access-Control-Request-Headers",
"Authorization"
]
},
"exposed": {
"headers": [
"Access-Control-Allow-Origin",
"Access-Control-Allow-Credentials"
]
},
"preflight_max_age": 600
}
},
"services": {
"matrix": {
"enabled": true,
"maximum_routes": 100,
"maximum_routes_flexible": 25,
"maximum_search_radius": 5000,
"maximum_visited_nodes": 100000,
"allow_resolve_locations": true,
"attribution": "openrouteservice.org, OpenStreetMap contributors"
},
"isochrones": {
"enabled": true,
"maximum_range_distance": [
{
"profiles": "any",
"value": 50000
},
{
"profiles": "driving-car, driving-hgv",
"value": 100000
}
],
"maximum_range_time": [
{
"profiles": "any",
"value": 18000
},
{
"profiles": "driving-car, driving-hgv",
"value": 3600
}
],
"fastisochrones": {
"maximum_range_distance": [
{
"profiles": "any",
"value": 50000
},
{
"profiles": "driving-car, driving-hgv",
"value": 500000
}
],
"maximum_range_time": [
{
"profiles": "any",
"value": 18000
},
{
"profiles": "driving-car, driving-hgv",
"value": 10800
}
],
"profiles": {
"default_params": {
"enabled": false,
"threads": 12,
"weightings": "recommended",
"maxcellnodes": 5000
},
"hgv": {
"enabled": false,
"threads": 12,
"weightings": "recommended, shortest",
"maxcellnodes": 5000
}
}
},
"maximum_intervals": 10,
"maximum_locations": 2,
"allow_compute_area": true
},
"routing": {
"enabled": true,
"mode": "normal",
"routing_description": "This is a routing file from openrouteservice",
"routing_name": "openrouteservice routing",
"sources": [
"/home/ors/ors-core/data/osm_file.pbf"
],
"init_threads": 1,
"attribution": "openrouteservice.org, OpenStreetMap contributors",
"elevation_preprocessed": false,
"profiles": {
"active": [
"car"
],
"default_params": {
"encoder_flags_size": 8,
"graphs_root_path": "/home/ors/ors-core/data/graphs",
"elevation_provider": "multi",
"elevation_cache_path": "/home/ors/ors-core/data/elevation_cache",
"elevation_cache_clear": false,
"instructions": true,
"maximum_distance": 100000,
"maximum_distance_dynamic_weights": 100000,
"maximum_distance_avoid_areas": 100000,
"maximum_waypoints": 50,
"maximum_snapping_radius": 400,
"maximum_avoid_polygon_area": 200000000,
"maximum_avoid_polygon_extent": 20000,
"maximum_distance_alternative_routes": 100000,
"maximum_alternative_routes": 3,
"maximum_distance_round_trip_routes": 100000,
"maximum_speed_lower_bound": 80,
"preparation": {
"min_network_size": 200,
"min_one_way_network_size": 200,
"methods": {
"lm": {
"enabled": true,
"threads": 1,
"weightings": "recommended,shortest",
"landmarks": 16
}
}
},
"execution": {
"methods": {
"lm": {
"disabling_allowed": true,
"active_landmarks": 8
}
}
}
},
"profile-car": {
"profiles": "driving-car",
"parameters": {
"encoder_flags_size": 8,
"encoder_options": "turn_costs=true|block_fords=false|use_acceleration=true",
"maximum_distance": 100000,
"elevation": true,
"maximum_snapping_radius": 350,
"preparation": {
"min_network_size": 200,
"min_one_way_network_size": 200,
"methods": {
"ch": {
"enabled": true,
"threads": 1,
"weightings": "fastest"
},
"lm": {
"enabled": false,
"threads": 1,
"weightings": "fastest,shortest",
"landmarks": 16
},
"core": {
"enabled": true,
"threads": 1,
"weightings": "fastest,shortest",
"landmarks": 64,
"lmsets": "highways;allow_all"
}
}
},
"execution": {
"methods": {
"ch": {
"disabling_allowed": true
},
"lm": {
"disabling_allowed": true,
"active_landmarks": 6
},
"core": {
"disabling_allowed": true,
"active_landmarks": 6
}
}
},
"ext_storages": {
"WayCategory": {},
"HeavyVehicle": {},
"WaySurfaceType": {},
"RoadAccessRestrictions": {
"use_for_warnings": true
}
}
}
},
"profile-hgv": {
"profiles": "driving-hgv",
"parameters": {
"encoder_flags_size": 8,
"encoder_options": "turn_costs=true|block_fords=false|use_acceleration=true",
"maximum_distance": 100000,
"elevation": true,
"preparation": {
"min_network_size": 200,
"min_one_way_network_size": 200,
"methods": {
"ch": {
"enabled": true,
"threads": 1,
"weightings": "recommended"
},
"core": {
"enabled": true,
"threads": 1,
"weightings": "recommended,shortest",
"landmarks": 64,
"lmsets": "highways;allow_all"
}
}
},
"execution": {
"methods": {
"ch": {
"disabling_allowed": true
},
"core": {
"disabling_allowed": true,
"active_landmarks": 6
}
}
},
"ext_storages": {
"WayCategory": {},
"HeavyVehicle": {
"restrictions": true
},
"WaySurfaceType": {}
}
}
},
"profile-bike-regular": {
"profiles": "cycling-regular",
"parameters": {
"encoder_options": "consider_elevation=true|turn_costs=true|block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-bike-mountain": {
"profiles": "cycling-mountain",
"parameters": {
"encoder_options": "consider_elevation=true|turn_costs=true|block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-bike-road": {
"profiles": "cycling-road",
"parameters": {
"encoder_options": "consider_elevation=true|turn_costs=true|block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-bike-electric": {
"profiles": "cycling-electric",
"parameters": {
"encoder_options": "consider_elevation=true|turn_costs=true|block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-walking": {
"profiles": "foot-walking",
"parameters": {
"encoder_options": "block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-hiking": {
"profiles": "foot-hiking",
"parameters": {
"encoder_options": "block_fords=false",
"elevation": true,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"HillIndex": {},
"TrailDifficulty": {}
}
}
},
"profile-wheelchair": {
"profiles": "wheelchair",
"parameters": {
"encoder_options": "block_fords=true",
"elevation": true,
"maximum_snapping_radius": 50,
"ext_storages": {
"WayCategory": {},
"WaySurfaceType": {},
"Wheelchair": {
"KerbsOnCrossings": "true"
},
"OsmId": {}
}
}
},
"profile-public-transport": {
"profiles": "public-transport",
"parameters": {
"encoder_options": "block_fords=false",
"elevation": true,
"maximum_visited_nodes": 1000000,
"gtfs_file": "openrouteservice-api-tests/data/vrn_gtfs.zip"
}
}
}
}
},
"logging": {
"enabled": true,
"level_file": "DEBUG_LOGGING.json",
"location": "/home/ors/ors-core/logs/ors",
"stdout": true
},
"system_message": [
{
"active": false,
"text": "This message would be sent with every routing bike fastest request",
"condition": {
"request_service": "routing",
"request_profile": "cycling-regular,cycling-mountain,cycling-road,cycling-electric",
"request_preference": "fastest"
}
},
{
"active": false,
"text": "This message would be sent with every request for geojson response",
"condition": {
"api_format": "geojson"
}
},
{
"active": false,
"text": "This message would be sent with every request on API v1 from January 2020 until June 2050",
"condition": {
"api_version": 1,
"time_after": "2020-01-01T00:00:00Z",
"time_before": "2050-06-01T00:00:00Z"
}
},
{
"active": false,
"text": "This message would be sent with every request"
}
]
}
}
ORS LOG
2023-11-02 16:27:07,341 INFO [core.CoreLandmarkStorage] - Created core node ID map for car_ors_fastest_with_turn_costs_allow_all of size 1446
2023-11-02 16:27:07,343 INFO [core.CoreLandmarkStorage] - Created core node ID map for car_ors_shortest_with_turn_costs_highways of size 1446
2023-11-02 16:27:07,344 INFO [core.CoreLandmarkStorage] - Created core node ID map for car_ors_shortest_with_turn_costs_allow_all of size 1446
2023-11-02 16:27:07,348 INFO [core.CoreLMPreparationHandler] - 1/4 calling LM prepare.doWork for limited_access|fastest|car_ors ... (totalMB:4096, usedMB:1239)
2023-11-02 16:27:07,466 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_highways] Made 0 edges inaccessible. Calculated country cut in 0.09878795s, totalMB:4096, usedMB:1279
2023-11-02 16:27:07,494 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_highways] Calculated 177 subnetworks via tarjan in 0.026953215s, totalMB:4096, usedMB:1281
2023-11-02 16:27:07,585 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_highways] init landmarks for subnetworks with node count greater than 723 with factor:0.07607902526367187, maxWeight:4985.91499968 from quick estimation
2023-11-02 16:27:07,594 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_highways] start node: 18 (49.371167,8.6367578) subnetwork 1264, subnetwork size: 1265, totalMB:4096, usedMB:1299 area:[com.graphhopper.routing.lm.SplitArea@36e22507]
2023-11-02 16:27:08,793 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_highways] Finished landmark creation. Subnetwork node count sum 1446 vs. nodes 1446
2023-11-02 16:27:08,801 INFO [core.CoreLMPreparationHandler] - LM car_ors_fastest_with_turn_costs_highways finished totalMB:4096, usedMB:1697
2023-11-02 16:27:08,801 INFO [core.CoreLMPreparationHandler] - 2/4 calling LM prepare.doWork for limited_access|fastest|car_ors ... (totalMB:4096, usedMB:1697)
2023-11-02 16:27:08,934 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_allow_all] Made 0 edges inaccessible. Calculated country cut in 0.12606737s, totalMB:4096, usedMB:1735
2023-11-02 16:27:08,946 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_allow_all] Calculated 121 subnetworks via tarjan in 0.011325505s, totalMB:4096, usedMB:1735
2023-11-02 16:27:09,016 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_allow_all] init landmarks for subnetworks with node count greater than 723 with factor:0.07607902526367187, maxWeight:4985.91499968 from quick estimation
2023-11-02 16:27:09,017 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_allow_all] start node: 4 (49.4115105,8.6349536) subnetwork 1320, subnetwork size: 1321, totalMB:4096, usedMB:1753 area:[com.graphhopper.routing.lm.SplitArea@36e22507]
2023-11-02 16:27:09,525 INFO [core.CoreLandmarkStorage] - [car_ors_fastest_with_turn_costs_allow_all] Finished landmark creation. Subnetwork node count sum 1446 vs. nodes 1446
2023-11-02 16:27:09,529 INFO [core.CoreLMPreparationHandler] - LM car_ors_fastest_with_turn_costs_allow_all finished totalMB:4096, usedMB:408
2023-11-02 16:27:09,530 INFO [core.CoreLMPreparationHandler] - 3/4 calling LM prepare.doWork for limited_access|shortest|car_ors ... (totalMB:4096, usedMB:410)
2023-11-02 16:27:09,580 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_highways] Made 0 edges inaccessible. Calculated country cut in 0.047523946s, totalMB:4096, usedMB:448
2023-11-02 16:27:09,585 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_highways] Calculated 177 subnetworks via tarjan in 0.004786845s, totalMB:4096, usedMB:448
2023-11-02 16:27:09,611 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_highways] init landmarks for subnetworks with node count greater than 723 with factor:0.9843695551757811, maxWeight:64511.64316799999 from quick estimation
2023-11-02 16:27:09,611 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_highways] start node: 18 (49.371167,8.6367578) subnetwork 1264, subnetwork size: 1265, totalMB:4096, usedMB:468 area:[com.graphhopper.routing.lm.SplitArea@36e22507]
2023-11-02 16:27:09,996 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_highways] Finished landmark creation. Subnetwork node count sum 1446 vs. nodes 1446
2023-11-02 16:27:10,000 INFO [core.CoreLMPreparationHandler] - LM car_ors_shortest_with_turn_costs_highways finished totalMB:4096, usedMB:938
2023-11-02 16:27:10,001 INFO [core.CoreLMPreparationHandler] - 4/4 calling LM prepare.doWork for limited_access|shortest|car_ors ... (totalMB:4096, usedMB:938)
2023-11-02 16:27:10,044 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_allow_all] Made 0 edges inaccessible. Calculated country cut in 0.03850526s, totalMB:4096, usedMB:974
2023-11-02 16:27:10,049 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_allow_all] Calculated 121 subnetworks via tarjan in 0.00426874s, totalMB:4096, usedMB:976
2023-11-02 16:27:10,075 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_allow_all] init landmarks for subnetworks with node count greater than 723 with factor:0.9924305251464844, maxWeight:65039.926896000004 from quick estimation
2023-11-02 16:27:10,078 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_allow_all] start node: 4 (49.4115105,8.6349536) subnetwork 1320, subnetwork size: 1321, totalMB:4096, usedMB:996 area:[com.graphhopper.routing.lm.SplitArea@36e22507]
2023-11-02 16:27:10,656 INFO [core.CoreLandmarkStorage] - [car_ors_shortest_with_turn_costs_allow_all] Finished landmark creation. Subnetwork node count sum 1446 vs. nodes 1446
2023-11-02 16:27:10,661 INFO [core.CoreLMPreparationHandler] - LM car_ors_shortest_with_turn_costs_allow_all finished totalMB:4096, usedMB:1464
2023-11-02 16:27:10,661 INFO [core.CoreLMPreparationHandler] - Finished LM preparation, totalMB:4096, usedMB:1464
2023-11-02 16:27:10,662 INFO [extensions.ORSGraphHopper] - flushing graph CH|car_ors|RAM_STORE|3D|turn_cost|7,20,5,4,5, details:edges:20 826(1MB), nodes:17 464(1MB), name:(1MB), geo:137 647(1MB), bounds:7.7084693,9.1039669,49.3325699,49.5168325,89.0,582.0, shortcuts:12 512 (1MB), nodesCH:17 464 (1MB), shortcuts:16 216 (1MB), nodesCH:17 464 (1MB), shortcuts:17 191 (1MB), nodesCH:17 464 (1MB), totalMB:4096, usedMB:1464)
2023-11-02 16:27:10,724 INFO [extensions.ORSGraphHopper] - flushed graph totalMB:4096, usedMB:1472)
2023-11-02 16:27:10,725 INFO [routing.RoutingProfile] - [1] Edges: 20826 - Nodes: 17464.
2023-11-02 16:27:10,726 INFO [routing.RoutingProfile] - [1] Total time: 61.283s.
2023-11-02 16:27:10,726 INFO [routing.RoutingProfile] - [1] Finished at: 2023-11-02 16:27:10.
2023-11-02 16:27:10,753 INFO [routing.RoutingProfileManager] - Total time: 61.375s.
2023-11-02 16:27:10,754 INFO [routing.RoutingProfileManager] - ========================================================================
2023-11-02 16:27:10,754 INFO [routing.RoutingProfileManager] - ====> Recycling garbage...
2023-11-02 16:27:10,754 INFO [routing.RoutingProfileManager] - Before: Total - 4 GB, Free - 2.56 GB, Max: 8 GB, Used - 1.44 GB
2023-11-02 16:27:10,863 INFO [routing.RoutingProfileManager] - After: Total - 4 GB, Free - 3.93 GB, Max: 8 GB, Used - 68.39 MB
2023-11-02 16:27:10,863 INFO [routing.RoutingProfileManager] - ========================================================================
2023-11-02 16:27:10,863 INFO [routing.RoutingProfileManager] - ====> Memory usage by profiles:
2023-11-02 16:27:10,865 INFO [routing.RoutingProfileManager] - [1] 23.04 MB (33.7%)
2023-11-02 16:27:10,865 INFO [routing.RoutingProfileManager] - Total: 23.04 MB (33.7%)
2023-11-02 16:27:10,865 INFO [routing.RoutingProfileManager] - ========================================================================
2023-11-02 17:00:02,685 INFO [listeners.ORSInitContextListener] - Shutting down ORS and releasing resources.
CATALINA LOG
02-Nov-2023 17:00:02.476 INFO [Thread-4] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]
02-Nov-2023 17:00:02.747 INFO [Thread-4] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8080"]
02-Nov-2023 17:00:02.764 INFO [Thread-4] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["http-nio-8080"]
LOCALHOST LOG
02-Nov-2023 16:25:59.992 INFO [main] org.apache.catalina.core.ApplicationContext.log 2 Spring WebApplicationInitializers detected on classpath
02-Nov-2023 16:26:06.764 INFO [main] org.apache.catalina.core.ApplicationContext.log Initializing Spring embedded WebApplicationContext
02-Nov-2023 16:26:09.625 INFO [main] org.apache.catalina.core.ApplicationContext.log ContextListener: contextInitialized()
02-Nov-2023 16:26:09.625 INFO [main] org.apache.catalina.core.ApplicationContext.log SessionListener: contextInitialized()
02-Nov-2023 16:26:09.627 INFO [main] org.apache.catalina.core.ApplicationContext.log ContextListener: attributeAdded('StockTicker', 'async.Stockticker@38b114c1')
02-Nov-2023 16:26:09.783 INFO [http-nio-8080-exec-1] org.apache.catalina.core.ApplicationContext.log Initializing Spring DispatcherServlet 'dispatcherServlet'
02-Nov-2023 17:00:02.532 INFO [Thread-4] org.apache.catalina.core.ApplicationContext.log SessionListener: contextDestroyed()
02-Nov-2023 17:00:02.532 INFO [Thread-4] org.apache.catalina.core.ApplicationContext.log ContextListener: contextDestroyed()
02-Nov-2023 17:00:02.549 INFO [Thread-4] org.apache.catalina.core.ApplicationContext.log Destroying Spring FrameworkServlet 'dispatcherServlet'
02-Nov-2023 17:00:02.550 INFO [Thread-4] org.apache.catalina.core.ApplicationContext.log Closing Spring root WebApplicationContext
It seems to be ORSInitContextListener which is shutting down the container every hour. But why?
Hi @aggsmart,
are you using a specific image, or building it from source?
Could you provide your docker-compose.yml as well?
Or the way you started ORS?
Best regards
I have used docker-compose with the “latest” and “nightly”. Both shut down on the hour.
The latest test was the standard “stock” install below without any customisation.
I also have it built from source and running directly on Tomcat without Docker and it runs fine and does not shut down. But, ideally I want to manage multiple instances via docker.
I have done some research that says that port 8005 is the Tomcat shutdown port, so a cronjob may be running on the hour which calls this. But, as far as I am aware, the docker containers only have the ports open which are specified.
# For example for the latest release
git clone https://github.com/GIScience/openrouteservice.git
cd openrouteservice
# Checkout latest version
export LATEST_ORS_RELEASE=$(git describe --tags --abbrev=0);
git checkout $LATEST_ORS_RELEASE
# If the docker folder exists cd into it
cd docker || echo "No docker folder found. Continue with next step."
# Now change the version the docker-compose.yml uses
sed -i='' "s/openrouteservice\/openrouteservice:nightly/openrouteservice\/openrouteservice:$LATEST_ORS_RELEASE/g" docker-compose.yml
sed -i='' "s/openrouteservice\/openrouteservice:latest/openrouteservice\/openrouteservice:$LATEST_ORS_RELEASE/g" docker-compose.yml
# Run docker compose with
docker compose up -d