nickjj / docker-rails-example

A production ready example Rails app that's using Docker and Docker Compose.
MIT License
941 stars 185 forks source link

"web", "cable", and "worker" containers do not display any logging #59

Closed Ikariusrb closed 1 year ago

Ikariusrb commented 1 year ago

... unless you remove the "tty=true" from docker-compose.yml.

As the repo is, the only containers which show logging output when running "docker compose up" are the postgres and redis containers, which are second to least-important.

Reproduced on MacOS Monterey with docker 4.6.0.

nickjj commented 1 year ago

Hi,

Can you post a screenshot of what you see? Did you change anything?

I'm not able to reproduce this. Docker Desktop 4.6.0 is over a year old. What if you try a more modern version?

Here's what happens when I start the project:

$ docker compose up
[+] Running 8/8
 ⠿ Network hellorails_default       Created                                                                                                         0.1s
 ⠿ Container hellorails-css-1       Created                                                                                                         0.2s
 ⠿ Container hellorails-redis-1     Created                                                                                                         0.2s
 ⠿ Container hellorails-postgres-1  Created                                                                                                         0.2s
 ⠿ Container hellorails-js-1        Created                                                                                                         0.2s
 ⠿ Container hellorails-cable-1     Created                                                                                                         0.2s
 ⠿ Container hellorails-web-1       Created                                                                                                         0.2s
 ⠿ Container hellorails-worker-1    Created                                                                                                         0.2s
Attaching to hellorails-cable-1, hellorails-css-1, hellorails-js-1, hellorails-postgres-1, hellorails-redis-1, hellorails-web-1, hellorails-worker-1
hellorails-redis-1     | 1:C 18 Mar 2023 18:59:19.041 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
hellorails-redis-1     | 1:C 18 Mar 2023 18:59:19.041 # Redis version=7.0.8, bits=64, commit=00000000, modified=0, pid=1, just started
hellorails-redis-1     | 1:C 18 Mar 2023 18:59:19.041 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.042 * monotonic clock: POSIX clock_gettime
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.042 * Running mode=standalone, port=6379.
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 # Server initialized
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * Loading RDB produced by version 7.0.8
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * RDB age 8611 seconds
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * RDB memory usage when created 1.22 Mb
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * Done loading RDB, keys loaded: 0, keys expired: 2.
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * DB loaded from disk: 0.000 seconds
hellorails-redis-1     | 1:M 18 Mar 2023 18:59:19.043 * Ready to accept connections
yarn run v1.22.19
$ ./run yarn:build:css
hellorails-postgres-1  |
hellorails-postgres-1  | PostgreSQL Database directory appears to contain a database; Skipping initialization
hellorails-postgres-1  |
hellorails-postgres-1  | 2023-03-18 18:59:19.364 UTC [1] LOG:  starting PostgreSQL 15.2 (Debian 15.2-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
hellorails-postgres-1  | 2023-03-18 18:59:19.364 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
hellorails-postgres-1  | 2023-03-18 18:59:19.364 UTC [1] LOG:  listening on IPv6 address "::", port 5432
hellorails-postgres-1  | 2023-03-18 18:59:19.412 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
hellorails-postgres-1  | 2023-03-18 18:59:19.458 UTC [30] LOG:  database system was shut down at 2023-03-18 16:35:48 UTC
hellorails-postgres-1  | 2023-03-18 18:59:19.485 UTC [1] LOG:  database system is ready to accept connections
yarn run v1.22.19
$ ./run yarn:build
hellorails-js-1        | [watch] build finished, watching for changes...
hellorails-css-1       |
hellorails-css-1       | Rebuilding...
hellorails-cable-1     | Puma starting in single mode...
hellorails-cable-1     | * Puma version: 6.1.1 (ruby 3.2.1-p31) ("The Way Up")
hellorails-cable-1     | *  Min threads: 5
hellorails-cable-1     | *  Max threads: 5
hellorails-cable-1     | *  Environment: development
hellorails-cable-1     | *          PID: 1
hellorails-css-1       |
hellorails-css-1       | Done in 413ms.
hellorails-web-1       | => Booting Puma
hellorails-web-1       | => Rails 7.0.4.2 application starting in development
hellorails-web-1       | => Run `bin/rails server --help` for more startup options
hellorails-web-1       | Puma starting in single mode...
hellorails-web-1       | * Puma version: 6.1.1 (ruby 3.2.1-p31) ("The Way Up")
hellorails-web-1       | *  Min threads: 5
hellorails-web-1       | *  Max threads: 5
hellorails-web-1       | *  Environment: development
hellorails-web-1       | *          PID: 1
hellorails-web-1       | * Listening on http://0.0.0.0:8000
hellorails-web-1       | Use Ctrl-C to stop
hellorails-worker-1    |
hellorails-worker-1    |
hellorails-worker-1    |                m,
hellorails-worker-1    |                `$b
hellorails-worker-1    |           .ss,  $$:         .,d$
hellorails-worker-1    |           `$$P,d$P'    .,md$P"'
hellorails-worker-1    |            ,$$$$$b/md$$$P^'
hellorails-worker-1    |          .d$$$$$$/$$$P'
hellorails-worker-1    |          $$^' `"/$$$'       ____  _     _      _    _
hellorails-worker-1    |          $:    ',$$:       / ___|(_) __| | ___| | _(_) __ _
hellorails-worker-1    |          `b     :$$        \___ \| |/ _` |/ _ \ |/ / |/ _` |
hellorails-worker-1    |                 $$:         ___) | | (_| |  __/   <| | (_| |
hellorails-worker-1    |                 $$         |____/|_|\__,_|\___|_|\_\_|\__, |
hellorails-worker-1    |               .d$$                                       |_|
hellorails-worker-1    |
hellorails-worker-1    |
hellorails-worker-1    | 2023-03-18T18:59:21.877Z pid=1 tid=2mh INFO: Booted Rails 7.0.4.2 application in development environment
hellorails-worker-1    | 2023-03-18T18:59:21.877Z pid=1 tid=2mh INFO: Running in ruby 3.2.1 (2023-02-08 revision 31819e82c8) [x86_64-linux]
hellorails-worker-1    | 2023-03-18T18:59:21.877Z pid=1 tid=2mh INFO: See LICENSE and the LGPL-3.0 for licensing details.
hellorails-worker-1    | 2023-03-18T18:59:21.877Z pid=1 tid=2mh INFO: Upgrade to Sidekiq Pro for more features and support: https://sidekiq.org
hellorails-worker-1    | 2023-03-18T18:59:21.878Z pid=1 tid=2mh INFO: Sidekiq 7.0.6 connecting to Redis with options {:size=>5, :pool_name=>"internal", :url=>"redis://redis:6379/1"}
hellorails-worker-1    | 2023-03-18T18:59:21.885Z pid=1 tid=2mh INFO: Sidekiq 7.0.6 connecting to Redis with options {:size=>5, :pool_name=>"default", :url=>"redis://redis:6379/1"}
hellorails-worker-1    | 2023-03-18T18:59:21.886Z pid=1 tid=2mh INFO: Starting processing, hit Ctrl-C to stop
hellorails-cable-1     | * Listening on http://0.0.0.0:28080
hellorails-cable-1     | Use Ctrl-C to stop

And after hitting the home page in a browser:

hellorails-web-1       | Started GET "/" for 172.25.0.1 at 2023-03-18 19:00:18 +0000
hellorails-web-1       | Processing by PagesController#home as HTML
hellorails-web-1       |   Rendering layout layouts/application.html.erb
hellorails-web-1       |   Rendering pages/home.html.erb within layouts/application
hellorails-web-1       |   Rendered pages/home.html.erb within layouts/application (Duration: 2.0ms | Allocations: 645)
hellorails-web-1       |   Rendered layout layouts/application.html.erb (Duration: 6.0ms | Allocations: 2227)
hellorails-web-1       | Completed 200 OK in 7ms (Views: 6.9ms | ActiveRecord: 0.0ms | Allocations: 2443)
Ikariusrb commented 1 year ago

On my system, the output from docker compose up --build stops after the line hellorails-redis-1 | 1:M 18 Mar 2023 18:59:19.043 * Ready to accept connections and subsequently only shows output from postgres and redis; mostly it shows periodic postgres tasks occurring. Web requests don't show up, nothing. I'm able to grab logs from the containers via docker logs <CONTAINERID>. I was able to get the output to show normally by removing tty=true options from the docker compose yaml- there're a couple scattered, but the important one which impacted web, sidekiq and cable was in the default-app section. I made no changes to anything beyond cloning the repo and running the bringup commands as documented.

I'm running on MacOS Monterey, docker version 4.6.0, running in iTerm2, and my shell is zsh.

nickjj commented 1 year ago

Do you see output for tailwind and esbuild? Both of them have tty: true set as well as web + worker + cable, but Postgres and Redis do not.

Ikariusrb commented 1 year ago

Nope, don't have any output for either of those either, aside from the docker image build bits that I believe come from docker itself. I'm currently downloading more recent version of docker to see if that changes the behavior.

Ikariusrb commented 1 year ago

OK then, it appears that it was the old version of docker causing this. I updated to 4.17, and the behavior is now fixed. My apologies, I thought I'd only installed Docker last week, it must have been sitting around on my machine for a while.

nickjj commented 1 year ago

It's all good. I'm kind of surprised that setting would cause no logs to be produced. I've used that setting for more than a year and logs were produced. In any case, glad to hear it's working for you.