search

iv-org / invidious

Invidious is an alternative front-end to YouTube
https://invidious.io
GNU Affero General Public License v3.0
16.38k stars 1.83k forks source link

[Bug] Docker compose is currently broken #3578

Closed whereismybugfix closed 1 year ago

whereismybugfix commented 1 year ago

Description

Docker compose method of launching Invidious is broken. At least for me. Both dev and prod docker-compose.yml files aren't functional. The issue seems to be in the DB connection. Even though, Postgres is running, Invidious is failing with DB::ConnectionRefused. I'm gonna continue digging into the issue and at the same time decided to report it here.

Steps to Reproduce

$ git clone https://github.com/iv-org/invidious
$ cd invidious
$ docker compose up

alternatively, it's also broken if I replace docker-compose.yml with the production one from https://docs.invidious.io/installation/#automated-installation, Docker-compose method (production) section.

Logs

Docker ps:

$ docker ps
CONTAINER ID   IMAGE                                COMMAND                  CREATED         STATUS                     PORTS                      NAMES
990fb9d2c8a4   quay.io/invidious/invidious:latest   "/sbin/tini -- /invi…"   2 minutes ago   Up 2 minutes (unhealthy)   127.0.0.1:3000->3000/tcp   invidious-invidious-1
61569c8f6cea   postgres:14                          "docker-entrypoint.s…"   2 minutes ago   Up 2 minutes (healthy)     5432/tcp                   invidious-invidious-db-1

Logs in all their glory:

invidious-invidious-db-1  | 2023-01-19 03:32:27.477 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious-invidious-db-1  | 2023-01-19 03:32:27.477 UTC [1] LOG:  listening on IPv6 address "::", port 5432
invidious-invidious-db-1  | 2023-01-19 03:32:27.492 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-invidious-db-1  | 2023-01-19 03:32:27.518 UTC [82] LOG:  database system was shut down at 2023-01-19 03:32:27 UTC
invidious-invidious-db-1  | 2023-01-19 03:32:27.539 UTC [1] LOG:  database system is ready to accept connections
invidious-invidious-1     | Unhandled exception:  (DB::ConnectionRefused)
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:16:9 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1     | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious-invidious-1     |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1     | Caused by: Error connecting to 'invidious-db:5432': Operation timed out (Socket::ConnectError)
invidious-invidious-1     |   from /usr/share/crystal/src/gc/boehm.cr:192:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1 exited with code 1

Additional context

OS: Ubuntu 22.04 Docker version 20.10.21

unixfox commented 1 year ago

Closing as I can't reproduce this error. Invidious obviously give a DB error at the start but when it is restarted it function well.

The default docker-compose.yml is tested for each new code change so we know it works fine: https://github.com/iv-org/invidious/blob/master/.github/workflows/ci.yml#L96

And the production docker-compose.yml file is being used by all the public instances so we know it works fine: https://instances.invidious.io

Something is probably wrong on your setup.

Details:

Docker compose ps:

NAME                       IMAGE                           COMMAND                  SERVICE             CREATED             STATUS                   PORTS
invidious-invidious-1      invidious-invidious             "/sbin/tini -- /invi…"   invidious           2 minutes ago       Up 2 minutes (healthy)   127.0.0.1:3000->3000/tcp
invidious-invidious-db-1   docker.io/library/postgres:13   "docker-entrypoint.s…"   invidious-db        2 minutes ago       Up 2 minutes (healthy)   5432/tcp

Full logs:

invidious-invidious-db-1  | The files belonging to this database system will be owned by user "postgres".
invidious-invidious-db-1  | This user must also own the server process.
invidious-invidious-db-1  | 
invidious-invidious-db-1  | The database cluster will be initialized with locale "en_US.utf8".
invidious-invidious-db-1  | The default database encoding has accordingly been set to "UTF8".
invidious-invidious-db-1  | The default text search configuration will be set to "english".
invidious-invidious-db-1  | 
invidious-invidious-db-1  | Data page checksums are disabled.
invidious-invidious-db-1  | 
invidious-invidious-db-1  | fixing permissions on existing directory /var/lib/postgresql/data ... ok
invidious-invidious-db-1  | creating subdirectories ... ok
invidious-invidious-db-1  | selecting dynamic shared memory implementation ... posix
invidious-invidious-db-1  | selecting default max_connections ... 100
invidious-invidious-db-1  | selecting default shared_buffers ... 128MB
invidious-invidious-db-1  | selecting default time zone ... Etc/UTC
invidious-invidious-db-1  | creating configuration files ... ok
invidious-invidious-db-1  | running bootstrap script ... ok
invidious-invidious-db-1  | performing post-bootstrap initialization ... ok
invidious-invidious-db-1  | syncing data to disk ... ok
invidious-invidious-db-1  | 
invidious-invidious-db-1  | initdb: warning: enabling "trust" authentication for local connections
invidious-invidious-db-1  | You can change this by editing pg_hba.conf or using the option -A, or
invidious-invidious-db-1  | --auth-local and --auth-host, the next time you run initdb.
invidious-invidious-db-1  | 
invidious-invidious-db-1  | Success. You can now start the database server using:
invidious-invidious-db-1  | 
invidious-invidious-db-1  |     pg_ctl -D /var/lib/postgresql/data -l logfile start
invidious-invidious-db-1  | 
invidious-invidious-db-1  | waiting for server to start....2023-01-19 11:37:54.274 UTC [47] LOG:  starting PostgreSQL 13.9 (Debian 13.9-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-invidious-db-1  | 2023-01-19 11:37:54.277 UTC [47] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-invidious-db-1  | 2023-01-19 11:37:54.287 UTC [48] LOG:  database system was shut down at 2023-01-19 11:37:54 UTC
invidious-invidious-db-1  | 2023-01-19 11:37:54.294 UTC [47] LOG:  database system is ready to accept connections
invidious-invidious-db-1  |  done
invidious-invidious-db-1  | server started
invidious-invidious-db-1  | CREATE DATABASE
invidious-invidious-db-1  | 
invidious-invidious-db-1  | 
invidious-invidious-db-1  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init-invidious-db.sh
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE INDEX
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE TYPE
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | CREATE TABLE
invidious-invidious-db-1  | GRANT
invidious-invidious-db-1  | 
invidious-invidious-db-1  | waiting for server to shut down....2023-01-19 11:37:55.234 UTC [47] LOG:  received fast shutdown request
invidious-invidious-db-1  | 2023-01-19 11:37:55.236 UTC [47] LOG:  aborting any active transactions
invidious-invidious-db-1  | 2023-01-19 11:37:55.238 UTC [47] LOG:  background worker "logical replication launcher" (PID 54) exited with exit code 1
invidious-invidious-db-1  | 2023-01-19 11:37:55.244 UTC [49] LOG:  shutting down
invidious-invidious-db-1  | 2023-01-19 11:37:55.282 UTC [47] LOG:  database system is shut down
invidious-invidious-db-1  |  done
invidious-invidious-db-1  | server stopped
invidious-invidious-db-1  | 
invidious-invidious-db-1  | PostgreSQL init process complete; ready for start up.
invidious-invidious-db-1  | 
invidious-invidious-db-1  | 2023-01-19 11:37:55.371 UTC [1] LOG:  starting PostgreSQL 13.9 (Debian 13.9-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-invidious-db-1  | 2023-01-19 11:37:55.371 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious-invidious-db-1  | 2023-01-19 11:37:55.371 UTC [1] LOG:  listening on IPv6 address "::", port 5432
invidious-invidious-db-1  | 2023-01-19 11:37:55.968 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-invidious-db-1  | 2023-01-19 11:37:55.980 UTC [81] LOG:  database system was shut down at 2023-01-19 11:37:55 UTC
invidious-invidious-db-1  | 2023-01-19 11:37:55.988 UTC [1] LOG:  database system is ready to accept connections
invidious-invidious-1     | Unhandled exception:  (DB::ConnectionRefused)
invidious-invidious-1     |   from lib/db/src/db/connection.cr:34 in 'initialize'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious-invidious-1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:40:5 in 'new:initial_pool_size:max_pool_size:max_idle_pool_size:checkout_timeout:retry_attempts:retry_delay'
invidious-invidious-1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious-invidious-1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious-invidious-1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '~PG_DB:init'
invidious-invidious-1     |   from src/invidious.cr:63:1 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main_user_code'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:101:7 in 'main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:127:3 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1     | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious-invidious-1     |   from lib/pg/src/pq/connection.cr:34:9 in 'initialize'
invidious-invidious-1     |   from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious-invidious-1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:40:5 in 'new:initial_pool_size:max_pool_size:max_idle_pool_size:checkout_timeout:retry_attempts:retry_delay'
invidious-invidious-1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious-invidious-1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious-invidious-1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '~PG_DB:init'
invidious-invidious-1     |   from src/invidious.cr:63:1 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main_user_code'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:101:7 in 'main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:127:3 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1     | Caused by: Error connecting to 'invidious-db:5432': Connection refused (Socket::ConnectError)
invidious-invidious-1     |   from /usr/share/crystal/src/socket/addrinfo.cr:67:17 in 'initialize'
invidious-invidious-1     |   from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'initialize'
invidious-invidious-1     |   from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'new'
invidious-invidious-1     |   from lib/pg/src/pq/connection.cr:30:17 in 'initialize'
invidious-invidious-1     |   from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious-invidious-1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious-invidious-1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious-invidious-1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:214:27 in 'build_resource'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/pool.cr:40:5 in 'new:initial_pool_size:max_pool_size:max_idle_pool_size:checkout_timeout:retry_attempts:retry_delay'
invidious-invidious-1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious-invidious-1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious-invidious-1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious-invidious-1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious-invidious-1     |   from src/invidious.cr:62:15 in '~PG_DB:init'
invidious-invidious-1     |   from src/invidious.cr:63:1 in '__crystal_main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:115:5 in 'main_user_code'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:101:7 in 'main'
invidious-invidious-1     |   from /usr/share/crystal/src/crystal/main.cr:127:3 in 'main'
invidious-invidious-1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-invidious-1     | [development] Invidious is ready to lead at http://0.0.0.0:3000
invidious-invidious-1     | 2023-01-19 11:37:56 UTC [info] jobs: running ClearExpiredItems job
invidious-invidious-1     | 2023-01-19 11:37:56 UTC [info] jobs: ClearExpiredItems done.
invidious-invidious-1     | 2023-01-19 11:38:27 UTC [info] 200 GET /api/v1/comments/jNQXAC9IVRw 353.98ms
whereismybugfix commented 1 year ago

Hey, @unixfox. Thanks for that! I'll try to play around it this way.

unixfox commented 1 year ago

Now I've looked at your docker containers running I should point out that you should use postgres 13 and not 14. See https://github.com/iv-org/invidious/issues/2938

whereismybugfix commented 1 year ago

Ewww, that can be the thing. Postgres 14 comes from https://docs.invidious.io/installation/#docker-compose-method-production where it's mentioned in recommended docker-compose file - docker.io/library/postgres:14