Hasura graphql-engine server does not start properly on local environment after version 2.17.1

[maria-nemeti]

Hi all,
We are using hasura in production and currently the cloud version is at [v2.25.1-cloud.1], but we didn’t manage to keep up to date with our local development environment where we did get stuck to version 2.17.1 (hasura/graphql-engine:v2.17.1.cli-migrations-v3). The reason is that any newer version just cannot start properly even if we did not change anything in our docker compose yaml file:

version: '3.8'
services:
  postgres:
    image: safenow/hasura-alarmdata-db:latest
    environment:
      POSTGRES_PASSWORD: postgrespassword
    networks:
      - alarmdata2
    ports:
      - "5432:5432"
  graphql-engine:
    image: safenow/hasura-alarmdata-with-migrations:latest
    ports:
      - "7070:7070"
    restart: always
    depends_on:
      - postgres
    environment:
      HASURA_GRAPHQL_UNAUTHORIZED_ROLE: "anonymous"
      HASURA_GRAPHQL_SERVER_PORT: 7070
      HASURA_GRAPHQL_DATABASE_URL: postgres://postgres:postgrespassword@postgres:5432/postgres
      PG_DATABASE_URL: postgres://postgres:postgrespassword@postgres:5432/postgres
      HASURA_GRAPHQL_ENABLE_CONSOLE: "true" # set to "true" to enable console, but be aware that then the migrations/metadata are not written to disc
      HASURA_GRAPHQL_ENABLED_LOG_TYPES: startup,http-log,webhook-log,websocket-log,query-log,livequery-poller-log,action-handler-log,data-connector-log # all allowed log-types
      HASURA_GRAPHQL_LOG_LEVEL: "debug"
      HASURA_GRAPHQL_JWT_SECRET: '{"type":"HS256","key":"Secret"}'
      HASURA_GRAPHQL_ADMIN_SECRET: "sss"
      WAIT_BEFORE_START_ENDPOINT: "postgres:5432"
      HASURA_GRAPHQL_INFER_FUNCTION_PERMISSIONS: "false"
      HASURA_GRAPHQL_DEV_MODE: "true"
    networks:
      - alarmdata2
    extra_hosts:
      - "host.docker.internal:host-gateway"

In the logs didn't find anything suspicious, the last thing logged is an invocation of the cron trigger, so it looks like will start, but then it just stops..

Any idea how to fix this?
Thanks in advance,
Maria

{"detail":{"info":"gracefully shutting down server","kind":"server"},"level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"startup"}
{"detail":"Shutting websockets server down","level":"debug","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":"Stopping immortal update JWK thread","level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":"Stopping immortal runTelemetry thread","level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":"Stopping immortal websocket connection reaper thread thread","level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":"Stopping immortal sourcePingPoller thread","level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":"Stopping immortal checkForUpdates thread","level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"unstructured"}
{"detail":{"info":"All in-flight events have finished processing","kind":"scheduled_events"},"level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"startup"}
{"detail":{"info":{"database_url":"postgres://postgres:...@postgres:5432/postgres","retries":1},"kind":"postgres_connection"},"level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":"Already at the latest catalog version (48); nothing to do.","kind":"catalog_migrate"},"level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":"Schema sync enabled. Polling at Refined (Milliseconds {milliseconds = 1s})","kind":"schema-sync"},"level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":{"instance_id":"adb44e24-87d9-4c37-837d-4e57a049bc00","message":"listener thread started","thread_id":"ThreadId 28"},"kind":"schema-sync"},"level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":"EE client credentials not present in the metadata database. Hasura EE features are disabled.","kind":"license_info"},"level":"warn","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":"Successfully resolved source","kind":"resolve_source"},"level":"debug","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":{"info":{"message":"source \"default\" is already at the latest catalog version (3).","source":"default"},"kind":"source_catalog_migrate"},"level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"startup"}
{"detail":"Thread ourIdleGC (re)started","level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"unstructured"}
{"detail":"Thread SchemeUpdate.listener (re)started","level":"info","timestamp":"2023-05-25T19:43:23.624+0000","type":"unstructured"}
{"detail":"Stopping immortal processScheduledTriggers thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":{"num_cron_events_fetched":2,"num_fetches":1,"num_one_off_scheduled_events_fetched":0},"level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"scheduled-trigger-process"}
{"detail":"Stopping immortal runCronEventsGenerator thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":"Stopping immortal asyncActionSubscriptionsProcessor thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":{"info":"All in-flight events have finished processing","kind":"async_actions"},"level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"startup"}
{"detail":"Stopping immortal asyncActionsProcessor thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":{"info":"All in-flight events have finished processing","kind":"event_triggers"},"level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"startup"}
{"detail":"Stopping immortal processEventQueue thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":"Stopping immortal SchemeUpdate.processor thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":"Stopping immortal SchemeUpdate.listener thread","level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"unstructured"}
{"detail":{"cron_triggers":[],"num_fetches":1},"level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"cron-event-generator-process"}
{"detail":{"num_events_fetched":{},"num_fetches":11},"level":"info","timestamp":"2023-05-25T19:43:25.525+0000","type":"event-trigger-process"}
{"detail":"The following environment variables are deprecated and moved to metadata: HASURA_GRAPHQL_NO_OF_RETRIES","level":"warn","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":{"info":{"instance_id":"adb44e24-87d9-4c37-837d-4e57a049bc00","message":"processor thread started","thread_id":"ThreadId 93"},"kind":"schema-sync"},"level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"startup"}
{"detail":{"info":"starting workers","kind":"event_triggers"},"level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"startup"}
{"detail":"Thread asyncActionSubscriptionsProcessor (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread processScheduledTriggers (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread update JWK (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread runCronEventsGenerator (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread checkForUpdates (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread SchemeUpdate.processor (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread processEventQueue (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":{"info":"preparing data","kind":"scheduled_triggers"},"level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"startup"}
{"detail":"Thread sourcePingPoller (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":{"info":"Help us improve Hasura! The graphql-engine server collects anonymized usage stats which allows us to keep improving Hasura at warp speed. To read more or opt-out, visit https://hasura.io/docs/latest/graphql/core/guides/telemetry.html","kind":"telemetry"},"level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"startup"}
{"detail":{"info":{"message":"starting API server","time_taken":2.2845795},"kind":"server"},"level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"startup"}
{"detail":"Thread asyncActionsProcessor (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread websocket connection reaper thread (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":"Thread runTelemetry (re)started","level":"info","timestamp":"2023-05-25T19:43:25.856+0000","type":"unstructured"}
{"detail":{"event_id":"5bc4e154-06ed-45c9-bc33-885ddf14a0be","event_name":"ResetOutdatedLocations","request":{"original_request":{"body":"{\"comment\":\"This endpoint executes bulk update operation which sets all locations to latitude=null, longitude=null for all person_locations with old phonestatuses\",\"id\":\"5bc4e154-06ed-45c9-bc33-885ddf14a0be\",\"name\":\"ResetOutdatedLocations\",\"payload\":{},\"scheduled_time\":\"2023-05-25T19:44:00Z\"}","headers":{"Content-Type":"application/json","User-Agent":"hasura-graphql-engine/v2.25.1","caller":"hasura"},"method":"POST","query_string":"","response_timeout":"5000000","url":"{{SAFENOW_PHONESTATUS_RECEIVER_BASEURL}}/resetOutdatedLocations"},"original_size":293,"req_transform_ctx":null,"session_vars":null,"transformed_request":null,"transformed_size":null},"response":{"detail":{"message":"Connection failure","request":{"host":"host.docker.internal","method":"POST","path":"/resetOutdatedLocations","port":8901,"queryString":"","requestHeaders":{"Content-Type":"application/json","User-Agent":"hasura-graphql-engine/v2.25.1","X-B3-ParentSpanId":"7d8382c6cee1c905","X-B3-Sampled":"1","X-B3-SpanId":"6fe4c9d044bdf3bf","X-B3-TraceId":"58e2d58bbf9309a2fa2f933b6828c015","caller":"hasura"},"responseTimeout":"ResponseTimeoutMicro 5000000","secure":false},"type":"http_exception"},"type":"client"}},"level":"info","timestamp":"2023-05-25T19:44:05.892+0000","type":"scheduled-trigger"}
{"detail":{"event_id":"c220196d-b189-4293-b088-00e6ec27b7aa","event_name":"EvaluateRules","request":{"original_request":{"body":"{\"comment\":\"Cron that triggers the rule-engine\",\"id\":\"c220196d-b189-4293-b088-00e6ec27b7aa\",\"name\":\"EvaluateRules\",\"payload\":{},\"scheduled_time\":\"2023-05-25T19:44:00Z\"}","headers":{"Content-Type":"application/json","User-Agent":"hasura-graphql-engine/v2.25.1","caller":"hasura"},"method":"POST","query_string":"","response_timeout":"60000000","url":"{{SAFENOW_RULE_ENGINE_BASEURL}}/evaluateRules"},"original_size":168,"req_transform_ctx":null,"session_vars":null,"transformed_request":null,"transformed_size":null},"response":{"detail":{"message":"Connection failure","request":{"host":"host.docker.internal","method":"POST","path":"/evaluateRules","port":8712,"queryString":"","requestHeaders":{"Content-Type":"application/json","User-Agent":"hasura-graphql-engine/v2.25.1","X-B3-ParentSpanId":"7ff53e914c1d096b","X-B3-Sampled":"1","X-B3-SpanId":"3a0da82feac908fa","X-B3-TraceId":"a59118fac4af8b493321cbfcb640cba1","caller":"hasura"},"responseTimeout":"ResponseTimeoutMicro 60000000","secure":false},"type":"http_exception"},"type":"client"}},"level":"info","timestamp":"2023-05-25T19:44:05.892+0000","type":"scheduled-trigger"}

[SamirTalwar]

Looks like the first line of the logs is "gracefully shutting down server":

{"detail":{"info":"gracefully shutting down server","kind":"server"},"level":"info","timestamp":"2023-05-25T19:43:23.259+0000","type":"startup"}

This implies there's more logs beforehand that we're not seeing. Can you share them?

In addition, it seems you're using a custom Docker image that runs HGE: safenow/hasura-alarmdata-with-migrations:latest. Could you please share the Dockerfile for this image, otherwise it will be very hard to tell where this is going wrong.

[maria-nemeti]

Hi Samir,

here is the docker file:

FROM hasura/graphql-engine:v2.25.1.cli-migrations-v3
ENV HASURA_GRAPHQL_CLI_ENVIRONMENT=default
ADD config/migrations /hasura-migrations
ADD config/metadata /hasura-metadata
ADD config/seeds /seeds
ADD config/config.yaml /config.yaml
COPY docker-entrypoint.sh /bin/docker-entrypoint.sh
LABEL safenow-logtype="json-logfile"
LABEL safenow-context="alarmdata"

I did checked and the docker entry point is similar just a few extra logging.

The logs (all of it since all looks good to me, but truncated at the end since it's only logs of the seeds for pages):

{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"environment variable 'WAIT_BEFORE_START_ENDPOINT' set to postgres:5432 . will wait for it","info":""}}
{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"waiting 30 for postgres:5432 to be ready","info":""}}
{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"postgres:5432 is ready","info":""}}
{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"migrations server port env var is not set, defaulting to 9161"}}
{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"starting graphql engine temporarily on port 9161"}}
{"timestamp":"2023-05-27T10:04:51.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"waiting 300 for 9161 to be ready"}}
{"detail":{"info":{"admin_secret_set":true,"auth_hook":null,"auth_hook_mode":null,"console_assets_dir":null,"console_sentry_dsn":null,"cors_config":{"allowed_origins":"*","disabled":false,"ws_read_cookie":null},"enable_allowlist":false,"enable_console":true,"enable_maintenance_mode":false,"enable_metadata_query_logging":false,"enable_telemetry":false,"enabled_apis":["metadata"],"enabled_log_types":["webhook-log","action-handler-log","http-log","startup","query-log","data-connector-log","websocket-log"],"events_fetch_batch_size":100,"experimental_features":[],"graceful_shutdown_timeout":120,"infer_function_permissions":false,"jwt_secret":[{"audience":null,"claims_format":"json","claims_namespace":"https://hasura.io/jwt/claims","header":null,"issuer":null,"key":"<JWK REDACTED>","type":"<TYPE REDACTED>"}],"live_query_options":{"batch_size":100,"refetch_delay":1},"log_level":"debug","port":9161,"remote_schema_permissions":false,"server_host":"HostAny","stringify_numeric_types":false,"transaction_isolation":"ISOLATION LEVEL READ COMMITTED","unauth_role":"anonymous","use_prepared_statements":true,"v1-boolean-null-collapse":false,"websocket_compression_options":"NoCompression","websocket_connection_init_timeout":"Refined (Seconds {seconds = 3s})","websocket_keep_alive":"KeepAliveDelay {unKeepAliveDelay = Refined (Seconds {seconds = 5s})}"},"kind":"server_configuration"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":{"database_url":"postgres://postgres:...@postgres:5432/postgres","retries":1},"kind":"postgres_connection"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":"Already at the latest catalog version (48); nothing to do.","kind":"catalog_migrate"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":"Schema sync enabled. Polling at Refined (Milliseconds {milliseconds = 1s})","kind":"schema-sync"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":{"instance_id":"e33ffbc5-356b-43bd-b6f5-54db90ac23d0","message":"listener thread started","thread_id":"ThreadId 28"},"kind":"schema-sync"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":"EE client credentials not present in the metadata database. Hasura EE features are disabled.","kind":"license_info"},"level":"warn","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":"Successfully resolved source","kind":"resolve_source"},"level":"debug","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":{"info":{"message":"source \"default\" is already at the latest catalog version (3).","source":"default"},"kind":"source_catalog_migrate"},"level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"startup"}
{"detail":"Thread SchemeUpdate.listener (re)started","level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"unstructured"}
{"detail":"Thread ourIdleGC (re)started","level":"info","timestamp":"2023-05-27T10:04:51.800+0000","type":"unstructured"}
{"detail":"The following environment variables are deprecated and moved to metadata: HASURA_GRAPHQL_NO_OF_RETRIES","level":"warn","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":{"info":{"instance_id":"e33ffbc5-356b-43bd-b6f5-54db90ac23d0","message":"processor thread started","thread_id":"ThreadId 90"},"kind":"schema-sync"},"level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"startup"}
{"detail":{"info":"starting workers","kind":"event_triggers"},"level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"startup"}
{"detail":{"info":"preparing data","kind":"scheduled_triggers"},"level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"startup"}
{"detail":{"info":"Help us improve Hasura! The graphql-engine server collects anonymized usage stats which allows us to keep improving Hasura at warp speed. To read more or opt-out, visit https://hasura.io/docs/latest/graphql/core/guides/telemetry.html","kind":"telemetry"},"level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"startup"}
{"detail":{"info":{"message":"starting API server","time_taken":1.7274382},"kind":"server"},"level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"startup"}
{"detail":"Thread SchemeUpdate.processor (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread asyncActionSubscriptionsProcessor (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread sourcePingPoller (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread websocket connection reaper thread (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread runTelemetry (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread processScheduledTriggers (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread update JWK (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread processEventQueue (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread asyncActionsProcessor (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread runCronEventsGenerator (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"detail":"Thread checkForUpdates (re)started","level":"info","timestamp":"2023-05-27T10:04:53.496+0000","type":"unstructured"}
{"timestamp":"2023-05-27T10:04:54.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"port 9161 is ready"}}
{"timestamp":"2023-05-27T10:04:54.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"env var HASURA_GRAPHQL_MIGRATIONS_DIR is not set, defaulting to /hasura-migrations"}}
{"timestamp":"2023-05-27T10:04:54.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-startup","info":"env var HASURA_GRAPHQL_METADATA_DIR is not set, defaulting to /hasura-metadata"}}
{"timestamp":"2023-05-27T10:04:54.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-apply","info":"applying metadata from /hasura-metadata"}}
{"level":"info","msg":"Help us improve Hasura! The cli collects anonymized usage stats which\nallow us to keep improving Hasura at warp speed. To opt-out or read more,\nvisit https://hasura.io/docs/latest/graphql/core/guides/telemetry.html\n","time":"2023-05-27T10:04:54Z"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"d89ac759-1f0d-47d8-bd81-798bb5eaf99f","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"d89ac759-1f0d-47d8-bd81-798bb5eaf99f"},"level":"info","timestamp":"2023-05-27T10:04:54.832+0000","type":"http-log"}
{"level":"info","msg":"Applying metadata...","time":"2023-05-27T10:04:54Z"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"615a3bbc-d2cb-4c91-9d83-54fd7884c022","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"615a3bbc-d2cb-4c91-9d83-54fd7884c022"},"level":"info","timestamp":"2023-05-27T10:04:54.832+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.55076e-2,"request_id":"4208501f-3769-41c7-a153-6977d78a221c","request_mode":"non-graphql","request_read_time":8.3e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"4208501f-3769-41c7-a153-6977d78a221c"},"level":"info","timestamp":"2023-05-27T10:04:54.832+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/query"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.53304e-2,"request_id":"59d2199e-0309-4894-9776-0ce0ba2fdbde","request_mode":"non-graphql","request_read_time":7.3e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"59d2199e-0309-4894-9776-0ce0ba2fdbde"},"level":"info","timestamp":"2023-05-27T10:04:54.832+0000","type":"http-log"}
{"detail":{"info":"Successfully resolved source","kind":"resolve_source"},"level":"debug","timestamp":"2023-05-27T10:04:55.953+0000","type":"startup"}
{"detail":{"info":{"message":"source \"default\" is already at the latest catalog version (3).","source":"default"},"kind":"source_catalog_migrate"},"level":"info","timestamp":"2023-05-27T10:04:55.953+0000","type":"startup"}
{"level":"info","msg":"Metadata applied","time":"2023-05-27T10:04:57Z"}
{"timestamp":"2023-05-27T10:04:57.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-apply","info":"applying migrations from /hasura-migrations"}}
{"level":"info","msg":"getting lists of databases from server ","time":"2023-05-27T10:04:57Z"}
{"detail":{"info":"Attempting to insert new metadata in storage","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Successfully inserted new metadata in storage with resource version: 10","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Inserted schema cache sync notification at resource version:10","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"replace_metadata"},"query_execution_time":1.5058839,"request_id":"0e39563f-e564-436a-818f-1f50fcc78b74","request_mode":"non-graphql","request_read_time":4.825e-4,"response_size":48,"uncompressed_response_size":48,"user_vars":{"x-hasura-role":"admin"}},"request_id":"0e39563f-e564-436a-818f-1f50fcc78b74"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"348b1677-928d-4b23-abe3-8d2f32bbe4d7","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"348b1677-928d-4b23-abe3-8d2f32bbe4d7"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.38794e-2,"request_id":"4d904269-a753-44e3-b063-73743745d613","request_mode":"non-graphql","request_read_time":8.0e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"4d904269-a753-44e3-b063-73743745d613"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.50735e-2,"request_id":"ce0f3a08-d73a-4264-8583-6c372c261c04","request_mode":"non-graphql","request_read_time":7.3e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"ce0f3a08-d73a-4264-8583-6c372c261c04"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"info":"Received metadata resource version: 9, different from the current engine resource version: 10. Trying to update the schema cache.","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata with resource version: 10","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata notifications and received no notifications. Not updating the schema cache. Only setting resource version: 10 in schema cache","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Received metadata resource version: 9, different from the current engine resource version: 10. Trying to update the schema cache.","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata with resource version: 10","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata notifications and received no notifications. Not updating the schema cache. Only setting resource version: 10 in schema cache","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"schema-sync"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"c0181166-b7d9-4ff3-bd2a-43a341be3fe4","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"c0181166-b7d9-4ff3-bd2a-43a341be3fe4"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.34271e-2,"request_id":"b331a337-5f9d-4bb5-b583-6bf4a36d2dcd","request_mode":"non-graphql","request_read_time":7.8e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"b331a337-5f9d-4bb5-b583-6bf4a36d2dcd"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.8886e-2,"request_id":"82100e59-cc2c-4939-a940-8b5a8e30808d","request_mode":"non-graphql","request_read_time":8.1e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"82100e59-cc2c-4939-a940-8b5a8e30808d"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.56163e-2,"request_id":"870f566b-a332-4e84-b057-28d649ecaed8","request_mode":"non-graphql","request_read_time":6.6e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"870f566b-a332-4e84-b057-28d649ecaed8"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/query"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.15007e-2,"request_id":"1fc4ebbe-5654-4a2c-ab3e-7fb47dbfa75c","request_mode":"non-graphql","request_read_time":7.1e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"1fc4ebbe-5654-4a2c-ab3e-7fb47dbfa75c"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"set_catalog_state"},"query_execution_time":1.48879e-2,"request_id":"7787adcc-db91-4b4c-a6c5-67b7f26565e0","request_mode":"non-graphql","request_read_time":6.4e-6,"response_size":21,"uncompressed_response_size":21,"user_vars":{"x-hasura-role":"admin"}},"request_id":"7787adcc-db91-4b4c-a6c5-67b7f26565e0"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"level":"info","msg":"nothing to apply on database: default","time":"2023-05-27T10:04:57Z"}
{"timestamp":"2023-05-27T10:04:57.000+0000","level":"info","type":"startup","detail":{"kind":"migrations-apply","info":"reloading metadata"}}
{"level":"info","msg":"Reloading metadata...","time":"2023-05-27T10:04:58Z"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/query"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.11956e-2,"request_id":"35ead270-432b-42ea-a0cb-8ded87422414","request_mode":"non-graphql","request_read_time":7.4e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"35ead270-432b-42ea-a0cb-8ded87422414"},"level":"info","timestamp":"2023-05-27T10:04:58.207+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"bd3de8d2-0003-44c7-9fbd-0c8ccd8e95ab","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"bd3de8d2-0003-44c7-9fbd-0c8ccd8e95ab"},"level":"info","timestamp":"2023-05-27T10:04:58.207+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.53368e-2,"request_id":"2cce65e7-272d-4f6c-8a55-5baae98cae34","request_mode":"non-graphql","request_read_time":6.7e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"2cce65e7-272d-4f6c-8a55-5baae98cae34"},"level":"info","timestamp":"2023-05-27T10:04:58.207+0000","type":"http-log"}
{"detail":{"info":{"message":"source \"default\" is already at the latest catalog version (3).","source":"default"},"kind":"source_catalog_migrate"},"level":"info","timestamp":"2023-05-27T10:04:58.207+0000","type":"startup"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.50525e-2,"request_id":"9b35a9da-4123-4415-9090-951b5c56a940","request_mode":"non-graphql","request_read_time":9.6e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"9b35a9da-4123-4415-9090-951b5c56a940"},"level":"info","timestamp":"2023-05-27T10:04:57.155+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"95b61777-f02a-4c4f-bcde-2b79aa2c714f","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"95b61777-f02a-4c4f-bcde-2b79aa2c714f"},"level":"info","timestamp":"2023-05-27T10:04:58.207+0000","type":"http-log"}
{"detail":{"info":"Successfully resolved source","kind":"resolve_source"},"level":"debug","timestamp":"2023-05-27T10:04:58.207+0000","type":"startup"}
{"detail":{"info":"Attempting to insert new metadata in storage","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"level":"info","msg":"Metadata reloaded","time":"2023-05-27T10:04:59Z"}
{"level":"info","msg":"Metadata is consistent","time":"2023-05-27T10:04:59Z"}
Applying seed data
{"level":"info","msg":"Applying seeds...","time":"2023-05-27T10:05:00Z"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.31454e-2,"request_id":"d08226cc-ef75-4781-8b3c-eec24a03d5d3","request_mode":"non-graphql","request_read_time":5.9e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"d08226cc-ef75-4781-8b3c-eec24a03d5d3"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"info":"Successfully inserted new metadata in storage with resource version: 11","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Inserted schema cache sync notification at resource version:11","thread_type":"metadata-api"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"reload_metadata"},"query_execution_time":1.7104597,"request_id":"dbb1e484-dde4-4c83-a503-9be6765ce50b","request_mode":"non-graphql","request_read_time":8.1e-6,"response_size":42,"uncompressed_response_size":42,"user_vars":{"x-hasura-role":"admin"}},"request_id":"dbb1e484-dde4-4c83-a503-9be6765ce50b"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"info":"Received metadata resource version: 10, different from the current engine resource version: 11. Trying to update the schema cache.","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata with resource version: 11","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata notifications and received no notifications. Not updating the schema cache. Only setting resource version: 11 in schema cache","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Received metadata resource version: 10, different from the current engine resource version: 11. Trying to update the schema cache.","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata with resource version: 11","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"info":"Fetched metadata notifications and received no notifications. Not updating the schema cache. Only setting resource version: 11 in schema cache","thread_type":"processor"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"schema-sync"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/query"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.20462e-2,"request_id":"4b2c7913-fda6-4a11-9e6e-0ce25fc8760e","request_mode":"non-graphql","request_read_time":7.2e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"4b2c7913-fda6-4a11-9e6e-0ce25fc8760e"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"640907ac-dbf1-4c09-a7db-9305ad45bc4c","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"640907ac-dbf1-4c09-a7db-9305ad45bc4c"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_catalog_state"},"query_execution_time":1.4269e-2,"request_id":"ebb054f6-6abb-4de6-8df6-f02e318a7efd","request_mode":"non-graphql","request_read_time":7.6e-6,"response_size":3001,"uncompressed_response_size":8926,"user_vars":{"x-hasura-role":"admin"}},"request_id":"ebb054f6-6abb-4de6-8df6-f02e318a7efd"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"get_inconsistent_metadata"},"query_execution_time":3.16964e-2,"request_id":"95376baf-a86b-4824-84a1-6a2ade95aee1","request_mode":"non-graphql","request_read_time":1.24e-5,"response_size":48,"uncompressed_response_size":48,"user_vars":{"x-hasura-role":"admin"}},"request_id":"95376baf-a86b-4824-84a1-6a2ade95aee1"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/v1/version"},"operation":{"request_id":"c4f2982f-24db-45cf-a4d2-533624b47437","request_mode":"non-graphql","response_size":16,"uncompressed_response_size":16},"request_id":"c4f2982f-24db-45cf-a4d2-533624b47437"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v1/metadata"},"operation":{"query":{"type":"export_metadata"},"query_execution_time":1.23832e-2,"request_id":"2aadad51-7394-4c39-8481-e56744c46913","request_mode":"non-graphql","request_read_time":7.7e-6,"response_size":15419,"uncompressed_response_size":105109,"user_vars":{"x-hasura-role":"admin"}},"request_id":"2aadad51-7394-4c39-8481-e56744c46913"},"level":"info","timestamp":"2023-05-27T10:04:59.915+0000","type":"http-log"}
{"detail":{"http_info":{"content_encoding":"gzip","http_version":"HTTP/1.1","ip":"127.0.0.1","method":"POST","status":200,"url":"/v2/query"},"operation":{"query":{"args":[{"args":{"source":"default","sql":"UPDATE \"alarmdata\".\"application_settings\"\nSET …

[SamirTalwar]

It looks like you haven't added the CMD line documented in the README to your Dockerfile:

CMD graphql-engine \
  --metadata-database-url $METADATA_DATABASE_URL \
  serve \
  --server-port $PORT \
  --enable-console

Please take a look at the README for more info.

This information should also be in the docs but seems to be missing. I will bring it up with the Hasura documentation team.

[maria-nemeti]

Hi Samir,
thanks for your response! I did some tries today and I think that:

HASURA_GRAPHQL_SERVER_PORT: 7070

is not working as described here: https://hasura.io/docs/latest/deployment/graphql-engine-flags/reference/#server-port
(or stopped working sometime after version 2.17.1)

My local environment does work if I just replace the:

    image: safenow/hasura-alarmdata-with-migrations:latest
    ports:
      - "7070:7070"
    environment:
      HASURA_GRAPHQL_SERVER_PORT: 7070

  with 

    image: safenow/hasura-alarmdata-with-migrations:latest
    ports:
      - "7070:8080"
    environment:
      # HASURA_GRAPHQL_SERVER_PORT: 7070

[SamirTalwar]

That's being overridden by --server-port in the CMD line. I suggest removing --server-port $PORT.

In general, you may want to customize that CMD line however you see fit.