Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

[Bug] Weirdness with Postgres 14 #2938

Open
JackHewson opened this issue Feb 25, 2022 · 24 comments · Fixed by #2939
Open

[Bug] Weirdness with Postgres 14 #2938

JackHewson opened this issue Feb 25, 2022 · 24 comments · Fixed by #2939
Assignees
@TheFrenchGhosty
Labels
bug Something isn't working exempt-stale Exempt the issue from staling

Comments

@JackHewson
Copy link

Describe the bug
The recent commit (Feb 25, 2022) on a fresh installed docker environment (no existing images/volumes there) fails with this error message:
Error connecting to 'invidious-db:5432': Connection refused (Socket::ConnectError)

Steps to Reproduce

  1. git clone https://github.com/iv-org/invidious.git
  2. change to directory invidious, and run docker-compose up

Logs

invidious-db_1  | PostgreSQL init process complete; ready for start up.
invidious-db_1  |
invidious-db_1  | 2022-02-25 09:28:42.665 UTC [1] LOG:  starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-db_1  | 2022-02-25 09:28:42.671 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious-db_1  | 2022-02-25 09:28:42.671 UTC [1] LOG:  listening on IPv6 address "::", port 5432
invidious-db_1  | 2022-02-25 09:28:42.676 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-db_1  | 2022-02-25 09:28:42.680 UTC [80] LOG:  database system was shut down at 2022-02-25 09:28:42 UTC
invidious-db_1  | 2022-02-25 09:28:42.686 UTC [1] LOG:  database system is ready to accept connections
invidious_1     |   from lib/db/src/db/connection.cr:34:0 in 'initialize'
invidious_1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious_1     |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious_1     |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1     |   from src/invidious.cr:44:1 in '__crystal_main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1     | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious_1     |   from lib/pg/src/pq/connection.cr:34:9 in 'initialize'
invidious_1     |   from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1     |   from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious_1     |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious_1     |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1     |   from src/invidious.cr:44:1 in '__crystal_main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1     | Caused by: Error connecting to 'invidious-db:5432': Connection refused (Socket::ConnectError)
@JackHewson JackHewson added the bug Something isn't working label Feb 25, 2022
@unixfox
Copy link
Member

unixfox commented Feb 25, 2022

Please see #2933

@unixfox unixfox closed this as completed Feb 25, 2022
@JackHewson
Copy link
Author

@unixfox Thanks. But in my opinion, this issue is different from #2933. There is no existing installation, no database to migrate. It is just the last development version, which doesn't run.

@MathiusD
Copy link
Contributor

@unixfox Thanks. But in my opinion, this issue is different from #2933. There is no existing installation, no database to migrate. It is just the last development version, which doesn't run.

I agree with you. I had the same issue last night using the new docker-compose and after clearing the postgres volume when I was working on some PR [But with same compose structuration and postgres 10 (and clear volumes ofc) instead 14, it works])

@SamantazFox SamantazFox reopened this Feb 25, 2022
@SamantazFox
Copy link
Member

@MathiusD @JackHewson could you try with postgres 13 instead?

@MathiusD
Copy link
Contributor

@MathiusD @JackHewson could you try with postgres 13 instead?

I'm testing this as soon as possible (My laptop is out of battery and charging it on the bus is not the easiest thing ^^')

@martadinata666
Copy link

martadinata666 commented Feb 25, 2022 •
edited by SamantazFox
Loading

Test from clean out of curiousity, it works. it throws error first because DB not exist/created yet, then it created. Invidious connect after that

Docker Logs (click to expand) 
[+] Running 3/0
 ⠿ Container invidious1-apache-1    Created                                                                                                                                                                                            0.0s
 ⠿ Container invidious1-postgres-1  Created                                                                                                                                                                                            0.0s
 ⠿ Container invidious1-app-1       Created                                                                                                                                                                                            0.0s
Attaching to invidious1-apache-1, invidious1-app-1, invidious1-postgres-1
invidious1-postgres-1  | chmod: changing permissions of '/var/run/postgresql': Operation not permitted
invidious1-postgres-1  | The files belonging to this database system will be owned by user "postgres".
invidious1-postgres-1  | This user must also own the server process.
invidious1-postgres-1  | 
invidious1-postgres-1  | The database cluster will be initialized with locale "en_US.utf8".
invidious1-postgres-1  | The default database encoding has accordingly been set to "UTF8".
invidious1-postgres-1  | The default text search configuration will be set to "english".
invidious1-postgres-1  | 
invidious1-postgres-1  | Data page checksums are disabled.
invidious1-postgres-1  | 
invidious1-postgres-1  | fixing permissions on existing directory /var/lib/postgresql/data ... ok
invidious1-postgres-1  | creating subdirectories ... ok
invidious1-postgres-1  | selecting dynamic shared memory implementation ... posix
invidious1-postgres-1  | selecting default max_connections ... 100
invidious1-postgres-1  | selecting default shared_buffers ... 128MB
invidious1-postgres-1  | selecting default time zone ... Asia/Jakarta
invidious1-postgres-1  | creating configuration files ... ok
invidious1-apache-1    | AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.18.0.2. Set the 'ServerName' directive globally to suppress this message
invidious1-apache-1    | httpd (pid 10) already running
invidious1-postgres-1  | running bootstrap script ... ok
invidious1-apache-1 exited with code 0
invidious1-postgres-1  | performing post-bootstrap initialization ... ok
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-postgres-1  | syncing data to disk ... ok
invidious1-postgres-1  | 
invidious1-postgres-1  | 
invidious1-postgres-1  | Success. You can now start the database server using:
invidious1-postgres-1  | 
invidious1-postgres-1  |     pg_ctl -D /var/lib/postgresql/data -l logfile start
invidious1-postgres-1  | 
invidious1-postgres-1  | initdb: warning: enabling "trust" authentication for local connections
invidious1-postgres-1  | You can change this by editing pg_hba.conf or using the option -A, or
invidious1-postgres-1  | --auth-local and --auth-host, the next time you run initdb.
invidious1-postgres-1  | waiting for server to start....2022-02-25 19:59:54.112 WIB [41] LOG:  starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious1-postgres-1  | 2022-02-25 19:59:54.115 WIB [41] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-postgres-1  | 2022-02-25 19:59:54.406 WIB [42] LOG:  database system was shut down at 2022-02-25 19:59:47 WIB
invidious1-postgres-1  | 2022-02-25 19:59:54.540 WIB [41] LOG:  database system is ready to accept connections
invidious1-postgres-1  |  done
invidious1-postgres-1  | server started
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-postgres-1  | 2022-02-25 20:00:17.263 WIB [62] FATAL:  database "invidious" does not exist
invidious1-app-1       | Unhandled exception:  (DB::ConnectionRefused)
invidious1-app-1       |   from lib/sqlite3/src/sqlite3/connection.cr:10:11 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious1-app-1       |   from lib/pg/src/pq/connection.cr:34:9 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1       | Caused by: Error connecting to 'postgres:5432': Connection refused (Socket::ConnectError)
invidious1-app-1       |   from /usr/share/crystal/src/gc/boehm.cr:163:5 in 'new'
invidious1-app-1       |   from lib/pg/src/pg/connection.cr:13:23 in '->'
invidious1-app-1       |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious1-app-1       |   from /usr/share/crystal/src/int.cr:525:11 in 'build_database'
invidious1-app-1       |   from src/invidious.cr:43:15 in '__crystal_main'
invidious1-app-1       |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main'
invidious1-app-1       |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious1-app-1 exited with code 1
invidious1-postgres-1  | CREATE DATABASE
invidious1-postgres-1  | 
invidious1-postgres-1  | 
invidious1-postgres-1  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init-invidious-db.sh
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE INDEX
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE TYPE
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | CREATE TABLE
invidious1-postgres-1  | GRANT
invidious1-postgres-1  | 
invidious1-postgres-1  | 2022-02-25 20:00:34.912 WIB [41] LOG:  received fast shutdown request
invidious1-postgres-1  | waiting for server to shut down....2022-02-25 20:00:35.052 WIB [41] LOG:  aborting any active transactions
invidious1-postgres-1  | 2022-02-25 20:00:35.053 WIB [41] LOG:  background worker "logical replication launcher" (PID 48) exited with exit code 1
invidious1-postgres-1  | 2022-02-25 20:00:35.053 WIB [43] LOG:  shutting down
invidious1-postgres-1  | ....2022-02-25 20:00:39.868 WIB [41] LOG:  database system is shut down
invidious1-postgres-1  |  done
invidious1-postgres-1  | server stopped
invidious1-postgres-1  | 
invidious1-postgres-1  | PostgreSQL init process complete; ready for start up.
invidious1-postgres-1  | 
invidious1-postgres-1  | 2022-02-25 20:00:40.226 WIB [1] LOG:  starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious1-postgres-1  | 2022-02-25 20:00:40.226 WIB [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious1-postgres-1  | 2022-02-25 20:00:40.226 WIB [1] LOG:  listening on IPv6 address "::", port 5432
invidious1-postgres-1  | 2022-02-25 20:00:40.332 WIB [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious1-postgres-1  | 2022-02-25 20:00:40.608 WIB [83] LOG:  database system was shut down at 2022-02-25 20:00:39 WIB
invidious1-postgres-1  | 2022-02-25 20:00:40.677 WIB [1] LOG:  database system is ready to accept connections
invidious1-app-1       | [production] Invidious is ready to lead at http://0.0.0.0:3000

@unixfox
Copy link
Member

unixfox commented Feb 25, 2022

@JackHewson
Can you use the production docker-compose instead: https://docs.invidious.io/Installation.md?

@JackHewson
Copy link
Author

@unixfox Yes, the production docker-compose works fine.
But for this issue, I wanted to run the development docker-compose version, based on the development sources.

@unixfox
Copy link
Member

unixfox commented Feb 25, 2022 •
edited
Loading

Oh right sorry I didn't know that.

If you have nothing on docker you should stop everything in docker (you can use docker-compose down) then do docker system -a.

Then try docker-compose up -d.

@TheFrenchGhosty TheFrenchGhosty self-assigned this Feb 25, 2022
@TheFrenchGhosty
Copy link
Member

TheFrenchGhosty commented Feb 25, 2022 •
edited
Loading

Found the issue (I think) I forgot to edit the dockerfile, that has a sed to replace the hostname of the DB: https://github.com/iv-org/invidious/blob/master/docker/Dockerfile#L45

@MathiusD
Copy link
Contributor

MathiusD commented Feb 25, 2022 •
edited
Loading

@MathiusD @JackHewson could you try with postgres 13 instead?

@SamantazFox

Sorry for the delay. Here are the results of the tests with the docker-compose of master where I alter only the version of postgres :

10, 11, 12 and 13 : no issues encoutered

And for the 14, postgres does not encounter any problem, however the invidious container never manages to finalize its startup (I'm currently looking at what stage it remains blocked to eat 100% of my processor)

(Note: during each tests I have no pre-existing volume or any other container running)

Edited :

After having debugged to see what was the blocking step it is well the connection to the DB (And followings logs in postgres confirms : 2022-02-25 17:55:32.300 UTC [37] FATAL: canceling authentication due to timeout)

TheFrenchGhosty added a commit that referenced this issue Feb 25, 2022
@TheFrenchGhosty
Fix the Dockerfile sed command (Closes #2938)
7dcd503
@TheFrenchGhosty
Copy link
Member

TheFrenchGhosty commented Feb 25, 2022 •
edited by SamantazFox
Loading

Okay, something is really wrong: there's 0 problem with Postgres 13 but Invidious doesn't try to reconnect with Postgres 14.

Exact same setup (both running #2938 )

It should work, but it doesn't. Even though Postgres 14 works in production...

This is Postgres 13:

Docker Logs (click to expand) 
Creating invidious_invidious-db_1 ... done
Creating invidious_invidious_1    ... done
Attaching to invidious_invidious-db_1, invidious_invidious_1
invidious-db_1  | The files belonging to this database system will be owned by user "postgres".
invidious-db_1  | This user must also own the server process.
invidious-db_1  | 
invidious-db_1  | The database cluster will be initialized with locale "en_US.utf8".
invidious-db_1  | The default database encoding has accordingly been set to "UTF8".
invidious-db_1  | The default text search configuration will be set to "english".
invidious-db_1  | 
invidious-db_1  | Data page checksums are disabled.
invidious-db_1  | 
invidious-db_1  | fixing permissions on existing directory /var/lib/postgresql/data ... ok
invidious-db_1  | creating subdirectories ... ok
invidious-db_1  | selecting dynamic shared memory implementation ... posix
invidious-db_1  | selecting default max_connections ... 100
invidious-db_1  | selecting default shared_buffers ... 128MB
invidious-db_1  | selecting default time zone ... Etc/UTC
invidious-db_1  | creating configuration files ... ok
invidious-db_1  | running bootstrap script ... ok
invidious_1     | Unhandled exception:  (DB::ConnectionRefused)
invidious-db_1  | performing post-bootstrap initialization ... ok
invidious-db_1  | syncing data to disk ... initdb: warning: enabling "trust" authentication for local connections
invidious-db_1  | You can change this by editing pg_hba.conf or using the option -A, or
invidious-db_1  | --auth-local and --auth-host, the next time you run initdb.
invidious-db_1  | ok
invidious-db_1  | 
invidious-db_1  | 
invidious-db_1  | Success. You can now start the database server using:
invidious-db_1  | 
invidious-db_1  |     pg_ctl -D /var/lib/postgresql/data -l logfile start
invidious-db_1  | 
invidious-db_1  | waiting for server to start....2022-02-25 18:22:10.876 UTC [48] LOG:  starting PostgreSQL 13.6 (Debian 13.6-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-db_1  | 2022-02-25 18:22:10.878 UTC [48] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-db_1  | 2022-02-25 18:22:10.884 UTC [49] LOG:  database system was shut down at 2022-02-25 18:22:10 UTC
invidious-db_1  | 2022-02-25 18:22:10.890 UTC [48] LOG:  database system is ready to accept connections
invidious-db_1  |  done
invidious-db_1  | server started
invidious-db_1  | CREATE DATABASE
invidious-db_1  | 
invidious-db_1  | 
invidious-db_1  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init-invidious-db.sh
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE INDEX
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE TYPE
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | CREATE TABLE
invidious-db_1  | GRANT
invidious-db_1  | 
invidious-db_1  | 2022-02-25 18:22:11.555 UTC [48] LOG:  received fast shutdown request
invidious-db_1  | waiting for server to shut down....2022-02-25 18:22:11.557 UTC [48] LOG:  aborting any active transactions
invidious-db_1  | 2022-02-25 18:22:11.558 UTC [48] LOG:  background worker "logical replication launcher" (PID 55) exited with exit code 1
invidious-db_1  | 2022-02-25 18:22:11.559 UTC [50] LOG:  shutting down
invidious-db_1  | 2022-02-25 18:22:11.576 UTC [48] LOG:  database system is shut down
invidious-db_1  |  done
invidious-db_1  | server stopped
invidious-db_1  | 
invidious-db_1  | PostgreSQL init process complete; ready for start up.
invidious-db_1  | 
invidious-db_1  | 2022-02-25 18:22:11.671 UTC [1] LOG:  starting PostgreSQL 13.6 (Debian 13.6-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-db_1  | 2022-02-25 18:22:11.671 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious-db_1  | 2022-02-25 18:22:11.671 UTC [1] LOG:  listening on IPv6 address "::", port 5432
invidious-db_1  | 2022-02-25 18:22:11.674 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-db_1  | 2022-02-25 18:22:11.678 UTC [81] LOG:  database system was shut down at 2022-02-25 18:22:11 UTC
invidious-db_1  | 2022-02-25 18:22:11.684 UTC [1] LOG:  database system is ready to accept connections
invidious_1     |   from lib/db/src/db/connection.cr:34:0 in 'initialize'
invidious_1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious_1     |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious_1     |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1     |   from src/invidious.cr:44:1 in '__crystal_main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1     | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious_1     |   from lib/pg/src/pq/connection.cr:34:9 in 'initialize'
invidious_1     |   from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1     |   from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious_1     |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious_1     |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1     |   from src/invidious.cr:44:1 in '__crystal_main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1     | Caused by: Error connecting to 'invidious-db:5432': Connection refused (Socket::ConnectError)
invidious_1     |   from /usr/share/crystal/src/socket/addrinfo.cr:67:17 in 'initialize'
invidious_1     |   from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'initialize'
invidious_1     |   from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'new'
invidious_1     |   from lib/pg/src/pq/connection.cr:30:17 in 'initialize'
invidious_1     |   from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1     |   from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1     |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1     |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1     |   from lib/db/src/db/database.cr:57:16 in '->'
invidious_1     |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1     |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1     |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1     |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1     |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1     |   from lib/db/src/db.cr:119:5 in 'open'
invidious_1     |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1     |   from src/invidious.cr:44:1 in '__crystal_main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1     |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1     |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1     | [development] Invidious is ready to lead at http://0.0.0.0:3000
invidious_1     | 2022-02-25 18:22:21 UTC [info] 302 GET / 791.59µs
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /feed/popular 1.25ms
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /css/pure-min.css?v=31699468 831.27µs
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /css/grids-responsive-min.css?v=31699468 367.16µs
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /css/ionicons.min.css?v=31699468 1.4ms
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /css/default.css?v=31699468 500.3µs
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /js/handlers.js?v=31699468 339.6µs
invidious_1     | 2022-02-25 18:22:21 UTC [info] 200 GET /js/themes.js?v=31699468 273.71µs
invidious_1     | 2022-02-25 18:22:22 UTC [info] 200 GET /fonts/ionicons.woff2?v=4.6.3 299.97µs
invidious_1     | 2022-02-25 18:22:22 UTC [info] 200 GET /apple-touch-icon.png?v=31699468 233.94µs
invidious_1     | 2022-02-25 18:22:22 UTC [info] 200 GET /favicon-16x16.png?v=31699468 248.54µs
invidious_1     | 2022-02-25 18:22:43 UTC [info] 200 GET /api/v1/comments/jNQXAC9IVRw 203.85ms
invidious_1     | 2022-02-25 18:23:13 UTC [info] 200 GET /api/v1/comments/jNQXAC9IVRw 163.75ms
invidious_1     | 2022-02-25 18:23:43 UTC [info] 200 GET /api/v1/comments/jNQXAC9IVRw 181.11ms

@martadinata666
Copy link 

[+] Running 2/0
 ⠿ Container invidious-db-1   Created                                                                                                                                                                                                  0.0s
 ⠿ Container invidious-app-1  Created                                                                                                                                                                                                  0.0s
Attaching to invidious-app-1, invidious-db-1
invidious-db-1   | chmod: changing permissions of '/var/run/postgresql': Operation not permitted
invidious-db-1   | 
invidious-db-1   | PostgreSQL Database directory appears to contain a database; Skipping initialization
invidious-db-1   | 
invidious-db-1   | 2022-02-25 18:22:48.759 UTC [1] LOG:  starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidious-db-1   | 2022-02-25 18:22:48.759 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
invidious-db-1   | 2022-02-25 18:22:48.759 UTC [1] LOG:  listening on IPv6 address "::", port 5432
invidious-db-1   | 2022-02-25 18:22:49.672 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-db-1   | 2022-02-25 18:22:52.448 UTC [14] LOG:  database system was shut down at 2022-02-25 18:20:59 UTC
invidious-db-1   | 2022-02-25 18:22:52.449 UTC [15] FATAL:  the database system is starting up
invidious-app-1  | Unhandled exception:  (DB::ConnectionRefused)
invidious-db-1   | 2022-02-25 18:22:52.573 UTC [1] LOG:  database system is ready to accept connections
invidious-app-1  |   from lib/db/src/db/connection.cr:34:0 in 'initialize'
invidious-app-1  |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious-app-1  |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious-app-1  |   from lib/db/src/db/database.cr:57:16 in '->'
invidious-app-1  |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious-app-1  |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
invidious-app-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-app-1  |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious-app-1  |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious-app-1  |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious-app-1  |   from lib/db/src/db.cr:119:5 in 'open'
invidious-app-1  |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious-app-1  |   from src/invidious.cr:44:1 in '__crystal_main'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious-app-1  |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-app-1  | Caused by: the database system is starting up (PQ::PQError)
invidious-app-1  |   from lib/pg/src/pq/connection.cr:203:7 in 'handle_error'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:186:7 in 'handle_async_frames'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:162:7 in 'read'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:157:7 in 'read'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:414:31 in 'expect_frame'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:413:5 in 'expect_frame'
invidious-app-1  |   from lib/pg/src/pq/connection.cr:242:20 in 'connect'
invidious-app-1  |   from lib/pg/src/pg/connection.cr:14:9 in 'initialize'
invidious-app-1  |   from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious-app-1  |   from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious-app-1  |   from lib/db/src/db/database.cr:57:16 in '->'
invidious-app-1  |   from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious-app-1  |   from lib/db/src/db/pool.cr:47:34 in 'initialize'
invidious-app-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-app-1  |   from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious-app-1  |   from lib/db/src/db/database.cr:49:5 in 'new'
invidious-app-1  |   from lib/db/src/db.cr:155:5 in 'build_database'
invidious-app-1  |   from lib/db/src/db.cr:119:5 in 'open'
invidious-app-1  |   from src/invidious.cr:43:15 in '~PG_DB:init'
invidious-app-1  |   from src/invidious.cr:44:1 in '__crystal_main'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious-app-1  |   from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious-app-1  |   from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious-app-1 exited with code 1
invidious-app-1  | Invalid memory access (signal 11) at address 0x7fb6e6945000
invidious-app-1  | [0x7fb6e853b296] ???
invidious-app-1  | [0x7fb6e8401bca] ???
invidious-app-1  | [0x7fb6e91dcf55] ???
invidious-app-1 exited with code 11

This black magic, dunno what happen

@TheFrenchGhosty TheFrenchGhosty mentioned this issue Feb 25, 2022
Merged
@TheFrenchGhosty
Copy link
Member

TheFrenchGhosty commented Feb 25, 2022 •
edited
Loading

Re-opening since there's definitely a problem with Postgres 14

I suspect adding a wait time before initialization might fix it.

@TheFrenchGhosty TheFrenchGhosty changed the title [Bug] Recent commit (Feb 25, 2022) and (local) docker: Error connecting to 'invidious-db:5432': Connection refused (Socket::ConnectError) [Bug] Weirdness with Postgres 14 Feb 25, 2022
@SamantazFox
Copy link
Member

@TheFrenchGhosty or we could simply go back to Postgres 13 while we figure it out.

@TheFrenchGhosty
Copy link
Member

@SamantazFox Postgres 14 works in production the problem is only when running the development compose

@TheFrenchGhosty
Copy link
Member

TheFrenchGhosty commented Feb 25, 2022 •
edited
Loading

I've been trying stuff for the last hour or so... I just don't get what's the issue. For whatever reason Invidious can't connect to Postgres 14 (or doesn't retry after it fails), but has no problem with Postgres 13.

It doesn't make ANY sense.

Here some logs, where the only difference is the Postgres version (I renamed the DB so the name is normal).

Postgres 14:

Docker Logs (click to expand)

Creating invidiousdb ... done
Creating invidious_invidious_1 ... done
Attaching to invidiousdb, invidious_invidious_1
invidiousdb | The files belonging to this database system will be owned by user "postgres".
invidiousdb | This user must also own the server process.
invidiousdb |
invidiousdb | The database cluster will be initialized with locale "en_US.utf8".
invidiousdb | The default database encoding has accordingly been set to "UTF8".
invidiousdb | The default text search configuration will be set to "english".
invidiousdb |
invidiousdb | Data page checksums are disabled.
invidiousdb |
invidiousdb | fixing permissions on existing directory /var/lib/postgresql/data ... ok
invidiousdb | creating subdirectories ... ok
invidiousdb | selecting dynamic shared memory implementation ... posix
invidiousdb | selecting default max_connections ... 100
invidiousdb | selecting default shared_buffers ... 128MB
invidiousdb | selecting default time zone ... Etc/UTC
invidiousdb | creating configuration files ... ok
invidiousdb | running bootstrap script ... ok
invidious_1 | Unhandled exception: (DB::ConnectionRefused)
invidiousdb | performing post-bootstrap initialization ... ok
invidiousdb | syncing data to disk ... initdb: warning: enabling "trust" authentication for local connections
invidiousdb | You can change this by editing pg_hba.conf or using the option -A, or
invidiousdb | --auth-local and --auth-host, the next time you run initdb.
invidiousdb | ok
invidiousdb |
invidiousdb |
invidiousdb | Success. You can now start the database server using:
invidiousdb |
invidiousdb | pg_ctl -D /var/lib/postgresql/data -l logfile start
invidiousdb |
invidiousdb | waiting for server to start....2022-02-25 19:40:27.364 UTC [48] LOG: starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidiousdb | 2022-02-25 19:40:27.365 UTC [48] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidiousdb | 2022-02-25 19:40:27.370 UTC [49] LOG: database system was shut down at 2022-02-25 19:40:27 UTC
invidiousdb | 2022-02-25 19:40:27.374 UTC [48] LOG: database system is ready to accept connections
invidiousdb | done
invidiousdb | server started
invidiousdb | CREATE DATABASE
invidiousdb |
invidiousdb |
invidiousdb | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init-invidious-db.sh
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE TYPE
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb |
invidiousdb | 2022-02-25 19:40:28.123 UTC [48] LOG: received fast shutdown request
invidiousdb | waiting for server to shut down....2022-02-25 19:40:28.124 UTC [48] LOG: aborting any active transactions
invidiousdb | 2022-02-25 19:40:28.125 UTC [48] LOG: background worker "logical replication launcher" (PID 55) exited with exit code 1
invidiousdb | 2022-02-25 19:40:28.125 UTC [50] LOG: shutting down
invidiousdb | 2022-02-25 19:40:28.144 UTC [48] LOG: database system is shut down
invidiousdb | done
invidiousdb | server stopped
invidiousdb |
invidiousdb | PostgreSQL init process complete; ready for start up.
invidiousdb |
invidiousdb | 2022-02-25 19:40:28.240 UTC [1] LOG: starting PostgreSQL 14.2 (Debian 14.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidiousdb | 2022-02-25 19:40:28.240 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
invidiousdb | 2022-02-25 19:40:28.240 UTC [1] LOG: listening on IPv6 address "::", port 5432
invidiousdb | 2022-02-25 19:40:28.243 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidiousdb | 2022-02-25 19:40:28.247 UTC [81] LOG: database system was shut down at 2022-02-25 19:40:28 UTC
invidiousdb | 2022-02-25 19:40:28.254 UTC [1] LOG: database system is ready to accept connections
invidious_1 | from lib/db/src/db/connection.cr:34:0 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1 | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious_1 | from lib/pg/src/pq/connection.cr:34:9 in 'initialize'
invidious_1 | from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1 | from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1 | Caused by: Error connecting to 'invidiousdb:5432': Connection refused (Socket::ConnectError)
invidious_1 | from /usr/share/crystal/src/socket/addrinfo.cr:67:17 in 'initialize'
invidious_1 | from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'initialize'
invidious_1 | from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'new'
invidious_1 | from lib/pg/src/pq/connection.cr:30:17 in 'initialize'
invidious_1 | from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1 | from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'

Postgres 13:

Docker Logs (click to expand)

Creating invidiousdb ... done
Creating invidious_invidious_1 ... done
Attaching to invidiousdb, invidious_invidious_1
invidiousdb | The files belonging to this database system will be owned by user "postgres".
invidiousdb | This user must also own the server process.
invidiousdb |
invidiousdb | The database cluster will be initialized with locale "en_US.utf8".
invidiousdb | The default database encoding has accordingly been set to "UTF8".
invidiousdb | The default text search configuration will be set to "english".
invidiousdb |
invidiousdb | Data page checksums are disabled.
invidiousdb |
invidiousdb | fixing permissions on existing directory /var/lib/postgresql/data ... ok
invidiousdb | creating subdirectories ... ok
invidiousdb | selecting dynamic shared memory implementation ... posix
invidiousdb | selecting default max_connections ... 100
invidiousdb | selecting default shared_buffers ... 128MB
invidiousdb | selecting default time zone ... Etc/UTC
invidiousdb | creating configuration files ... ok
invidiousdb | running bootstrap script ... ok
invidious_1 | Unhandled exception: (DB::ConnectionRefused)
invidiousdb | performing post-bootstrap initialization ... ok
invidiousdb | syncing data to disk ... ok
invidiousdb |
invidiousdb |
invidiousdb | Success. You can now start the database server using:
invidiousdb |
invidiousdb | pg_ctl -D /var/lib/postgresql/data -l logfile start
invidiousdb |
invidiousdb | initdb: warning: enabling "trust" authentication for local connections
invidiousdb | You can change this by editing pg_hba.conf or using the option -A, or
invidiousdb | --auth-local and --auth-host, the next time you run initdb.
invidiousdb | waiting for server to start....2022-02-25 19:41:51.197 UTC [48] LOG: starting PostgreSQL 13.6 (Debian 13.6-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidiousdb | 2022-02-25 19:41:51.198 UTC [48] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidiousdb | 2022-02-25 19:41:51.204 UTC [49] LOG: database system was shut down at 2022-02-25 19:41:51 UTC
invidiousdb | 2022-02-25 19:41:51.208 UTC [48] LOG: database system is ready to accept connections
invidiousdb | done
invidiousdb | server started
invidiousdb | CREATE DATABASE
invidiousdb |
invidiousdb |
invidiousdb | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/init-invidious-db.sh
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE INDEX
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE TYPE
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb | CREATE TABLE
invidiousdb | GRANT
invidiousdb |
invidiousdb | 2022-02-25 19:41:51.943 UTC [48] LOG: received fast shutdown request
invidiousdb | waiting for server to shut down....2022-02-25 19:41:51.944 UTC [48] LOG: aborting any active transactions
invidiousdb | 2022-02-25 19:41:51.946 UTC [48] LOG: background worker "logical replication launcher" (PID 55) exited with exit code 1
invidiousdb | 2022-02-25 19:41:51.946 UTC [50] LOG: shutting down
invidiousdb | 2022-02-25 19:41:51.961 UTC [48] LOG: database system is shut down
invidiousdb | done
invidiousdb | server stopped
invidiousdb |
invidiousdb | PostgreSQL init process complete; ready for start up.
invidiousdb |
invidiousdb | 2022-02-25 19:41:52.071 UTC [1] LOG: starting PostgreSQL 13.6 (Debian 13.6-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
invidiousdb | 2022-02-25 19:41:52.072 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
invidiousdb | 2022-02-25 19:41:52.072 UTC [1] LOG: listening on IPv6 address "::", port 5432
invidiousdb | 2022-02-25 19:41:52.075 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidiousdb | 2022-02-25 19:41:52.080 UTC [81] LOG: database system was shut down at 2022-02-25 19:41:51 UTC
invidiousdb | 2022-02-25 19:41:52.085 UTC [1] LOG: database system is ready to accept connections
invidious_1 | from lib/db/src/db/connection.cr:34:0 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1 | Caused by: Cannot establish connection (PQ::ConnectionError)
invidious_1 | from lib/pg/src/pq/connection.cr:34:9 in 'initialize'
invidious_1 | from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1 | from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1 | Caused by: Error connecting to 'invidiousdb:5432': Connection refused (Socket::ConnectError)
invidious_1 | from /usr/share/crystal/src/socket/addrinfo.cr:67:17 in 'initialize'
invidious_1 | from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'initialize'
invidious_1 | from src/invidious/helpers/crystal_class_overrides.cr:6:3 in 'new'
invidious_1 | from lib/pg/src/pq/connection.cr:30:17 in 'initialize'
invidious_1 | from lib/pg/src/pq/connection.cr:19:5 in 'new'
invidious_1 | from lib/pg/src/pg/connection.cr:13:23 in 'initialize'
invidious_1 | from lib/pg/src/pg/connection.cr:7:5 in 'new'
invidious_1 | from lib/pg/src/pg/driver.cr:3:5 in 'build_connection'
invidious_1 | from lib/db/src/db/database.cr:57:16 in '->'
invidious_1 | from /usr/share/crystal/src/primitives.cr:266:3 in 'build_resource'
invidious_1 | from lib/db/src/db/pool.cr:47:34 in 'initialize'
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_1 | from lib/db/src/db/database.cr:56:15 in 'initialize'
invidious_1 | from lib/db/src/db/database.cr:49:5 in 'new'
invidious_1 | from lib/db/src/db.cr:155:5 in 'build_database'
invidious_1 | from lib/db/src/db.cr:119:5 in 'open'
invidious_1 | from src/invidious.cr:43:15 in '~PG_DB:init'
invidious_1 | from src/invidious.cr:44:1 in '__crystal_main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:96:7 in 'main'
invidious_1 | from /usr/share/crystal/src/crystal/main.cr:119:3 in 'main'
invidious_1 | from src/env/__libc_start_main.c:94:2 in 'libc_start_main_stage2'
invidious_1 | [development] Invidious is ready to lead at http://0.0.0.0:3000
invidious_1 | 2022-02-25 19:42:23 UTC [info] 200 GET /api/v1/comments/jNQXAC9IVRw 221.2ms

As you can see, both error out (when the DB isn't ready), but with 13 Invidious reconnect (something it doesn't do with 14 for WHATEVER reason)

@unixfox
Copy link
Member

unixfox commented Feb 25, 2022 •
edited
Loading

Maybe you can try this PR #2928 with the postgresql client version upgraded, that could fix the issue.
Another way is to wait for postgres to be available: https://stackoverflow.com/a/55835081

@SamantazFox
Copy link
Member

Maybe you can try this PR #2928 with the postgresql client version upgraded, that could fix the issue. Another way is to wait for postgres to be available: https://stackoverflow.com/a/55835081

I tried that and the problem still persists.
I'm in favor of going back to postgres 13 until we figure that out.

TheFrenchGhosty added a commit that referenced this issue Apr 4, 2022
@TheFrenchGhosty
Set the Postgres version to 13 as a temporary workaround for #2938
2c6cd74
TheFrenchGhosty added a commit that referenced this issue Apr 4, 2022
@TheFrenchGhosty
Merge pull request #3007 from iv-org/TheFrenchGhosty-postgres13
91b079f 
Set the Postgres version to 13 as a temporary workaround for #2938
@GaetanLepage
Copy link

I encountered a memory issue as well.
I am running postgresql 14.

Oct 05 09:16:21 server systemd[1]: Started Invidious (An alternative YouTube front-end).
Oct 05 09:16:21 server invidious-start[44780]: [production] Invidious is ready to lead at http://0.0.0.0:3000
Oct 05 09:16:23 server invidious-start[44780]: Invalid memory access (signal 11) at address 0x7f979a603000
Oct 05 09:16:23 server invidious-start[44780]: [0x4608b6] ?? +4589750 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x46087d] ?? +4589693 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x7f979beb2bf0] ?? +140289132669936 in /nix/store/lkxc9m0lm2c9lxzhfxs4hsll6nx3fjsl-glibc-2.35-163/lib/libc.so.6
Oct 05 09:16:23 server invidious-start[44780]: [0x9613bc] ?? +9835452 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x88d870] ?? +8968304 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x8b265a] ?? +9119322 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x54d982] ?? +5560706 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x54ddd7] ?? +5561815 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x45b4dc] ?? +4568284 in /nix/store/4wp823h53bsr3a3cf3lp1wf28337pn05-invidious-unstable-2022-08-13/bin/invidious
Oct 05 09:16:23 server invidious-start[44780]: [0x0] ???
Oct 05 09:16:23 server systemd[1]: invidious.service: Main process exited, code=exited, status=11/n/a
Oct 05 09:16:23 server systemd[1]: invidious.service: Failed with result 'exit-code'.
Oct 05 09:16:23 server systemd[1]: invidious.service: Consumed 122ms CPU time, received 79.5K IP traffic, sent 7.1K IP traffic.

@SamantazFox
Copy link
Member

SamantazFox commented Jan 5, 2023 •
edited
Loading

I've found the problem!

The postgres shard (crystal-pg, the crystal library that handles connection to the DB) tries to authenticate using the password method, even if md5 of scram-sha-256 are the preferred methods (and often the only available ones) on newer versions of PostgreSQL (13 and above, it seems).

As a temporary fix, database_url can be used with the following:
postgres://kemal:password@db-host/invidious?auth_methods=md5,scram-sha-256

I'll see if a PR has to be made to invidious or to the upstream library (auth method should be automatically negociated afaik).

@SamantazFox
Copy link
Member

SamantazFox commented Jan 5, 2023 •
edited
Loading

I encountered a memory issue as well. I am running postgresql 14.

@GaetanLepage This is probably related to #1791 / #3003.
Try to use the non-QUIC container, or compile without QUIC enabled (this is the default now, you can run make without any options and QUIC won't be used).

If the problem perists, please open a dedicated issue.

@SamantazFox SamantazFox mentioned this issue Jan 5, 2023
Merged
@GaetanLepage
Copy link

Good job @SamantazFox ! Great to hear that the cause for this bug is now known :)

Indeed, my problem was caused by QUIC. It works for me with QUIC disabled.

@unixfox unixfox mentioned this issue Jan 19, 2023
Closed
@BBaoVanC
Copy link

BBaoVanC commented Mar 1, 2023 •
edited
Loading

I've been using the latest tag for about 8-9 months now with postgres 14 with no issues, but now I'm getting this issue on the latest update. If I use the latest tag now, then I get this bug, but with the previous latest image (currently tagged b287ff21265007c13895a58537b8771353e8e22b), it works fine.

So it seems like this might have been fixed for a while, but there was a regression last week?

@unixfox unixfox added the exempt-stale Exempt the issue from staling label Mar 2, 2023
@SamantazFox SamantazFox mentioned this issue Jul 14, 2023
Closed
@unixfox unixfox mentioned this issue Mar 9, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@TheFrenchGhosty TheFrenchGhosty

Labels
bug Something isn't working exempt-stale Exempt the issue from staling
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix the Dockerfile sed command iv-org/invidious
8 participants
@martadinata666 @unixfox @BBaoVanC @GaetanLepage @JackHewson @TheFrenchGhosty @MathiusD @SamantazFox