search

immich-app / immich

High performance self-hosted photo and video management solution.
https://immich.app
GNU Affero General Public License v3.0
49.77k stars 2.63k forks source link

PostgreSQL database failure after v1.106 upgrade attempt #10239

Closed iamtherobin closed 4 months ago

iamtherobin commented 4 months ago

The bug

I tried to upgrade from v1.105.1 to v1.106.2 by following modifying the yaml file accordingly and pulling the new images. The result was restarting immich server container. Then I tried reverting back to v1.105.1 but now I am getting a postgres container error. I cannot get either v1.105.1 or newer to load anymore.

I am currently trying to load v1.106.3 and postgres keeps restarting at "PostgreSQL Database directory appears to contain a database". Both postgres and server container repeat the error shown in the docker log.

I also attached the postgres logs from the database log folder. The postgres start from where I attempted the v1.106 update upto the point where it just keeps repeating.

The OS that Immich Server is running on

Arch, kernel 6.8.9

Version of Immich Server

v1.106.3

Version of Immich Mobile App

latest

Platform with the issue

Your docker-compose.yml content

#
# WARNING: Make sure to use the docker-compose.yml of the current release:
#
# https://github.com/immich-app/immich/releases/latest/download/docker-compose.yml
#
# The compose file on main may not be compatible with the latest release.
#

name: immich

services:
  immich-server:
    container_name: immich-server
    image: ghcr.io/immich-app/immich-server:${IMMICH_VERSION:-release}
    # extends:
    #   file: hwaccel.transcoding.yml
    #   service: cpu # set to one of [nvenc, quicksync, rkmpp, vaapi, vaapi-wsl] for accelerated transcoding
    volumes:
      - ${UPLOAD_LOCATION}:/usr/src/app/upload
      - /etc/localtime:/etc/localtime:ro
    env_file:
      - .env
    ports:
      - 2283:3001
    depends_on:
      - redis
      - database
    restart: unless-stopped
    networks:
      - immich

  immich-machine-learning:
    container_name: immich-machinelearning
    # For hardware acceleration, add one of -[armnn, cuda, openvino] to the image tag.
    # Example tag: ${IMMICH_VERSION:-release}-cuda
    image: ghcr.io/immich-app/immich-machine-learning:${IMMICH_VERSION:-release}
    # extends: # uncomment this section for hardware acceleration - see https://immich.app/docs/features/ml-hardware-acceleration
    #   file: hwaccel.ml.yml
    #   service: cpu # set to one of [armnn, cuda, openvino, openvino-wsl] for accelerated inference - use the `-wsl` version for WSL2 where applicable
    volumes:
      - model-cache:/cache
    env_file:
      - .env
    restart: always
    networks:
      - immich

  redis:
    container_name: immich-redis
    image: docker.io/redis:6.2-alpine@sha256:d6c2911ac51b289db208767581a5d154544f2b2fe4914ea5056443f62dc6e900
    healthcheck:
      test: redis-cli ping || exit 1
    restart: always
    networks:
      - immich

  database:
    container_name: immich-postgres
    image: docker.io/tensorchord/pgvecto-rs:pg14-v0.2.0@sha256:90724186f0a3517cf6914295b5ab410db9ce23190a2d9d0b9dd6463e3fa298f0
    environment:
      POSTGRES_PASSWORD: ${DB_PASSWORD}
      POSTGRES_USER: ${DB_USERNAME}
      POSTGRES_DB: ${DB_DATABASE_NAME}
      POSTGRES_INITDB_ARGS: '--data-checksums'
    volumes:
      - ${DB_DATA_LOCATION}:/var/lib/postgresql/data
    healthcheck:
      test: pg_isready --dbname='${DB_DATABASE_NAME}' || exit 1; Chksum="$$(psql --dbname='${DB_DATABASE_NAME}' --username='${DB_USERNAME}' --tuples-only --no-align --command='SELECT COALESCE(SUM(checksum_failures), 0) FROM pg_stat_database')"; echo "checksum failure count is $$Chksum"; [ "$$Chksum" = '0' ] || exit 1
      interval: 5m
      start_interval: 30s
      start_period: 5m
    command: ["postgres", "-c" ,"shared_preload_libraries=vectors.so", "-c", 'search_path="$$user", public, vectors', "-c", "logging_collector=on", "-c", "max_wal_size=2GB", "-c", "shared_buffers=512MB", "-c", "wal_compression=on"]
    restart: always
    networks:
      - immich

volumes:
  model-cache:

networks:
  immich:
    name: immich
    enable_ipv6: true
    ipam:
      config:
        - subnet: fd12:3456:7890:3::/64
          gateway: fd12:3456:7890:3::1

Your .env content

# You can find documentation for all the supported env variables at https://immich.app/docs/install/environment-variables

# The location where your uploaded files are stored
UPLOAD_LOCATION=/hdd-storage/immich/library
# The location where your database files are stored
DB_DATA_LOCATION=/hdd-storage/immich/postgres

# To set a timezone, uncomment the next line and change Etc/UTC to a TZ identifier from this list: https://en.wikipedia.org/wiki/List_of_tz_database_time_zones#List
TZ=America/Toronto

# The Immich version to use. You can pin this to a specific version like "v1.71.0"
#IMMICH_VERSION=v1.105.1
IMMICH_VERSION=release

# Connection secret for postgres. You should change it to a random password
DB_PASSWORD=postgres

# The values below this line do not need to be changed
###################################################################################
DB_USERNAME=postgres
DB_DATABASE_NAME=immich

Reproduction steps

1.
2.
3.
...

Relevant log output

[robin@lab immich]$ sudo docker compose -f docker-compose-immich.yaml pull
[+] Pulling 4/4
 ✔ immich-machine-learning Pulled                                                                                                                                                                                                1.3s
 ✔ database Pulled                                                                                                                                                                                                               2.3s
 ✔ redis Pulled                                                                                                                                                                                                                  1.0s
 ✔ immich-server Pulled                                                                                                                                                                                                          1.3s
[robin@lab immich]$ sudo docker compose -f docker-compose-immich.yaml up
[+] Running 5/5
 ✔ Network immich                    Created                                                                                                                                                                                     0.1s
 ✔ Container immich-machinelearning  Created                                                                                                                                                                                     0.0s
 ✔ Container immich-postgres         Created                                                                                                                                                                                     0.0s
 ✔ Container immich-redis            Created                                                                                                                                                                                     0.0s
 ✔ Container immich-server           Created                                                                                                                                                                                     0.1s
Attaching to immich-machinelearning, immich-postgres, immich-redis, immich-server
immich-redis            | 1:C 12 Jun 2024 22:48:45.409 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
immich-redis            | 1:C 12 Jun 2024 22:48:45.409 # Redis version=6.2.14, bits=64, commit=00000000, modified=0, pid=1, just started
immich-redis            | 1:C 12 Jun 2024 22:48:45.409 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
immich-redis            | 1:M 12 Jun 2024 22:48:45.409 * monotonic clock: POSIX clock_gettime
immich-redis            | 1:M 12 Jun 2024 22:48:45.409 * Running mode=standalone, port=6379.
immich-redis            | 1:M 12 Jun 2024 22:48:45.409 # Server initialized
immich-redis            | 1:M 12 Jun 2024 22:48:45.409 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
immich-redis            | 1:M 12 Jun 2024 22:48:45.410 * Ready to accept connections
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:45.458 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:45.458 UTC [1] HINT:  Future log output will appear in directory "log".
immich-server           | Detected CPU Cores: 12
immich-machinelearning  | [06/12/24 18:48:45] INFO     Starting gunicorn 22.0.0
immich-machinelearning  | [06/12/24 18:48:45] INFO     Listening at: http://[::]:3003 (9)
immich-machinelearning  | [06/12/24 18:48:45] INFO     Using worker: app.config.CustomUvicornWorker
immich-machinelearning  | [06/12/24 18:48:45] INFO     Booting worker with pid: 10
immich-server           | Starting api worker
immich-server           | Starting microservices worker
immich-postgres exited with code 0
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:47.269 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:47.269 UTC [1] HINT:  Future log output will appear in directory "log".
immich-machinelearning  | [06/12/24 18:48:48] INFO     Started server process [10]
immich-machinelearning  | [06/12/24 18:48:48] INFO     Waiting for application startup.
immich-machinelearning  | [06/12/24 18:48:48] INFO     Created in-memory cache with unloading after 300s
immich-machinelearning  |                              of inactivity.
immich-machinelearning  | [06/12/24 18:48:48] INFO     Initialized request thread pool with 12 threads.
immich-machinelearning  | [06/12/24 18:48:48] INFO     Application startup complete.
immich-postgres exited with code 0
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:49.106 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:49.106 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres exited with code 1
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:51.070 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:51.070 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:53.351 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:53.351 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:48:56.547 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:48:56.547 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:49:01.277 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:49:01.277 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:49:09.180 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:49:09.180 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:49:23.432 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:49:23.432 UTC [1] HINT:  Future log output will appear in directory "log".
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:49:50.490 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:49:50.490 UTC [1] HINT:  Future log output will appear in directory "log".
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [NestFactory] Starting Nest application...
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] BullModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] OpenTelemetryModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] TypeOrmModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] OpenTelemetryCoreModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] ConfigHostModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] DiscoveryModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] ClsModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] ConfigModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] EventEmitterModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] ScheduleModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] BullModule dependencies initialized +0ms
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM     LOG [InstanceLoader] BullModule dependencies initialized +1ms
immich-server           | [Nest] 7  - 06/12/2024, 6:50:12 PM     LOG [NestFactory] Starting Nest application...
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (1)...
immich-server           | error: the database system is starting up
immich-server           |     at Parser.parseErrorMessage (/usr/src/app/node_modules/pg-protocol/dist/parser.js:283:98)
immich-server           |     at Parser.handlePacket (/usr/src/app/node_modules/pg-protocol/dist/parser.js:122:29)
immich-server           |     at Parser.parse (/usr/src/app/node_modules/pg-protocol/dist/parser.js:35:38)
immich-server           |     at Socket.<anonymous> (/usr/src/app/node_modules/pg-protocol/dist/index.js:11:42)
immich-server           |     at Socket.emit (node:events:519:28)
immich-server           |     at addChunk (node:internal/streams/readable:559:12)
immich-server           |     at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)
immich-server           |     at Readable.push (node:internal/streams/readable:390:5)
immich-server           |     at TCP.onStreamRead (node:internal/stream_base_commons:191:23)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (2)...
immich-server           | error: the database system is starting up
immich-server           |     at Parser.parseErrorMessage (/usr/src/app/node_modules/pg-protocol/dist/parser.js:283:98)
immich-server           |     at Parser.handlePacket (/usr/src/app/node_modules/pg-protocol/dist/parser.js:122:29)
immich-server           |     at Parser.parse (/usr/src/app/node_modules/pg-protocol/dist/parser.js:35:38)
immich-server           |     at Socket.<anonymous> (/usr/src/app/node_modules/pg-protocol/dist/index.js:11:42)
immich-server           |     at Socket.emit (node:events:519:28)
immich-server           |     at addChunk (node:internal/streams/readable:559:12)
immich-server           |     at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)
immich-server           |     at Readable.push (node:internal/streams/readable:390:5)
immich-server           |     at TCP.onStreamRead (node:internal/stream_base_commons:191:23)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (3)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (4)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 7  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (1)...
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (5)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (6)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (7)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (8)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [TypeOrmModule] Unable to connect to the database. Retrying (9)...
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | [Nest] 17  - 06/12/2024, 6:50:12 PM   ERROR [ExceptionHandler] getaddrinfo ENOTFOUND database
immich-server           | Error: getaddrinfo ENOTFOUND database
immich-server           |     at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26)
immich-server           | microservices worker exited with code 1
immich-server exited with code 0
immich-server           | Detected CPU Cores: 12
immich-server           | Starting api worker
immich-server           | Starting microservices worker
immich-postgres         |
immich-postgres         | PostgreSQL Database directory appears to contain a database; Skipping initialization
immich-postgres         |
immich-postgres         | 2024-06-12 22:50:43.168 UTC [1] LOG:  redirecting log output to logging collector process
immich-postgres         | 2024-06-12 22:50:43.168 UTC [1] HINT:  Future log output will appear in directory "log".
^CGracefully stopping... (press Ctrl+C again to force)
[+] Stopping 4/4
 ✔ Container immich-machinelearning  Stopped                                                                                                                                                                                     0.3s
 ✔ Container immich-server           Stopped                                                                                                                                                                                     0.4s
 ✔ Container immich-postgres         Stopped                                                                                                                                                                                     0.0s
 ✔ Container immich-redis            Stopped                                                                                                                                                                                     0.3s
canceled

Additional information

2024-06-12 02:57:29.817 UTC [1] LOG:  received fast shutdown request
2024-06-12 02:57:29.828 UTC [1] LOG:  aborting any active transactions
2024-06-12 02:57:29.828 UTC [1723] FATAL:  terminating connection due to administrator command
2024-06-12 02:57:29.828 UTC [55] FATAL:  terminating connection due to administrator command
2024-06-12 02:57:29.828 UTC [54] FATAL:  terminating connection due to administrator command
2024-06-12 02:57:29.830 UTC [1] LOG:  background worker "logical replication launcher" (PID 35) exited with exit code 1
2024-06-12 02:57:29.834 UTC [30] LOG:  shutting down
2024-06-12 02:57:29.994 UTC [1] LOG:  database system is shut down

2024-06-12 03:18:48.160 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 03:18:48.160 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 03:18:48.160 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 03:18:48.164 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 03:18:48.186 UTC [27] LOG:  database system was shut down at 2024-06-12 02:57:29 UTC
[2024-06-12T03:18:48Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T03:18:48Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T03:18:48Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 03:18:48.251 UTC [1] LOG:  database system is ready to accept connections
[2024-06-12T03:18:48Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 03:19:18.185 UTC [54] FATAL:  role "root" does not exist
2024-06-12 03:24:18.460 UTC [69] FATAL:  role "root" does not exist
2024-06-12 03:29:18.565 UTC [84] FATAL:  role "root" does not exist
2024-06-12 03:34:18.669 UTC [99] FATAL:  role "root" does not exist
2024-06-12 03:39:18.785 UTC [114] FATAL:  role "root" does not exist
2024-06-12 03:44:18.882 UTC [129] FATAL:  role "root" does not exist
2024-06-12 03:49:18.992 UTC [144] FATAL:  role "root" does not exist
2024-06-12 03:54:19.106 UTC [159] FATAL:  role "root" does not exist
2024-06-12 03:59:19.212 UTC [174] FATAL:  role "root" does not exist
2024-06-12 04:04:19.324 UTC [189] FATAL:  role "root" does not exist
2024-06-12 04:09:19.462 UTC [204] FATAL:  role "root" does not exist
2024-06-12 04:14:19.559 UTC [219] FATAL:  role "root" does not exist
2024-06-12 04:19:19.664 UTC [234] FATAL:  role "root" does not exist
2024-06-12 04:24:19.772 UTC [249] FATAL:  role "root" does not exist
2024-06-12 04:29:19.892 UTC [264] FATAL:  role "root" does not exist
2024-06-12 04:34:20.009 UTC [279] FATAL:  role "root" does not exist
2024-06-12 04:39:20.126 UTC [294] FATAL:  role "root" does not exist
2024-06-12 04:44:20.239 UTC [309] FATAL:  role "root" does not exist
2024-06-12 04:49:20.338 UTC [324] FATAL:  role "root" does not exist
2024-06-12 04:54:20.455 UTC [339] FATAL:  role "root" does not exist
2024-06-12 04:59:20.555 UTC [354] FATAL:  role "root" does not exist
2024-06-12 05:04:20.679 UTC [369] FATAL:  role "root" does not exist
2024-06-12 05:09:20.792 UTC [384] FATAL:  role "root" does not exist
2024-06-12 05:14:20.902 UTC [399] FATAL:  role "root" does not exist
2024-06-12 05:19:21.009 UTC [414] FATAL:  role "root" does not exist
2024-06-12 05:24:21.113 UTC [429] FATAL:  role "root" does not exist
2024-06-12 05:29:21.205 UTC [444] FATAL:  role "root" does not exist
2024-06-12 05:34:21.322 UTC [459] FATAL:  role "root" does not exist
2024-06-12 05:39:21.432 UTC [474] FATAL:  role "root" does not exist
2024-06-12 05:44:21.538 UTC [489] FATAL:  role "root" does not exist
2024-06-12 05:49:21.645 UTC [504] FATAL:  role "root" does not exist
2024-06-12 05:54:21.758 UTC [519] FATAL:  role "root" does not exist
2024-06-12 05:59:21.860 UTC [534] FATAL:  role "root" does not exist
2024-06-12 06:04:21.955 UTC [549] FATAL:  role "root" does not exist
2024-06-12 06:09:22.065 UTC [564] FATAL:  role "root" does not exist
2024-06-12 06:14:22.198 UTC [579] FATAL:  role "root" does not exist
2024-06-12 06:19:22.302 UTC [594] FATAL:  role "root" does not exist
2024-06-12 06:24:22.405 UTC [609] FATAL:  role "root" does not exist
2024-06-12 06:29:22.486 UTC [624] FATAL:  role "root" does not exist
2024-06-12 06:34:22.588 UTC [639] FATAL:  role "root" does not exist
2024-06-12 06:39:22.708 UTC [654] FATAL:  role "root" does not exist
2024-06-12 06:44:22.845 UTC [669] FATAL:  role "root" does not exist
2024-06-12 06:49:22.958 UTC [684] FATAL:  role "root" does not exist
2024-06-12 06:54:23.064 UTC [699] FATAL:  role "root" does not exist
2024-06-12 06:59:23.169 UTC [714] FATAL:  role "root" does not exist
2024-06-12 07:04:23.281 UTC [729] FATAL:  role "root" does not exist
2024-06-12 07:09:23.414 UTC [744] FATAL:  role "root" does not exist
2024-06-12 07:14:23.528 UTC [759] FATAL:  role "root" does not exist
2024-06-12 07:19:23.641 UTC [774] FATAL:  role "root" does not exist
2024-06-12 07:24:23.748 UTC [789] FATAL:  role "root" does not exist
2024-06-12 07:29:23.851 UTC [804] FATAL:  role "root" does not exist
2024-06-12 07:34:23.966 UTC [819] FATAL:  role "root" does not exist
2024-06-12 07:39:24.071 UTC [834] FATAL:  role "root" does not exist
2024-06-12 07:44:24.165 UTC [849] FATAL:  role "root" does not exist
2024-06-12 07:49:24.264 UTC [864] FATAL:  role "root" does not exist
2024-06-12 07:54:24.371 UTC [879] FATAL:  role "root" does not exist
2024-06-12 07:59:24.473 UTC [894] FATAL:  role "root" does not exist
2024-06-12 08:04:24.589 UTC [909] FATAL:  role "root" does not exist
2024-06-12 08:09:24.666 UTC [924] FATAL:  role "root" does not exist
2024-06-12 08:14:24.771 UTC [939] FATAL:  role "root" does not exist
2024-06-12 08:19:24.864 UTC [954] FATAL:  role "root" does not exist
2024-06-12 08:24:24.967 UTC [969] FATAL:  role "root" does not exist
2024-06-12 08:29:25.087 UTC [984] FATAL:  role "root" does not exist
2024-06-12 08:34:25.204 UTC [999] FATAL:  role "root" does not exist
2024-06-12 08:39:25.297 UTC [1014] FATAL:  role "root" does not exist
2024-06-12 08:44:25.411 UTC [1029] FATAL:  role "root" does not exist
2024-06-12 08:49:25.514 UTC [1044] FATAL:  role "root" does not exist
2024-06-12 08:54:25.627 UTC [1059] FATAL:  role "root" does not exist
2024-06-12 08:59:25.724 UTC [1074] FATAL:  role "root" does not exist
2024-06-12 09:04:25.834 UTC [1089] FATAL:  role "root" does not exist
2024-06-12 09:09:25.954 UTC [1104] FATAL:  role "root" does not exist
2024-06-12 09:14:26.067 UTC [1119] FATAL:  role "root" does not exist
2024-06-12 09:19:26.170 UTC [1134] FATAL:  role "root" does not exist
2024-06-12 09:24:26.293 UTC [1149] FATAL:  role "root" does not exist
2024-06-12 09:29:26.404 UTC [1164] FATAL:  role "root" does not exist
2024-06-12 09:34:26.524 UTC [1179] FATAL:  role "root" does not exist
2024-06-12 09:39:26.643 UTC [1194] FATAL:  role "root" does not exist
2024-06-12 09:44:26.750 UTC [1209] FATAL:  role "root" does not exist
2024-06-12 09:49:26.884 UTC [1224] FATAL:  role "root" does not exist
2024-06-12 09:54:26.996 UTC [1239] FATAL:  role "root" does not exist
2024-06-12 09:59:27.120 UTC [1254] FATAL:  role "root" does not exist
2024-06-12 10:04:27.213 UTC [1269] FATAL:  role "root" does not exist
2024-06-12 10:09:27.310 UTC [1284] FATAL:  role "root" does not exist
2024-06-12 10:14:27.428 UTC [1299] FATAL:  role "root" does not exist
2024-06-12 10:19:27.554 UTC [1314] FATAL:  role "root" does not exist
2024-06-12 10:24:27.664 UTC [1329] FATAL:  role "root" does not exist
2024-06-12 10:29:27.773 UTC [1344] FATAL:  role "root" does not exist
2024-06-12 10:34:27.878 UTC [1359] FATAL:  role "root" does not exist
2024-06-12 10:39:27.987 UTC [1374] FATAL:  role "root" does not exist
2024-06-12 10:44:28.104 UTC [1389] FATAL:  role "root" does not exist
2024-06-12 10:49:28.213 UTC [1404] FATAL:  role "root" does not exist
2024-06-12 10:54:28.353 UTC [1419] FATAL:  role "root" does not exist
2024-06-12 10:59:28.477 UTC [1434] FATAL:  role "root" does not exist
2024-06-12 11:04:28.586 UTC [1449] FATAL:  role "root" does not exist
2024-06-12 11:09:28.707 UTC [1464] FATAL:  role "root" does not exist
2024-06-12 11:14:28.833 UTC [1479] FATAL:  role "root" does not exist
2024-06-12 11:19:28.930 UTC [1494] FATAL:  role "root" does not exist
2024-06-12 11:24:29.057 UTC [1509] FATAL:  role "root" does not exist
2024-06-12 11:29:29.163 UTC [1524] FATAL:  role "root" does not exist
2024-06-12 11:34:29.293 UTC [1539] FATAL:  role "root" does not exist
2024-06-12 11:39:29.393 UTC [1554] FATAL:  role "root" does not exist
2024-06-12 11:44:29.496 UTC [1569] FATAL:  role "root" does not exist
2024-06-12 11:49:29.623 UTC [1584] FATAL:  role "root" does not exist
2024-06-12 11:54:29.753 UTC [1599] FATAL:  role "root" does not exist
2024-06-12 11:59:29.860 UTC [1614] FATAL:  role "root" does not exist
2024-06-12 12:04:29.974 UTC [1629] FATAL:  role "root" does not exist
2024-06-12 12:09:30.086 UTC [1644] FATAL:  role "root" does not exist
2024-06-12 12:14:30.200 UTC [1659] FATAL:  role "root" does not exist
2024-06-12 12:19:30.313 UTC [1674] FATAL:  role "root" does not exist
2024-06-12 12:24:30.426 UTC [1689] FATAL:  role "root" does not exist
2024-06-12 12:29:30.540 UTC [1704] FATAL:  role "root" does not exist
2024-06-12 12:34:30.649 UTC [1719] FATAL:  role "root" does not exist
2024-06-12 12:39:30.746 UTC [1734] FATAL:  role "root" does not exist
2024-06-12 12:44:30.849 UTC [1749] FATAL:  role "root" does not exist
2024-06-12 12:49:30.953 UTC [1764] FATAL:  role "root" does not exist
2024-06-12 12:54:31.079 UTC [1779] FATAL:  role "root" does not exist
2024-06-12 12:59:31.155 UTC [1794] FATAL:  role "root" does not exist
2024-06-12 13:04:31.269 UTC [1809] FATAL:  role "root" does not exist
2024-06-12 13:09:31.406 UTC [1824] FATAL:  role "root" does not exist
2024-06-12 13:14:31.546 UTC [1839] FATAL:  role "root" does not exist
2024-06-12 13:19:31.659 UTC [1854] FATAL:  role "root" does not exist
2024-06-12 13:24:31.769 UTC [1869] FATAL:  role "root" does not exist
2024-06-12 13:29:31.876 UTC [1884] FATAL:  role "root" does not exist
2024-06-12 13:34:31.953 UTC [1899] FATAL:  role "root" does not exist
2024-06-12 13:39:32.075 UTC [1914] FATAL:  role "root" does not exist
2024-06-12 13:44:32.172 UTC [1929] FATAL:  role "root" does not exist
2024-06-12 13:49:32.282 UTC [1944] FATAL:  role "root" does not exist
2024-06-12 13:54:32.389 UTC [1959] FATAL:  role "root" does not exist
2024-06-12 13:59:32.512 UTC [1974] FATAL:  role "root" does not exist
2024-06-12 14:04:32.619 UTC [1989] FATAL:  role "root" does not exist
2024-06-12 14:09:32.732 UTC [2004] FATAL:  role "root" does not exist
2024-06-12 14:14:32.829 UTC [2019] FATAL:  role "root" does not exist
2024-06-12 14:19:32.932 UTC [2034] FATAL:  role "root" does not exist
2024-06-12 14:24:33.035 UTC [2049] FATAL:  role "root" does not exist
2024-06-12 14:29:33.155 UTC [2064] FATAL:  role "root" does not exist
2024-06-12 14:34:33.273 UTC [2079] FATAL:  role "root" does not exist
2024-06-12 14:39:33.378 UTC [2094] FATAL:  role "root" does not exist
2024-06-12 14:44:33.485 UTC [2109] FATAL:  role "root" does not exist
2024-06-12 14:49:33.592 UTC [2124] FATAL:  role "root" does not exist
2024-06-12 14:54:00.649 UTC [1] LOG:  received fast shutdown request
2024-06-12 14:54:00.661 UTC [1] LOG:  aborting any active transactions
2024-06-12 14:54:00.662 UTC [1] LOG:  background worker "logical replication launcher" (PID 39) exited with exit code 1
2024-06-12 14:54:00.663 UTC [29] LOG:  shutting down
2024-06-12 14:54:00.700 UTC [1] LOG:  database system is shut down

2024-06-12 14:59:01.921 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 14:59:01.921 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 14:59:01.921 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 14:59:01.925 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 14:59:01.955 UTC [28] LOG:  database system was shut down at 2024-06-12 14:54:00 UTC
[2024-06-12T14:59:01Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T14:59:01Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T14:59:01Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 14:59:02.004 UTC [1] LOG:  database system is ready to accept connections
[2024-06-12T14:59:02Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 14:59:31.929 UTC [55] FATAL:  role "root" does not exist
2024-06-12 15:01:48.433 UTC [1] LOG:  received fast shutdown request
2024-06-12 15:01:48.447 UTC [1] LOG:  aborting any active transactions
2024-06-12 15:01:48.449 UTC [1] LOG:  background worker "logical replication launcher" (PID 35) exited with exit code 1
2024-06-12 15:01:48.449 UTC [30] LOG:  shutting down
2024-06-12 15:01:48.518 UTC [1] LOG:  database system is shut down

2024-06-12 15:01:49.502 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 15:01:49.502 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 15:01:49.502 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 15:01:49.506 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 15:01:49.512 UTC [27] LOG:  database system was shut down at 2024-06-12 15:01:48 UTC
[2024-06-12T15:01:49Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T15:01:49Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T15:01:49Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T15:01:49Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 15:01:49.523 UTC [1] LOG:  database system is ready to accept connections
2024-06-12 15:02:19.499 UTC [54] FATAL:  role "root" does not exist
2024-06-12 15:07:19.616 UTC [69] FATAL:  role "root" does not exist
2024-06-12 15:12:19.725 UTC [94] FATAL:  role "root" does not exist
2024-06-12 15:17:19.832 UTC [113] FATAL:  role "root" does not exist
2024-06-12 15:22:19.929 UTC [133] FATAL:  role "root" does not exist
2024-06-12 15:27:20.032 UTC [148] FATAL:  role "root" does not exist
2024-06-12 15:32:20.145 UTC [163] FATAL:  role "root" does not exist
2024-06-12 15:37:20.251 UTC [178] FATAL:  role "root" does not exist
2024-06-12 15:42:20.362 UTC [193] FATAL:  role "root" does not exist
2024-06-12 15:47:20.468 UTC [208] FATAL:  role "root" does not exist
2024-06-12 15:52:20.589 UTC [223] FATAL:  role "root" does not exist
2024-06-12 15:57:20.698 UTC [238] FATAL:  role "root" does not exist
2024-06-12 16:02:20.774 UTC [253] FATAL:  role "root" does not exist
2024-06-12 16:07:20.892 UTC [268] FATAL:  role "root" does not exist
2024-06-12 16:12:20.995 UTC [283] FATAL:  role "root" does not exist
2024-06-12 16:17:21.108 UTC [298] FATAL:  role "root" does not exist
2024-06-12 16:22:21.231 UTC [313] FATAL:  role "root" does not exist
2024-06-12 16:27:21.337 UTC [328] FATAL:  role "root" does not exist
2024-06-12 16:32:21.451 UTC [343] FATAL:  role "root" does not exist
2024-06-12 16:37:21.526 UTC [358] FATAL:  role "root" does not exist
2024-06-12 16:42:21.638 UTC [373] FATAL:  role "root" does not exist
2024-06-12 16:47:21.751 UTC [388] FATAL:  role "root" does not exist
2024-06-12 16:52:21.878 UTC [403] FATAL:  role "root" does not exist
2024-06-12 16:57:21.998 UTC [418] FATAL:  role "root" does not exist
2024-06-12 17:02:22.114 UTC [433] FATAL:  role "root" does not exist
2024-06-12 17:07:22.211 UTC [448] FATAL:  role "root" does not exist
2024-06-12 17:12:22.331 UTC [463] FATAL:  role "root" does not exist
2024-06-12 17:17:22.434 UTC [478] FATAL:  role "root" does not exist
2024-06-12 17:22:22.531 UTC [493] FATAL:  role "root" does not exist
2024-06-12 17:27:22.657 UTC [508] FATAL:  role "root" does not exist
2024-06-12 17:32:22.754 UTC [523] FATAL:  role "root" does not exist
2024-06-12 17:37:22.858 UTC [538] FATAL:  role "root" does not exist
2024-06-12 17:42:22.961 UTC [553] FATAL:  role "root" does not exist
2024-06-12 17:47:23.074 UTC [568] FATAL:  role "root" does not exist
2024-06-12 17:52:23.190 UTC [583] FATAL:  role "root" does not exist
2024-06-12 17:57:23.321 UTC [598] FATAL:  role "root" does not exist
2024-06-12 18:02:23.441 UTC [613] FATAL:  role "root" does not exist
2024-06-12 18:07:23.540 UTC [628] FATAL:  role "root" does not exist
2024-06-12 18:12:23.661 UTC [643] FATAL:  role "root" does not exist
2024-06-12 18:17:23.790 UTC [658] FATAL:  role "root" does not exist
2024-06-12 18:22:23.884 UTC [673] FATAL:  role "root" does not exist
2024-06-12 18:27:24.015 UTC [688] FATAL:  role "root" does not exist
2024-06-12 18:32:24.114 UTC [703] FATAL:  role "root" does not exist
2024-06-12 18:37:24.217 UTC [718] FATAL:  role "root" does not exist
2024-06-12 18:42:24.320 UTC [733] FATAL:  role "root" does not exist
2024-06-12 18:47:24.427 UTC [748] FATAL:  role "root" does not exist
2024-06-12 18:52:24.520 UTC [763] FATAL:  role "root" does not exist
2024-06-12 18:57:24.624 UTC [778] FATAL:  role "root" does not exist
2024-06-12 19:02:24.747 UTC [793] FATAL:  role "root" does not exist
2024-06-12 19:07:24.854 UTC [808] FATAL:  role "root" does not exist
2024-06-12 19:12:24.946 UTC [823] FATAL:  role "root" does not exist
2024-06-12 19:17:25.060 UTC [838] FATAL:  role "root" does not exist
2024-06-12 19:22:25.167 UTC [853] FATAL:  role "root" does not exist
2024-06-12 19:27:25.290 UTC [868] FATAL:  role "root" does not exist
2024-06-12 19:32:25.394 UTC [883] FATAL:  role "root" does not exist
2024-06-12 19:37:25.493 UTC [898] FATAL:  role "root" does not exist
2024-06-12 19:42:25.614 UTC [913] FATAL:  role "root" does not exist
2024-06-12 19:47:25.706 UTC [928] FATAL:  role "root" does not exist
2024-06-12 19:52:25.804 UTC [943] FATAL:  role "root" does not exist
2024-06-12 19:57:25.920 UTC [958] FATAL:  role "root" does not exist
2024-06-12 20:02:26.040 UTC [973] FATAL:  role "root" does not exist
2024-06-12 20:07:26.150 UTC [988] FATAL:  role "root" does not exist
2024-06-12 20:12:26.270 UTC [1003] FATAL:  role "root" does not exist
2024-06-12 20:17:26.380 UTC [1018] FATAL:  role "root" does not exist
2024-06-12 20:20:03.454 UTC [1] LOG:  could not open file "postmaster.pid": No such file or directory
2024-06-12 20:20:03.454 UTC [1] LOG:  performing immediate shutdown because data directory lock file is invalid
2024-06-12 20:20:03.454 UTC [1] LOG:  received immediate shutdown request
2024-06-12 20:20:03.454 UTC [1] LOG:  could not open file "postmaster.pid": No such file or directory
2024-06-12 20:20:03.461 UTC [1] LOG:  database system is shut down

2024-06-12 20:18:06.659 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:18:06.659 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:18:06.659 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:18:06.663 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:18:06.669 UTC [28] LOG:  database system was interrupted; last known up at 2024-06-12 20:16:54 UTC
[2024-06-12T20:18:06Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:18:06Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:18:06Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
[2024-06-12T20:18:06Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 20:18:06.696 UTC [28] LOG:  database system was not properly shut down; automatic recovery in progress
2024-06-12 20:18:06.702 UTC [28] LOG:  redo starts at 0/2F2AB9B8
2024-06-12 20:18:06.702 UTC [28] LOG:  invalid record length at 0/2F2ABFF8: wanted 24, got 0
2024-06-12 20:18:06.702 UTC [28] LOG:  redo done at 0/2F2ABFD0 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2024-06-12 20:18:06.741 UTC [1] LOG:  database system is ready to accept connections
2024-06-12 20:18:36.667 UTC [55] FATAL:  role "root" does not exist
2024-06-12 20:19:55.108 UTC [1] LOG:  received fast shutdown request
2024-06-12 20:19:55.119 UTC [1] LOG:  aborting any active transactions
2024-06-12 20:19:55.121 UTC [1] LOG:  background worker "logical replication launcher" (PID 47) exited with exit code 1
2024-06-12 20:19:55.121 UTC [42] LOG:  shutting down
2024-06-12 20:19:55.144 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:04.028 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:04.028 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:04.028 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:04.033 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:04.038 UTC [27] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:04.039 UTC [27] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:04.039 UTC [27] LOG:  invalid primary checkpoint record
2024-06-12 20:20:04.039 UTC [27] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:04Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:04Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:04Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
[2024-06-12T20:20:04Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 20:20:04.705 UTC [41] FATAL:  the database system is starting up
2024-06-12 20:20:05.129 UTC [1] LOG:  startup process (PID 27) was terminated by signal 6: Aborted
2024-06-12 20:20:05.129 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:05.130 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:05.773 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:05.773 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:05.773 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:05.776 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:05.782 UTC [27] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:05.783 UTC [27] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:05.783 UTC [27] LOG:  invalid primary checkpoint record
2024-06-12 20:20:05.783 UTC [27] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:05Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:05Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:05Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
[2024-06-12T20:20:05Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 20:20:06.053 UTC [41] FATAL:  the database system is starting up
2024-06-12 20:20:06.219 UTC [42] FATAL:  the database system is starting up
2024-06-12 20:20:06.302 UTC [43] FATAL:  the database system is starting up
2024-06-12 20:20:06.917 UTC [1] LOG:  startup process (PID 27) was terminated by signal 6: Aborted
2024-06-12 20:20:06.917 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:06.919 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:07.449 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:07.449 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:07.449 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:07.453 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:07.459 UTC [28] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:07.459 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:07.459 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:07.459 UTC [28] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 20:20:07.806 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:07.807 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:07.807 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:07.810 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:07.816 UTC [27] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:07.816 UTC [27] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:07.816 UTC [27] LOG:  invalid primary checkpoint record
2024-06-12 20:20:07.816 UTC [27] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T20:20:07Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 20:20:08.611 UTC [1] LOG:  startup process (PID 28) was terminated by signal 6: Aborted
2024-06-12 20:20:08.611 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:08.613 UTC [1] LOG:  database system is shut down
2024-06-12 20:20:08.966 UTC [41] FATAL:  the database system is starting up
2024-06-12 20:20:08.981 UTC [42] FATAL:  the database system is starting up
2024-06-12 20:20:09.014 UTC [1] LOG:  startup process (PID 27) was terminated by signal 6: Aborted
2024-06-12 20:20:09.014 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:09.015 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:09.588 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:09.659 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:09.659 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:09.662 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:09.725 UTC [27] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:09.725 UTC [27] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:09.725 UTC [27] LOG:  invalid primary checkpoint record
2024-06-12 20:20:09.725 UTC [27] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:09Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:09Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:09Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T20:20:09Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 20:20:10.871 UTC [1] LOG:  startup process (PID 27) was terminated by signal 6: Aborted
2024-06-12 20:20:10.871 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:10.873 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:10.342 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:10.405 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:10.405 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:10.410 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:10.451 UTC [28] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:10.452 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:10.452 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:10.452 UTC [28] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:10Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:10Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:10Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T20:20:10Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 20:20:10.580 UTC [42] FATAL:  the database system is starting up
2024-06-12 20:20:10.740 UTC [43] FATAL:  the database system is starting up
2024-06-12 20:20:11.063 UTC [44] FATAL:  the database system is starting up
2024-06-12 20:20:11.303 UTC [45] FATAL:  the database system is starting up
2024-06-12 20:20:11.602 UTC [1] LOG:  startup process (PID 28) was terminated by signal 6: Aborted
2024-06-12 20:20:11.602 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:11.603 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:11.939 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:11.939 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:11.939 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:11.943 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:11.949 UTC [28] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:11.949 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:11.949 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:11.949 UTC [28] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:11Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:11Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:11Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
[2024-06-12T20:20:11Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
2024-06-12 20:20:13.013 UTC [1] LOG:  startup process (PID 28) was terminated by signal 6: Aborted
2024-06-12 20:20:13.013 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:13.014 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:13.752 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:13.805 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:13.805 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:13.811 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:13.868 UTC [27] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:13.869 UTC [27] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:13.869 UTC [27] LOG:  invalid primary checkpoint record
2024-06-12 20:20:13.869 UTC [27] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:13Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:13Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:13Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
[2024-06-12T20:20:13Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 20:20:15.026 UTC [1] LOG:  startup process (PID 27) was terminated by signal 6: Aborted
2024-06-12 20:20:15.026 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:15.027 UTC [1] LOG:  database system is shut down

2024-06-12 20:20:14.008 UTC [1] LOG:  starting PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
2024-06-12 20:20:14.009 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2024-06-12 20:20:14.009 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2024-06-12 20:20:14.012 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2024-06-12 20:20:14.018 UTC [28] LOG:  database system was shut down at 2024-06-12 20:19:55 UTC
2024-06-12 20:20:14.018 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:14.018 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:14.018 UTC [28] PANIC:  could not locate a valid checkpoint record
[2024-06-12T20:20:14Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331".
[2024-06-12T20:20:14Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332".
[2024-06-12T20:20:14Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17332/segments/33fe4794-2866-4f9b-ac35-abc1e98e3702".
[2024-06-12T20:20:14Z INFO  service::utils::clean] Find directory "pg_vectors/indexes/17331/segments/bcdf2e1b-94dc-4397-9bff-bbf85e446260".
2024-06-12 20:20:15.149 UTC [1] LOG:  startup process (PID 28) was terminated by signal 6: Aborted
2024-06-12 20:20:15.149 UTC [1] LOG:  aborting startup due to startup process failure
2024-06-12 20:20:15.150 UTC [1] LOG:  database system is shut down
mmomjian commented 4 months ago

There are a few things going on here. Firstly, I believe your database is corrupted, caused by an unclean shutdown around 2024-06-12 20:20:03.454 UTC. Can you restore from backup?

2024-06-12 20:20:07.459 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:07.459 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:07.459 UTC [28] PANIC:  could not locate a valid checkpoint record

To fix the FATAL: role "root" does not exist, can you try implementing the fix in #10221 and report back?

alextran1502 commented 4 months ago

Also you can try to remove the health-check section if the above suggestion doesn't work

image

iamtherobin commented 4 months ago

There are a few things going on here. Firstly, I believe your database is corrupted, caused by an unclean shutdown around 2024-06-12 20:20:03.454 UTC. Can you restore from backup?

2024-06-12 20:20:07.459 UTC [28] LOG:  incorrect resource manager data checksum in record at 0/2F2AC0C0
2024-06-12 20:20:07.459 UTC [28] LOG:  invalid primary checkpoint record
2024-06-12 20:20:07.459 UTC [28] PANIC:  could not locate a valid checkpoint record

To fix the FATAL: role "root" does not exist, can you try implementing the fix in #10221 and report back?

I am pretty much on the same conclusion about the db being corrupted. I don't have a backup so I will have to dump the server a start fresh. It's annoying even though nothing lost since I have all the original data. But it does worry me if I cannot figure out where I went wrong or if the update caused this.

I was already using the change posted in that ticket as of time of posting this ticket. I don't remember if I updated that health check to the compose file before or after the last time the FATAL line shows up in the log since I was attempting a sequence of compose edits to try to get the containers to start again.

I am now noticing that the last time the FATAL line shows up, it is timestamped to fit inside the previous log file, which is interesting.

iamtherobin commented 4 months ago

Ok I THINK I figured out what happened here.

tl;dr: You cannot change the ".env" filename. It seems docker compose does not care what you supply in the env_file: property. It will always load the environment variables from "/.env". It seems the property can be dropped completely from the compose file and it will still read from .env

The fact that the corruption apparently happened in a log file that fits inside the timestamp of the previous log leaves me to believe the database got corrupted due to launching two postgres containers.

When I attempted to update from v1.105 to v1.106 the container was constantly restarting. Likely (but not certain) due to manually changes in the compose file. I attempted the make the yaml changes manually by referencing the new compose file. In hindsight, I should have a pulled a whole new compose file.

Since I started reading about others also having restarting containers with this update, I figured it is probably not my compose file that was the issue but maybe something else. So I thought I would test upgrading v1.105 to v1.106 and see if it would update on a cleanly without the container restarting on a fresh deployment.

To do that I created a new compose yaml file based on v1.105 with separate container names, a new environment file called "old.env" with properties for the v1.105 tag and a new library/postgres location so it would not conflict with my existing one. In the compose file I added "env_file: - old.env" to all the containers with variables. Logically, I assumed if the there is a env_file: property, it would obey it, right? Turns out it just loads the already present ".env" anyways. Which means it just attempted to pull v1.602 again and run it pointed to the same library and database, while using the compose template intended for v1.105.

While I cannot be absolutely certain at this point what actually happened, dual postgres instances pointing to the same database is the only explanation I can think of why one log is stamped to occur inbetween the previous one. It also the same point where the checksum error occurs.

The saving grace here is I deployed immich only a week ago and was still in the process of testing it for exactly this type of quirky situations before actually relying on it for production use (which is why I didn't setup a backup process yet).

I now launched a fresh v1.106.3 and it is working.

jrasm91 commented 4 months ago

Docker compose will read .env and those settings can be used inside the compose file itself. Unrelated if the env_file property which passes the file to the container.