extract metadata almost stuck in v1.109.2

[mschiff]

The bug

I just upgraded to v1.109.2 to make use of #10950 - therefore I started the extract-metadata job on all files (currently only about 60k images).

But after a short while the job is almost stuck and the server load is close to 0, no process eating abnormal cpu time. I write almost because while having the job run for hours and while writing this issue I just noticed one new log like below so I am not really sure if it really stuck or just painfully slow like doing one picture every 10-15 minutes or so and the waiting count for the job is not really decreasing like it was the case in the pre 1.109.0 version I was running before.

The log shows nothing special, but I noticed some WARNings in the logs I had not expected showing Response ... was null

And at lease most of these are places that had a City before and now it seems they have no place at all anymore.

Any idea what might be wrong?

immich_server            | [Nest] 6  - 07/23/2024, 10:48:05 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.0412339666667, longitude: -142.472638966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:05 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.0412339666667, longitude: -142.472638966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:05 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.0412339666667, longitude: -142.472638966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:05 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.0412339666667, longitude: -142.472638966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:05 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.0412379666667, longitude: -142.472653 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:06 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.0412379666667, longitude: -142.472653 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:06 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.041169, longitude: -142.473320966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:06 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.041169, longitude: -142.473320966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:06 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.041169, longitude: -142.473320966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:06 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.041169, longitude: -142.473320966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:07 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.0398449666667, longitude: -142.474613 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:07 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.0398449666667, longitude: -142.474613 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:08 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.039798, longitude: -142.474658 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:08 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.039798, longitude: -142.474658 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:08 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.039798, longitude: -142.474658 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:48:08 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.039798, longitude: -142.474658 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:04 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.7784249666667, longitude: 179.333123966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:04 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.7784249666667, longitude: 179.333123966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:05 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -14.968016, longitude: -147.638422966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:05 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -14.968016, longitude: -147.638422966667 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:06 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.5078759666667, longitude: -145.458435 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:06 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.5078759666667, longitude: -145.458435 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:06 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.778293, longitude: 179.333054 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:08 PM    WARN [Microservices:MapRepository] Response from database for reverse geocoding latitude: -16.0820125, longitude: 145.467412083333 was null
immich_server            | [Nest] 6  - 07/23/2024, 10:50:08 PM    WARN [Microservices:MapRepository] Response from database for natural earth reverse geocoding latitude: -16.0820125, longitude: 145.467412083333 was null

The OS that Immich Server is running on

Gentoo

Version of Immich Server

v1.109.2

Version of Immich Mobile App

none

Platform with the issue

• Server
• Web
• Mobile

Your docker-compose.yml content

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
      - /zdata/images:/mnt/media/images:ro
    env_file:
      - .env
    ports:
      - 2283:3001
    depends_on:
      - redis
      - database
    restart: always

  immich-machine-learning:
    container_name: immich_machine_learning
    # 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
  redis:
    container_name: immich_redis
    image: docker.io/redis:6.2-alpine@sha256:d6c2911ac51b289db208767581a5d154544f2b2fe4914ea5056443f62dc6e900
    healthcheck:
      test: redis-cli ping || exit 1
    restart: always

  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 "ch
ecksum 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

volumes:
  model-cache:

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=./library
UPLOAD_LOCATION=/zdata/images/immich/library
# The location where your database files are stored
DB_DATA_LOCATION=./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=Etc/UTC
TZ=Europe/Berlin

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

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

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

Reproduction steps

1. have some images in external lib
2. start job 'extract metadata'
3. see logs

Relevant log output

No response

Additional information

No response

[alextran1502]

When you say almost stuck, does it eventually processing through?

[mschiff]

When you say almost stuck, does it eventually processing through?

I just had another look after returning home and now its all done! While I was watching it, there was no progress (numbers on the job page did not decrease) for hours, so I was assuming its stuck somewhere.

Now looking at some pictures it seems to be fine. (Though having the same for oceans would be great too ;))

[zebrapurring]

I was able to speed up the metadata extraction by temporarily increasing the maximum number of Exiftool processes in app/node_modules/exiftool-vendored/dist/DefaultMaxProcs.js:

exports.DefaultMaxProcs = Math.max(100, Math.floor(_os.cpus().length / 4));

[zebrapurring]

Also inside app/node_modules/batch-cluster/dist/BatchClusterOptions.js:

        this.minDelayBetweenSpawnMillis = 0;