docker compose setup results in "Recv failure: Connection reset by peer"

[shade-belisar]

I followed the instructions for setting up stringer using docker-compose. Specifically, I did this:

mkdir stringer
cd stringer
wget https://raw.githubusercontent.com/stringer-rss/stringer/main/docker-compose.yml
touch .env
docker compose up -d

Unfortunately, if I try to access stringer with curl localhost, I only get curl: (56) Recv failure: Connection reset by peer. Did I misunderstand the instructions, or is this a bug?

[guidopetri]

Does it load the webpage if you access it in your browser?

[shade-belisar]

No. Navigating to http://localhost results in

This site can’t be reached The webpage at http://localhost/ might be temporarily down or it may have moved permanently to a new web address. ERR_SOCKET_NOT_CONNECTED

[guidopetri]

It takes a few minutes to load once booted - I just restarted my docker container and it took ~5min for the application to load completely. Have you been waiting that long? If so, are there any logs in the container/from your reverse proxy that you can share?

[shade-belisar]

Waiting did not solve the issue. According to the logs there is an authentication error, but I don't quite understand how that could be.

2024-02-06 22:18:50,179 DEBG 'puma' stdout output:
(See full trace by running task with --trace)

2024-02-06 22:18:50,199 DEBG fd 9 closed, stopped monitoring <POutputDispatcher at 140613420985296 for <Subprocess at 140613420721040 with name puma in state RUNNING> (stdout)>
2024-02-06 22:18:50,199 WARN exited: puma (exit status 1; not expected)
2024-02-06 22:18:50,200 DEBG received SIGCHLD indicating a child quit
2024-02-06 22:18:51,203 INFO spawned: 'puma' with pid 533
2024-02-06 22:18:52,205 INFO success: puma entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-02-06 22:18:54,292 DEBG 'puma' stdout output:
rake aborted!
ActiveRecord::NoDatabaseError: We could not find your database: stringer. Available database configurations can be found in config/database.yml. (ActiveRecord::NoDatabaseError)

To resolve this error:

- Did you not create the database, or did you delete it? To create the database, run:

    bin/rails db:create

- Has the database name changed? Verify that config/database.yml contains the correct database name.

2024-02-06 22:18:54,293 DEBG 'puma' stdout output:
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:74:in `rescue in new_client'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:68:in `new_client'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:980:in `connect'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:992:in `reconnect'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:685:in `block in reconnect!'
/usr/local/bundle/gems/activesupport-7.1.3/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:684:in `reconnect!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:788:in `verify!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:795:in `connect!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1001:in `block in with_raw_connection'
/usr/local/bundle/gems/activesupport-7.1.3/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1000:in `with_raw_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1113:in `valid_raw_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `get_database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:374:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:70:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:200:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:871:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:644:in `check_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:678:in `new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:723:in `checkout_new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:702:in `try_to_checkout_new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:654:in `acquire_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:353:in `checkout'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:182:in `connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_handler.rb:246:in `retrieve_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_handling.rb:287:in `retrieve_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_handling.rb:254:in `connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/tasks/database_tasks.rb:510:in `migration_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/tasks/database_tasks.rb:243:in `migrate'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/railties/databases.rake:93:in `block (2 levels) in <top (required)>'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:486:in `exec'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:31:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:25:in `start'
/usr/local/bundle/gems/bundler-2.3.25/exe/bundle:48:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/friendly_errors.rb:120:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.3.25/exe/bundle:36:in `<top (required)>'
/usr/local/bundle/bin/bundle:25:in `load'
/usr/local/bundle/bin/bundle:25:in `<main>'

Caused by:
PG::ConnectionBad: connection to server at "172.29.0.2", port 5432 failed: FATAL:  password authentication failed for user "stringer" (PG::ConnectionBad)

2024-02-06 22:18:54,293 DEBG 'puma' stdout output:
/usr/local/bundle/gems/pg-1.5.4/lib/pg/connection.rb:696:in `async_connect_or_reset'
/usr/local/bundle/gems/pg-1.5.4/lib/pg/connection.rb:824:in `connect_to_hosts'
/usr/local/bundle/gems/pg-1.5.4/lib/pg/connection.rb:759:in `new'
/usr/local/bundle/gems/pg-1.5.4/lib/pg.rb:63:in `connect'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:69:in `new_client'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:980:in `connect'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:992:in `reconnect'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:685:in `block in reconnect!'
/usr/local/bundle/gems/activesupport-7.1.3/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:684:in `reconnect!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:788:in `verify!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:795:in `connect!'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1001:in `block in with_raw_connection'
/usr/local/bundle/gems/activesupport-7.1.3/lib/active_support/concurrency/null_lock.rb:9:in `synchronize'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1000:in `with_raw_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:1113:in `valid_raw_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `get_database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:374:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:70:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/schema_cache.rb:200:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract_adapter.rb:871:in `database_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/postgresql_adapter.rb:644:in `check_version'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:678:in `new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:723:in `checkout_new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:702:in `try_to_checkout_new_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:654:in `acquire_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:353:in `checkout'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:182:in `connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_adapters/abstract/connection_handler.rb:246:in `retrieve_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_handling.rb:287:in `retrieve_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/connection_handling.rb:254:in `connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/tasks/database_tasks.rb:510:in `migration_connection'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/tasks/database_tasks.rb:243:in `migrate'
/usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/railties/databases.rake:93:in `block (2 levels) in <top (required)>'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `load'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:58:in `kernel_load'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli/exec.rb:23:in `run'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:486:in `exec'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:31:in `dispatch'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/cli.rb:25:in `start'
/usr/local/bundle/gems/bundler-2.3.25/exe/bundle:48:in `block in <top (required)>'
/usr/local/bundle/gems/bundler-2.3.25/lib/bundler/friendly_errors.rb:120:in `with_friendly_errors'
/usr/local/bundle/gems/bundler-2.3.25/exe/bundle:36:in `<top (required)>'
/usr/local/bundle/bin/bundle:25:in `load'
/usr/local/bundle/bin/bundle:25:in `<main>'
Tasks: TOP => db:migrate

[guidopetri]

That's interesting, I see two errors here. The first:

ActiveRecord::NoDatabaseError: We could not find your database: stringer.

somehow it seems that your postgres container is not initializing the stringer db correctly.

PG::ConnectionBad: connection to server at "172.29.0.2", port 5432 failed: FATAL:  password authentication failed for user "stringer" (PG::ConnectionBad)

seemingly the root cause, the password authentication failed. Did you at some point remove the .env file that got created? Or perhaps the .env file already existed? I think the database may have been initialized with different values for the default password, and now your .env file is out of date. Maybe try starting from scratch again by removing the .env file, the ~/stringer directory (maybe back this up just in case, since it's the db data), and rerunning touch .env && docker compose up -d?

[shade-belisar]

I deleted env and ~/stringer and ran the docker compose command again. Now I am getting a different error. In the stringer container:

tput: No value for $TERM and no -T specified
Error: no DATABASE_URL was specified.

And in the stringer-postgres container:

Error: Database is uninitialized and superuser password is not specified.
       You must specify POSTGRES_PASSWORD to a non-empty value for the
       superuser. For example, "-e POSTGRES_PASSWORD=password" on "docker run".

       You may also use "POSTGRES_HOST_AUTH_METHOD=trust" to allow all
       connections without a password. This is *not* recommended.

       See PostgreSQL documentation about "trust":
       https://www.postgresql.org/docs/current/auth-trust.html

Weirdly enough, the .env file does contain values for both those variables, so I ran docker compose down followed by another docker compose up -d, thinking that maybe they were initialized late.

This led to the containers ostensibly starting, but curl localhost simply returning nothing.

As far as I can see, there is nothing that would explain this in the logs.

In the stringer container:

``` I, [2024-02-15T06:33:15.702085 #7] INFO -- : Writing /app/public/assets/manifest-dad05bf766af0fe3d79dd746db3c1361c0583026cdf35d6a2921bccaea835331.js I, [2024-02-15T06:33:15.702429 #7] INFO -- : Writing /app/public/assets/manifest-dad05bf766af0fe3d79dd746db3c1361c0583026cdf35d6a2921bccaea835331.js.gz I, [2024-02-15T06:33:15.702587 #7] INFO -- : Writing /app/public/assets/application-e2755f1050a83dda947a71e96e575409d42d488bb570f7cd04bcc734bff97283.css I, [2024-02-15T06:33:15.702859 #7] INFO -- : Writing /app/public/assets/application-e2755f1050a83dda947a71e96e575409d42d488bb570f7cd04bcc734bff97283.css.gz I, [2024-02-15T06:33:15.703050 #7] INFO -- : Writing /app/public/assets/bootstrap-min-d95ed3d3bc3c94894f80b1f45c536f9f2fceeeb84aa3947104ffdfd770d3ab83.css I, [2024-02-15T06:33:15.711001 #7] INFO -- : Writing /app/public/assets/bootstrap-min-d95ed3d3bc3c94894f80b1f45c536f9f2fceeeb84aa3947104ffdfd770d3ab83.css.gz I, [2024-02-15T06:33:15.711480 #7] INFO -- : Writing /app/public/assets/flat-ui-no-icons-efe50810e3aeeac5c2a9bc5c0c354ff794cce478af58541cf79075dbde764f4a.css I, [2024-02-15T06:33:15.711920 #7] INFO -- : Writing /app/public/assets/flat-ui-no-icons-efe50810e3aeeac5c2a9bc5c0c354ff794cce478af58541cf79075dbde764f4a.css.gz I, [2024-02-15T06:33:15.712215 #7] INFO -- : Writing /app/public/assets/font-awesome-min-fb64aedbc2a7a9fbd25e062f1e1c1377ef7939bce61208c1143b6a4df950e23b.css I, [2024-02-15T06:33:15.712858 #7] INFO -- : Writing /app/public/assets/font-awesome-min-fb64aedbc2a7a9fbd25e062f1e1c1377ef7939bce61208c1143b6a4df950e23b.css.gz I, [2024-02-15T06:33:15.713067 #7] INFO -- : Writing /app/public/assets/lato-fonts-7ac7b1f2dffb0aaa58bf602983c4ed193e66766d3bfcbce80fcb7fc78e2b0688.css I, [2024-02-15T06:33:15.713694 #7] INFO -- : Writing /app/public/assets/lato-fonts-7ac7b1f2dffb0aaa58bf602983c4ed193e66766d3bfcbce80fcb7fc78e2b0688.css.gz I, [2024-02-15T06:33:15.713930 #7] INFO -- : Writing /app/public/assets/reenie-beanie-font-ae77a8ce9dc528027b12f1132236e0b5f364f0f8a041367b308f6d3ebe452aff.css I, [2024-02-15T06:33:15.714440 #7] INFO -- : Writing /app/public/assets/reenie-beanie-font-ae77a8ce9dc528027b12f1132236e0b5f364f0f8a041367b308f6d3ebe452aff.css.gz I, [2024-02-15T06:33:15.714658 #7] INFO -- : Writing /app/public/assets/application-281e18c7a05c3cf640912d0d91332eb34e415d8733a53187a56e1f7129322c36.js I, [2024-02-15T06:33:15.714982 #7] INFO -- : Writing /app/public/assets/application-281e18c7a05c3cf640912d0d91332eb34e415d8733a53187a56e1f7129322c36.js.gz 2024-02-15 06:33:15,946 INFO supervisord started with pid 1 2024-02-15 06:33:16,949 INFO spawned: 'cron' with pid 23 2024-02-15 06:33:16,950 INFO spawned: 'puma' with pid 24 2024-02-15 06:33:16,963 DEBG 'cron' stderr output: time="2024-02-15T06:33:16Z" level=info msg="read crontab: /app/crontab" 2024-02-15 06:33:17,964 INFO success: cron entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2024-02-15 06:33:17,964 INFO success: puma entered RUNNING state, process has stayed up for > than 1 seconds (startsecs) 2024-02-15 06:33:18,769 DEBG 'puma' stdout output: I, [2024-02-15T06:33:18.615928 #25] INFO -- : Migrating to CreateFeeds (20130409010818) == 20130409010818 CreateFeeds: migrating ====================================== -- create_table(:feeds, {:id=>:integer}) -> 0.0077s == 20130409010818 CreateFeeds: migrated (0.0078s) ============================= I, [2024-02-15T06:33:18.628267 #25] INFO -- : Migrating to CreateStories (20130409010826) == 20130409010826 CreateStories: migrating ==================================== -- create_table(:stories, {:id=>:integer}) -> 0.0068s == 20130409010826 CreateStories: migrated (0.0069s) =========================== I, [2024-02-15T06:33:18.637292 #25] INFO -- : Migrating to AddNewFieldsToStories (20130412185253) == 20130412185253 AddNewFieldsToStories: migrating ============================ -- add_column(:stories, :published, :timestamp) -> 0.0006s -- add_column(:stories, :is_read, :boolean) -> 0.0003s -- add_column(:stories, :author, :string) -> 0.0004s == 20130412185253 AddNewFieldsToStories: migrated (0.0013s) =================== I, [2024-02-15T06:33:18.640646 #25] INFO -- : Migrating to AddUserModel (20130418221144) == 20130418221144 AddUserModel: migrating ===================================== -- create_table(:users, {:id=>:integer}) -> 0.0073s == 20130418221144 AddUserModel: migrated (0.0073s) ============================ I, [2024-02-15T06:33:18.650041 #25] INFO -- : Migrating to DropEmailFromUser (20130423001740) == 20130423001740 DropEmailFromUser: migrating ================================ -- remove_column(:users, :email) -> 0.0005s == 20130423001740 DropEmailFromUser: migrated (0.0006s) ======================= I, [2024-02-15T06:33:18.652316 #25] INFO -- : Migrating to RemoveAuthorFromStories (20130423180446) == 20130423180446 RemoveAuthorFromStories: migrating ========================== -- remove_column(:stories, :author) -> 0.0004s == 20130423180446 RemoveAuthorFromStories: migrated (0.0004s) ================= I, [2024-02-15T06:33:18.654432 #25] INFO -- : Migrating to AddSetupCompleteToUser (20130425211008) == 20130425211008 AddSetupCompleteToUser: migrating =========================== -- add_column(:users, :setup_complete, :boolean) -> 0.0005s == 20130425211008 AddSetupCompleteToUser: migrated (0.0005s) ================== I, [2024-02-15T06:33:18.656852 #25] INFO -- : Migrating to AddDelayedJob (20130425222157) == 20130425222157 AddDelayedJob: migrating ==================================== -- create_table(:delayed_jobs, {:force=>true, :id=>:integer}) -> 0.0082s -- add_index(:delayed_jobs, [:priority, :run_at], {:name=>"delayed_jobs_priority"}) -> 0.0030s == 20130425222157 AddDelayedJob: migrated (0.0114s) =========================== I, [2024-02-15T06:33:18.670349 #25] INFO -- : Migrating to AddStatusToFeeds (20130429232127) == 20130429232127 AddStatusToFeeds: migrating ================================= -- add_column(:feeds, :status, :int) -> 0.0005s == 20130429232127 AddStatusToFeeds: migrated (0.0006s) ======================== I, [2024-02-15T06:33:18.672777 #25] INFO -- : Migrating to TextUrl (20130504005816) == 20130504005816 TextUrl: migrating ========================================== -- change_column(:feeds, :url, :text) -> 0.0005s == 20130504005816 TextUrl: migrated (0.0005s) ================================= I, [2024-02-15T06:33:18.675293 #25] INFO -- : Migrating to ChangeStoryPermalinkColumn (20130504022615) == 20130504022615 ChangeStoryPermalinkColumn: migrating ======================= -- change_column(:stories, :permalink, :text) -> 0.0004s == 20130504022615 ChangeStoryPermalinkColumn: migrated (0.0004s) ============== I, [2024-02-15T06:33:18.677418 #25] INFO -- : Migrating to AddUniqueConstraints (20130509131045) == 20130509131045 AddUniqueConstraints: migrating ============================= -- add_index(:stories, [:permalink, :feed_id], {:unique=>true, :name=>"index_stories_on_permalink_and_feed_id"}) -> 0.0030s -- add_index(:feeds, :url, {:unique=>true, :name=>"index_feeds_on_url"}) -> 0.0028s == 20130509131045 AddUniqueConstraints: migrated (0.0060s) ==================== I, [2024-02-15T06:33:18.685097 #25] INFO -- : Migrating to AddKeepUnreadToStories (20130513025939) == 20130513025939 AddKeepUnreadToStories: migrating =========================== -- add_column(:stories, :keep_unread, :boolean, {:default=>false}) -> 0.0098s == 20130513025939 AddKeepUnreadToStories: migrated (0.0098s) ================== I, [2024-02-15T06:33:18.697269 #25] INFO -- : Migrating to AddIsStarredStatusForStories (20130513044029) == 20130513044029 AddIsStarredStatusForStories: migrating ===================== -- add_column(:stories, :is_starred, :boolean, {:default=>false}) -> 0.0100s == 20130513044029 AddIsStarredStatusForStories: migrated (0.0101s) ============ I, [2024-02-15T06:33:18.709636 #25] INFO -- : Migrating to AddAPIKeyToUser (20130522014405) == 20130522014405 AddAPIKeyToUser: migrating ================================== -- add_column(:users, :api_key, :string) -> 0.0004s == 20130522014405 AddAPIKeyToUser: migrated (0.0004s) ========================= I, [2024-02-15T06:33:18.711775 #25] INFO -- : Migrating to AddEntryIdToStories (20130730120312) == 20130730120312 AddEntryIdToStories: migrating ============================== -- add_column(:stories, :entry_id, :string) -> 0.0004s == 20130730120312 AddEntryIdToStories: migrated (0.0004s) ===================== I, [2024-02-15T06:33:18.713993 #25] INFO -- : Migrating to UpdateStoriesUniqueConstraints (20130805113712) == 20130805113712 UpdateStoriesUniqueConstraints: migrating =================== -- remove_index(:stories, [:permalink, :feed_id], {:name=>"index_stories_on_permalink_and_feed_id"}) -> 0.0030s -- add_index(:stories, [:entry_id, :feed_id], {:unique=>true, :length=>{:permalink=>767}, :name=>"index_stories_on_entry_id_and_feed_id"}) -> 0.0030s == 20130805113712 UpdateStoriesUniqueConstraints: migrated (0.0074s) ========== I, [2024-02-15T06:33:18.723288 #25] INFO -- : Migrating to UpdateNilEntryIds (20130821020313) == 20130821020313 UpdateNilEntryIds: migrating ================================ == 20130821020313 UpdateNilEntryIds: migrated (0.0220s) ======================= I, [2024-02-15T06:33:18.747004 #25] INFO -- : Migrating to UseTextDatatypeForTitleAndEntryId (20130905204142) == 20130905204142 UseTextDatatypeForTitleAndEntryId: migrating ================ -- change_column(:stories, :title, :text) -> 0.0004s -- change_column(:stories, :entry_id, :text) -> 0.0005s == 20130905204142 UseTextDatatypeForTitleAndEntryId: migrated (0.0009s) ======= I, [2024-02-15T06:33:18.749656 #25] INFO -- : Migrating to AddGroupsTableAndForeignKeysToFeeds (20140413100725) == 20140413100725 AddGroupsTableAndForeignKeysToFeeds: migrating ============== -- create_table(:groups, {:id=>:integer}) -> 0.0065s -- add_column(:feeds, :group_id, :integer) -> 0.0003s == 20140413100725 AddGroupsTableAndForeignKeysToFeeds: migrated (0.0069s) ===== I, [2024-02-15T06:33:18.758522 #25] INFO -- : Migrating to FixInvalidUnicode (20140421224454) == 20140421224454 FixInvalidUnicode: migrating ================================ == 20140421224454 FixInvalidUnicode: migrated (0.0009s) ======================= I, [2024-02-15T06:33:18.761316 #25] INFO -- : Migrating to FixInvalidTitlesWithUnicodeLineEndings (20141102103617) == 20141102103617 FixInvalidTitlesWithUnicodeLineEndings: migrating =========== == 20141102103617 FixInvalidTitlesWithUnicodeLineEndings: migrated (0.0009s) == I, [2024-02-15T06:33:18.764188 #25] INFO -- : Migrating to AddEnclosureUrlToStories (20221206231914) == 20221206231914 AddEnclosureUrlToStories: migrating ========================= -- add_column(:stories, :enclosure_url, :string) -> 0.0006s == 20221206231914 AddEnclosureUrlToStories: migrated (0.0006s) ================ I, [2024-02-15T06:33:18.766657 #25] INFO -- : Migrating to DropSetupComplete (20230120222742) == 20230120222742 DropSetupComplete: migrating ================================ -- remove_column(:users, :setup_complete, :boolean) -> 0.0004s == 20230120222742 DropSetupComplete: migrated (0.0004s) ======================= I, [2024-02-15T06:33:18.769035 #25] INFO -- : Migrating to AddUserIdToTables (20230221233057) 2024-02-15 06:33:19,017 DEBG 'puma' stdout output: == 20230221233057 AddUserIdToTables: migrating ================================ -- add_reference(:feeds, :user, {:index=>true, :foreign_key=>true}) -> 0.0153s -- add_reference(:groups, :user, {:index=>true, :foreign_key=>true}) -> 0.0043s == 20230221233057 AddUserIdToTables: migrated (0.0196s) ======================= I, [2024-02-15T06:33:18.790778 #25] INFO -- : Migrating to AddNullFalseToAssociations (20230223045525) == 20230223045525 AddNullFalseToAssociations: migrating ======================= -- change_column_null(:feeds, :user_id, false, nil) -> 0.0003s -- change_column_null(:groups, :user_id, false, nil) -> 0.0003s -- change_column_null(:stories, :feed_id, false, nil) -> 0.0002s == 20230223045525 AddNullFalseToAssociations: migrated (0.0112s) ============== I, [2024-02-15T06:33:18.803985 #25] INFO -- : Migrating to AddUsernameToUsers (20230223231930) == 20230223231930 AddUsernameToUsers: migrating =============================== -- add_column(:users, :username, :string) -> 0.0004s -- add_index(:users, :username, {:unique=>true, :name=>"index_users_on_username"}) -> 0.0029s -- change_column_null(:users, :username, false, nil) -> 0.0002s == 20230223231930 AddUsernameToUsers: migrated (0.0038s) ====================== I, [2024-02-15T06:33:18.809487 #25] INFO -- : Migrating to UpdateUniqueIndexes (20230224042638) == 20230224042638 UpdateUniqueIndexes: migrating ============================== -- remove_index(:feeds, :url) -> 0.0019s -- add_index(:feeds, [:url, :user_id], {:unique=>true, :name=>"index_feeds_on_url_and_user_id"}) -> 0.0029s -- add_index(:groups, [:name, :user_id], {:unique=>true, :name=>"index_groups_on_name_and_user_id"}) -> 0.0028s == 20230224042638 UpdateUniqueIndexes: migrated (0.0077s) ===================== I, [2024-02-15T06:33:18.819091 #25] INFO -- : Migrating to EncryptAPIKey (20230301024452) == 20230301024452 EncryptAPIKey: migrating ==================================== -- change_column_null(:users, :api_key, false, nil) -> 0.0003s -- add_index(:users, :api_key, {:unique=>true, :name=>"index_users_on_api_key"}) -> 0.0030s == 20230301024452 EncryptAPIKey: migrated (0.0062s) =========================== I, [2024-02-15T06:33:18.827216 #25] INFO -- : Migrating to CreateGoodJobs (20230305010750) == 20230305010750 CreateGoodJobs: migrating =================================== -- enable_extension("pgcrypto") -> 0.0086s -- create_table(:good_jobs, {:id=>:uuid}) -> 0.0070s -- create_table(:good_job_batches, {:id=>:uuid}) -> 0.0067s -- create_table(:good_job_processes, {:id=>:uuid}) -> 0.0065s -- create_table(:good_job_settings, {:id=>:uuid}) -> 0.0091s -- add_index(:good_jobs, :scheduled_at, {:where=>"(finished_at IS NULL)", :name=>"index_good_jobs_on_scheduled_at"}) -> 0.0059s -- add_index(:good_jobs, [:queue_name, :scheduled_at], {:where=>"(finished_at IS NULL)", :name=>:index_good_jobs_on_queue_name_and_scheduled_at}) -> 0.0049s -- add_index(:good_jobs, [:active_job_id, :created_at], {:name=>:index_good_jobs_on_active_job_id_and_created_at}) -> 0.0028s -- add_index(:good_jobs, :concurrency_key, {:where=>"(finished_at IS NULL)", :name=>:index_good_jobs_on_concurrency_key_when_unfinished}) -> 0.0048s -- add_index(:good_jobs, [:cron_key, :created_at], {:name=>:index_good_jobs_on_cron_key_and_created_at}) -> 0.0028s -- add_index(:good_jobs, [:cron_key, :cron_at], {:name=>:index_good_jobs_on_cron_key_and_cron_at, :unique=>true}) -> 0.0028s -- add_index(:good_jobs, [:active_job_id], {:name=>:index_good_jobs_on_active_job_id}) -> 0.0028s -- add_index(:good_jobs, [:finished_at], {:where=>"retried_good_job_id IS NULL AND finished_at IS NOT NULL", :name=>:index_good_jobs_jobs_on_finished_at}) -> 0.0049s -- add_index(:good_jobs, [:priority, :created_at], {:order=>{:priority=>"DESC NULLS LAST", :created_at=>:asc}, :where=>"finished_at IS NULL", :name=>:index_good_jobs_jobs_on_priority_created_at_when_unfinished}) -> 0.0049s -- add_index(:good_jobs, [:batch_id], {:where=>"batch_id IS NOT NULL", :name=>"index_good_jobs_on_batch_id"}) -> 0.0068s -- add_index(:good_jobs, [:batch_callback_id], {:where=>"batch_callback_id IS NOT NULL", :name=>"index_good_jobs_on_batch_callback_id"}) -> 0.0064s == 20230305010750 CreateGoodJobs: migrated (0.0884s) ========================== I, [2024-02-15T06:33:18.919437 #25] INFO -- : Migrating to DropDelayedJob (20230312193113) == 20230312193113 DropDelayedJob: migrating =================================== -- drop_table(:delayed_jobs) -> 0.0012s == 20230312193113 DropDelayedJob: migrated (0.0013s) ========================== I, [2024-02-15T06:33:18.924324 #25] INFO -- : Migrating to AddAdminToUsers (20230313034938) == 20230313034938 AddAdminToUsers: migrating ================================== -- add_column(:users, :admin, :boolean) -> 0.0004s -- change_column_null(:users, :admin, false, nil) -> 0.0002s == 20230313034938 AddAdminToUsers: migrated (0.0025s) ========================= I, [2024-02-15T06:33:18.928555 #25] INFO -- : Migrating to CreateSubscriptions (20230330215830) == 20230330215830 CreateSubscriptions: migrating ============================== -- create_table(:subscriptions) -> 0.0121s -- add_index(:subscriptions, :stripe_customer_id, {:unique=>true, :name=>"index_subscriptions_on_stripe_customer_id"}) -> 0.0030s -- add_index(:subscriptions, :stripe_subscription_id, {:unique=>true, :name=>"index_subscriptions_on_stripe_subscription_id"}) -> 0.0030s == 20230330215830 CreateSubscriptions: migrated (0.0194s) ===================== I, [2024-02-15T06:33:18.951823 #25] INFO -- : Migrating to CreateSettings (20230721160939) == 20230721160939 CreateSettings: migrating =================================== -- create_table(:settings) -> 0.0125s == 20230721160939 CreateSettings: migrated (0.0125s) ========================== I, [2024-02-15T06:33:18.966519 #25] INFO -- : Migrating to CreateGoodJobSettings (20230801025230) == 20230801025230 CreateGoodJobSettings: migrating ============================ == 20230801025230 CreateGoodJobSettings: migrated (0.0006s) =================== I, [2024-02-15T06:33:18.972300 #25] INFO -- : Migrating to CreateIndexGoodJobsJobsOnPriorityCreatedAtWhenUnfinished (20230801025231) == 20230801025231 CreateIndexGoodJobsJobsOnPriorityCreatedAtWhenUnfinished: migrating == 20230801025231 CreateIndexGoodJobsJobsOnPriorityCreatedAtWhenUnfinished: migrated (0.0011s) I, [2024-02-15T06:33:18.976662 #25] INFO -- : Migrating to CreateGoodJobBatches (20230801025232) == 20230801025232 CreateGoodJobBatches: migrating ============================= == 20230801025232 CreateGoodJobBatches: migrated (0.0005s) ==================== I, [2024-02-15T06:33:18.980336 #25] INFO -- : Migrating to CreateGoodJobExecutions (20230801025233) == 20230801025233 CreateGoodJobExecutions: migrating ========================== -- create_table(:good_job_executions, {:id=>:uuid}) -> 0.0133s -- change_table(:good_jobs) -> 0.0035s == 20230801025233 CreateGoodJobExecutions: migrated (0.0185s) ================= I, [2024-02-15T06:33:19.000777 #25] INFO -- : Migrating to CreateGoodJobsErrorEvent (20230801025234) == 20230801025234 CreateGoodJobsErrorEvent: migrating ========================= -- add_column(:good_jobs, :error_event, :integer, {:limit=>2}) -> 0.0004s -- add_column(:good_job_executions, :error_event, :integer, {:limit=>2}) -> 0.0002s == 20230801025234 CreateGoodJobsErrorEvent: migrated (0.0092s) ================ 2024-02-15 06:33:19,287 DEBG 'puma' stdout output: Warning: You specified code to run in a `before_fork` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `before_fork` block did not run Warning: You specified code to run in a `on_worker_boot` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `on_worker_boot` block did not run Warning: You specified code to run in a `on_worker_shutdown` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `on_worker_shutdown` block did not run 2024-02-15 06:33:19,288 DEBG 'puma' stdout output: [24] Puma starting in cluster mode... [24] * Puma version: 6.4.2 (ruby 3.3.0-p0) ("The Eagle of Durango") [24] * Min threads: 2 [24] * Max threads: 2 [24] * Environment: production 2024-02-15 06:33:19,288 DEBG 'puma' stdout output: [24] * Master PID: 24 [24] * Workers: 2 [24] * Restarts: (✔) hot (✖) phased [24] * Preloading application 2024-02-15 06:33:20,831 DEBG 'puma' stdout output: I, [2024-02-15T06:33:20.796265 #24] INFO -- : [GoodJob] [24] GoodJob 3.23.0 started scheduler with queues=* max_threads=5. [24] * Listening on http://0.0.0.0:8080 [24] ! WARNING: Detected 5 Thread(s) started in app boot: 2024-02-15 06:33:20,831 DEBG 'puma' stdout output: [24] ! # - /usr/local/bundle/gems/pg-1.5.4/lib/pg/connection.rb:690:in `connect_poll' [24] ! # - :18:in `pop' [24] ! # - /usr/local/bundle/gems/pg-1.5.4/lib/pg/connection.rb:690:in `connect_poll' 2024-02-15 06:33:20,831 DEBG 'puma' stdout output: [24] ! # - /usr/local/bundle/gems/activerecord-7.1.3/lib/active_record/model_schema.rb:560:in `synchronize' 2024-02-15 06:33:20,831 DEBG 'puma' stdout output: [24] ! # - /usr/local/bundle/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:53:in `sleep' 2024-02-15 06:33:20,832 DEBG 'puma' stdout output: [24] Use Ctrl-C to stop 2024-02-15 06:33:20,842 DEBG 'puma' stdout output: I, [2024-02-15T06:33:20.842496 #24] INFO -- : [GoodJob] Notifier subscribed with LISTEN 2024-02-15 06:33:20,867 DEBG 'puma' stdout output: I, [2024-02-15T06:33:20.867135 #24] INFO -- : [GoodJob] Notifier unsubscribed with UNLISTEN 2024-02-15 06:33:20,871 DEBG 'puma' stdout output: I, [2024-02-15T06:33:20.871771 #24] INFO -- : [GoodJob] [24] GoodJob shutting down scheduler... 2024-02-15 06:33:20,873 DEBG 'puma' stdout output: I, [2024-02-15T06:33:20.873004 #24] INFO -- : [GoodJob] [24] GoodJob scheduler is shut down. 2024-02-15 06:33:21,879 DEBG 'puma' stdout output: I, [2024-02-15T06:33:21.879028 #56] INFO -- : [GoodJob] [56] GoodJob 3.23.0 started scheduler with queues=* max_threads=5. 2024-02-15 06:33:21,880 DEBG 'puma' stdout output: I, [2024-02-15T06:33:21.880399 #59] INFO -- : [GoodJob] [59] GoodJob 3.23.0 started scheduler with queues=* max_threads=5. 2024-02-15 06:33:21,881 DEBG 'puma' stdout output: [24] - Worker 0 (PID: 56) booted in 0.01s, phase: 0 2024-02-15 06:33:21,882 DEBG 'puma' stdout output: [24] - Worker 1 (PID: 59) booted in 0.01s, phase: 0 2024-02-15 06:33:21,902 DEBG 'puma' stdout output: I, [2024-02-15T06:33:21.902459 #56] INFO -- : [GoodJob] Notifier subscribed with LISTEN 2024-02-15 06:33:21,903 DEBG 'puma' stdout output: I, [2024-02-15T06:33:21.903847 #59] INFO -- : [GoodJob] Notifier subscribed with LISTEN 2024-02-15 06:35:00,000 DEBG 'cron' stderr output: time="2024-02-15T06:35:00Z" level=info msg=starting iteration=0 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:35:01,750 DEBG 'cron' stderr output: time="2024-02-15T06:35:01Z" level=info msg="job succeeded" iteration=0 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:40:00,000 DEBG 'cron' stderr output: time="2024-02-15T06:40:00Z" level=info msg=starting iteration=1 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:40:01,637 DEBG 'cron' stderr output: time="2024-02-15T06:40:01Z" level=info msg="job succeeded" iteration=1 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:45:00,000 DEBG 'cron' stderr output: time="2024-02-15T06:45:00Z" level=info msg=starting iteration=2 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:45:01,623 DEBG 'cron' stderr output: time="2024-02-15T06:45:01Z" level=info msg="job succeeded" iteration=2 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:50:00,000 DEBG 'cron' stderr output: time="2024-02-15T06:50:00Z" level=info msg=starting iteration=3 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:50:01,622 DEBG 'cron' stderr output: time="2024-02-15T06:50:01Z" level=info msg="job succeeded" iteration=3 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:55:00,000 DEBG 'cron' stderr output: time="2024-02-15T06:55:00Z" level=info msg=starting iteration=4 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 06:55:01,617 DEBG 'cron' stderr output: time="2024-02-15T06:55:01Z" level=info msg="job succeeded" iteration=4 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 07:00:00,000 DEBG 'cron' stderr output: time="2024-02-15T07:00:00Z" level=info msg=starting iteration=5 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" 2024-02-15 07:00:01,615 DEBG 'cron' stderr output: time="2024-02-15T07:00:01Z" level=info msg="job succeeded" iteration=5 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" time="2024-02-15T07:00:01Z" level=error msg="failed to close pipe: close |0: bad file descriptor" channel=stderr iteration=5 job.command="cd /app && bundle exec rake fetch_feeds" job.position=0 job.schedule="*/5 * * * *" ```

And the stringer postgres container:

``` The files belonging to this database system will be owned by user "postgres". This user must also own the server process. The database cluster will be initialized with locale "en_US.utf8". The default database encoding has accordingly been set to "UTF8". The default text search configuration will be set to "english". Data page checksums are disabled. fixing permissions on existing directory /var/lib/postgresql/data ... ok creating subdirectories ... ok selecting default max_connections ... 100 selecting default shared_buffers ... 128MB selecting default timezone ... UTC selecting dynamic shared memory implementation ... posix creating configuration files ... ok creating template1 database in /var/lib/postgresql/data/base/1 ... ok initializing pg_authid ... ok setting password ... ok initializing dependencies ... ok creating system views ... ok loading system objects' descriptions ... ok sh: locale: not found creating collations ... ok No usable system locales were found. Use the option "--debug" to see details. creating conversions ... ok creating dictionaries ... ok setting privileges on built-in objects ... ok creating information schema ... ok loading PL/pgSQL server-side language ... ok vacuuming database template1 ... ok copying template1 to template0 ... ok copying template1 to postgres ... ok syncing data to disk ... ok WARNING: enabling "trust" authentication for local connections You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb. Success. You can now start the database server using: pg_ctl -D /var/lib/postgresql/data -l logfile start waiting for server to start....LOG: database system was shut down at 2024-02-15 06:33:13 UTC LOG: MultiXact member wraparound protections are now enabled LOG: database system is ready to accept connections LOG: autovacuum launcher started done server started CREATE DATABASE /usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/* waiting for server to shut down....LOG: received fast shutdown request LOG: aborting any active transactions LOG: autovacuum launcher shutting down LOG: shutting down LOG: database system is shut down done server stopped PostgreSQL init process complete; ready for start up. LOG: database system was shut down at 2024-02-15 06:33:15 UTC LOG: MultiXact member wraparound protections are now enabled LOG: database system is ready to accept connections LOG: autovacuum launcher started ```

[guidopetri]

Interesting. The logs you posted after the restart look correct to me, so I'm surprised that you're still not seeing anything from localhost. I'm not sure why the db initialized incorrectly for you, but I'll try and repro.

[guidopetri]

@mockdeep and I tried this out and we did indeed observe the error you're seeing. I think it might be docker compose trying to load environment files into variables before they get set, and as a result it loads an empty .env before populating it. I'll see if there's a way around this.