Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

during health check ups "status": "not ready" #1677

Closed
1 task done
Boom199801 opened this issue Feb 4, 2024 · 4 comments
Closed
1 task done

during health check ups "status": "not ready" #1677

Boom199801 opened this issue Feb 4, 2024 · 4 comments
Labels
api bug Erroneous behavior of the backend

Comments

@Boom199801
Copy link

Boom199801 commented Feb 4, 2024

Is there an existing issue for this?

  • I have searched the existing issues

Where did you encounter this issue?

live API

Request URL

http://localhost:8080/ors/v2/health

POST Request Body

{
  "status": "not ready"
}

Response

Response
PASTE HERE

Current behavior

docker compose up -d
[+] Running 1/1
 ⠿ Container ors-app  Started                                                                                                                                                                                                   1.6s
[root@bigdata-gpu01 docker]# docker logs -f ors-app
Running container as user root with id 0
ORS Path: /home/ors
Catalina Path: /home/ors/tomcat
### openrouteservice configuration ###
Copy ors-config.yml

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.1.6)

04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.Application                      ]   Starting Application v8.0-SNAPSHOT using Java 17.0.7 with PID 1 (/home/ors/tomcat/webapps/ors/WEB-INF/classes started by root in /home/ors)
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.Application                      ]   The following 1 profile is active: "default"
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   Configuration file set by environment variable.
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   Loaded file 'ors-conf/ors-config.yml'
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   Environment variables overriding openrouteservice configuration parameters detected: 
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   ORS_CONFIG_LOCATION=ors-conf/ors-config.yml
04 Feb 04:48:20 INFO                                                  main [ o.h.o.a.ORSEnvironmentPostProcessor      ]   
log4j:WARN No appenders could be found for logger (io.micrometer.common.util.internal.logging.InternalLoggerFactory).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
04 Feb 04:48:24 INFO                                                  main [ o.h.o.a.Application                      ]   Started Application in 4.304 seconds (process running for 10.995)

Expected behavior

during health check ups "status": "not ready"

The steps used are:

git clone https://github.com/GIScience/openrouteservice.git
cd openrouteservice
export LATEST_ORS_RELEASE=$(git describe --tags --abbrev=0); 
git checkout $LATEST_ORS_RELEASE
docker compose up -d

docker-compose:

version: '2.4'
services:
  ors-app:
    container_name: ors-app
    ports:
      - "31223:8080"
      - "31224:9001"
    image: openrouteservice/openrouteservice:nightly
    user: "${UID:-0}:${GID:-0}"
#    build:
#      context: ../
#      args:
#        ORS_CONFIG: ./openrouteservice/src/main/resources/ors-config-sample.json
#        OSM_FILE: ./openrouteservice/src/main/files/heidelberg.osm.gz
    volumes:
      - ./graphs:/home/ors/ors-core/data/graphs
      - ./elevation_cache:/home/ors/ors-core/data/elevation_cache
      - ./logs/ors:/home/ors/ors-core/logs/ors
      - ./logs/tomcat:/home/ors/tomcat/logs
      - ./conf:/home/ors/ors-conf
      - /nfs4/nfs/dazhao_model/wjg/china-latest.osm.pbf:/home/ors/ors-core/data/osm_file.pbf
    environment:
      - BUILD_GRAPHS=False  # 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 -Xms1g -Xmx2g"
      - "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"

Openrouteservice Version

nightly

Build date

No response

Graph date

No response

Forum Topic Link

No response

@Boom199801 Boom199801 added api bug Erroneous behavior of the backend labels Feb 4, 2024
@Boom199801
Copy link
Author

192.168.10.15 - - [04/Feb/2024:04:51:00 +0000] "GET /ors/v2/health HTTP/1.1" 503 42
192.168.10.15 - - [04/Feb/2024:04:52:28 +0000] "GET /ors/v2/health HTTP/1.1" 503 42
192.168.10.15 - - [04/Feb/2024:05:04:13 +0000] "GET /ors/v2/health HTTP/1.1" 503 42
192.168.10.15 - - [04/Feb/2024:05:04:15 +0000] "GET /ors/v2/health HTTP/1.1" 503 42
192.168.10.15 - - [04/Feb/2024:05:04:17 +0000] "GET /ors/v2/health HTTP/1.1" 503 42
192.168.10.15 - - [04/Feb/2024:05:04:18 +0000] "GET /ors/v2/health HTTP/1.1" 503 42

@Boom199801
Copy link
Author

docker logs -f ors-app
Running container as user root with id 0
ORS Path: /home/ors
Catalina Path: /home/ors/tomcat

openrouteservice configuration

Extract war file to /home/ors/tomcat/webapps/ors
No ors-config.json in ors-conf folder. Copying original config from /home/ors/ors-core/ors-config.json
Deploy ors with config from /home/ors/ors-conf/ors-config.json
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
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
04-Feb-2024 05:16:39.365 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
04-Feb-2024 05:16:45.922 INFO [main] 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.
04 Feb 05:16:47 INFO [config.AppConfig] - Default path of 'ors-config.json' used for configuration
04 Feb 05:16:47 INFO [config.AppConfig] - Loading configuration from /home/ors/tomcat/webapps/ors/WEB-INF/classes/ors-config.json

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

04 Feb 05:16:48 INFO [ors.Application] - Starting Application v7.1.1 using Java 17.0.7 on 06717c55a79a with PID 1 (/home/ors/tomcat/webapps/ors/WEB-INF/classes started by root in /home/ors)
04 Feb 05:16:48 DEBUG [ors.Application] - Running with Spring Boot v2.7.12, Spring v5.3.27
04 Feb 05:16:48 INFO [ors.Application] - No active profile set, falling back to 1 default profile: "default"
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:51 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 DEBUG [Validator] - ERROR [ModelSpecification.spec] At least one type of specification is required
04 Feb 05:16:52 INFO [ors.Application] - Started Application in 5.793 seconds (JVM running for 13.945)
04 Feb 05:16:52 INFO [logging.LoggingUtility] - Logging configuration loaded from DEBUG_LOGGING.json, logging to file /home/ors/ors-core/logs/ors/ors-logs.log
04 Feb 05:16:52 INFO [routing.RoutingProfileManager] - Total - 5 GB, Free - 4.55 GB, Max: 10 GB, Used - 461.19 MB
04 Feb 05:16:52 INFO [routing.RoutingProfileManager] -
04 Feb 05:16:52 INFO [routing.RoutingProfileManager] - ====> Initializing profiles from '/home/ors/ors-core/data/osm_file.pbf' (1 threads) ...
04 Feb 05:16:52 INFO [routing.RoutingProfileManager] - 1 tasks submitted.
04 Feb 05:16:52 INFO [routing.RoutingProfile] - [1] Profiles: 'driving-car', location: '/home/ors/ors-core/data/graphs/car'.
04-Feb-2024 05:16:52.852 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
04 Feb 05:16:52 INFO [core.CoreLMPreparationHandler] - Loaded landmark splitting collection from
04 Feb 05:16:53 INFO [extensions.ORSGraphHopper] - version v4.8.1|2023-09-05T08:03:54Z (7,20,5,4,5,7)
04 Feb 05:16:53 INFO [extensions.ORSGraphHopper] - graph CH|car_ors|RAM_STORE|3D|turn_cost|,,,,, details:edges:0(0MB), nodes:0(0MB), name:(0MB), geo:0(0MB), bounds:1.7976931348623157E308,-1.7976931348623157E308,1.7976931348623157E308,-1.7976931348623157E308,1.7976931348623157E308,-1.7976931348623157E308, shortcuts:0 (0MB), nodesCH:-1 (0MB), shortcuts:0 (0MB), nodesCH:-1 (0MB), shortcuts:0 (0MB), nodesCH:-1 (0MB)
04 Feb 05:16:53 INFO [extensions.ORSGraphHopper] - No custom areas are used, custom_areas.directory not given
04 Feb 05:16:53 INFO [extensions.ORSGraphHopper] - start creating graph from /home/ors/ors-core/data/osm_file.pbf
04 Feb 05:16:53 INFO [extensions.ORSGraphHopper] - using CH|car_ors|RAM_STORE|3D|turn_cost|,,,,, memory:totalMB:5120, usedMB:609

Will the error here have any impact

@sfendrich
Copy link
Contributor

sfendrich commented Feb 15, 2024

From the log output it seems you haven't configured any profile:

04 Feb 05:16:48 INFO [ors.Application] - No active profile set, falling back to 1 default profile: "default"

Still it seems to build a graph for the car profile. However, at the point where your log-file ends the graph is not yet finished building and ORS not fully started.

@MichaelsJP
Copy link
Member

MichaelsJP commented Mar 1, 2024

@wangjiegui Thanks for reporting. It's as @sfendrich mentioned. The endpoint is returning 200 once the graphs are built and ors is ready. Until then, it reports whatever spring-boot allows us to report. Until a certain point it's 503, it could also be something else, depending on the internal tomcat startup phase.
Not much we can do.

My advice here, make sure you define the profiles and rely on 200 as the indicator for ors is started, graphs are built and one can start querying.

Closing the issue.
@wangjiegui Feel free to head over to our forum for further questions: ask.openrouteservice.org/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
api bug Erroneous behavior of the backend
Projects
No open projects
Status: Awaiting release
Development

No branches or pull requests

3 participants