Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Logging to STDOUT in a ruby program (not working in Docker)

I'm dockerizing one of my ruby apps, but I've got this very strange logging behavior. It only seems to load when the program ENDS not while it's running. When I run the program (daemon) with docker-compose all I see is this:

Starting custom_daemon_1
Attaching to custom_daemon_1

However, if I put an exit part way into the program I see all my puts and logger outputs.

Starting custom_daemon_1
Attaching to custom_daemon_1
custom_daemon_1  | requires
custom_daemon_1  | starting logger
custom_daemon_1  | Starting loads
custom_daemon_1  | Hello base
custom_daemon_1  | Loaded track
custom_daemon_1  | Loaded geo
custom_daemon_1  | Loaded geo_all
custom_daemon_1  | Loaded unique
custom_daemon_1  | D, [2016-11-14T13:31:19.295785 #1] DEBUG -- : Starting custom_daemon...
custom_daemon_1  | D, [2016-11-14T13:31:19.295889 #1] DEBUG -- : Loading xx from disk...
custom_daemon_1 exited with code 0

The top ones without times were just puts debugging, seeing if it would show - the bottom two are created by:

Logger.new(STDOUT)
LOG = Logger.new(STDOUT)
LOG.level = Logger::DEBUG

Then I would call LOG.debug "xxx" or LOG.error "xxx" any idea why this strange behavior is happening? When I ctrl+c out of the first one, the logs still do not show up.

This was originally run by a .sh script and now I've made the call to run it directly as the CMD of the Dockerfile.

There is a python question I found asking something similar here. Someone speculates it may have to do with PID 1 processes having logging to STDOUT surpressed.

Test

Here is a test I ran:

puts "starting logger"
Logger.new(STDOUT)
LOG = Logger.new(STDOUT)
LOG.level = Logger::DEBUG
puts "this is 'puts'"
p "this is 'p'"
LOG.debug "this is 'log.debug'"
puts "Starting loads"   

outputs:

custom_daemon_1  | starting logger
custom_daemon_1  | this is 'puts'
custom_daemon_1  | "this is 'p'"

Notice that the first two puts printed but as soon as I try to use LOG.debug it didn't work.

TEST 2

I also decided to try the logger using a file, and as expected it logs to the file just fine, through docker.

All I did was change Logger.new(STDOUT) to Logger.new('mylog.log') and I can tail -f mylog.log and all the LOG.debug prompts show up.

like image 418
Jono Avatar asked Jan 06 '23 01:01

Jono


1 Answers

As say in this thread Log issue in Rails4 with Docker running rake task

Try disabling output buffering to STDOUT: $stdout.sync = true

like image 123
gagalago Avatar answered Jan 13 '23 19:01

gagalago