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.

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

Echoing to /dev/stdout does not appear in 'docker logs' #19616

Closed
geekscrapy opened this issue Jan 24, 2016 · 19 comments
Closed

Echoing to /dev/stdout does not appear in 'docker logs' #19616

geekscrapy opened this issue Jan 24, 2016 · 19 comments

Comments

@geekscrapy
Copy link

Whilst attempting to symlink a log file in /var/logs/ to /dev/stdout the logs do not appear in 'docker logs'.

I have also attempted simply just echoing into /dev/stdout but it is just echo'd back to the terminal.

# docker info
Containers: 2
Images: 95
Server Version: 1.9.1
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 99
 Dirperm1 Supported: false
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 3.13.0-52-generic
Operating System: Ubuntu 14.04.3 LTS
CPUs: 1
Total Memory: 994 MiB
Name: XXX
ID: 7SC5:COW6:LFBN:33OV:NJN5:X7D6:U4SG:2DBJ:ZP5T:AZ6G:6JCN:SDC5
WARNING: No swap limit support

# docker version
Client:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:12:04 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 13:12:04 UTC 2015
 OS/Arch:      linux/amd64

Hosted with DigitalOcean, pretty vanilla ubuntu image.

Reproduction steps:

Dockerfile:

FROM ubuntu:latest

# Run the wrapper script (to keep the container alive)
COPY daemon.sh /usr/bin/daemon.sh
RUN chmod +x /usr/bin/daemon.sh

# Create the pesudo log file to point to stdout
RUN ln -sf /dev/stdout /var/log/test.log

# Create a cronjob to echo into the logfile just created
RUN echo '* * * * * root `date` > /var/log/test.log' > /etc/crontab

ENTRYPOINT ["/usr/bin/daemon.sh"]

daemon.sh

#!/bin/bash

# Start cron
cron

# Script to keep the container alive
while : ; do
    sleep 3
    echo FROM keepalive script: `date` > /var/log/test.log
done

Run with: docker build -t test . ; docker run -d --name=test1 test

Results received: Logs from the daemon.sh 'keepalive' script are shown in 'docker logs'
Results expected: Logs from the cron job to also show in 'docker logs'

For ref, I originally opened a stackexchange question here: http://stackoverflow.com/questions/34950465/logging-from-multiprocess-docker-containers

@GordonTheTurtle
Copy link

If you are reporting a new issue, make sure that we do not have any duplicates already open. You can ensure this by searching the issue list for this repository. If there is a duplicate, please close your issue and add a comment to the existing issue instead.

If you suspect your issue is a bug, please edit your issue description to include the BUG REPORT INFORMATION shown below. If you fail to provide this information within 7 days, we cannot debug your issue and will close it. We will, however, reopen it if you later provide the information.

For more information about reporting issues, see CONTRIBUTING.md.

You don't have to include this information if this is a feature request

(This is an automated, informational response)


BUG REPORT INFORMATION

Use the commands below to provide key information from your environment:

docker version:
docker info:

Provide additional environment details (AWS, VirtualBox, physical, etc.):

List the steps to reproduce the issue:
1.
2.
3.

Describe the results you received:

Describe the results you expected:

Provide additional info you think is important:

----------END REPORT ---------

#ENEEDMOREINFO

@cpuguy83
Copy link
Member

Can you provide an example?

@geekscrapy
Copy link
Author

Just added the required info :)

@cpuguy83
Copy link
Member

This is because /dev/stdout is a device and can't be linked to like this in the image.
This should work if you move the symlink to daemon.sh.

@geekscrapy
Copy link
Author

I moved the symlink creation to daemon.sh and it still fails to produce anything in 'docker logs'. However if I remove the symlink so it just writes to the /var/log/test.log file it writes just fine.

Why does this work in the nginx dockerfile?

https://github.com/nginxinc/docker-nginx/blob/a8b6da8425c4a41a5dedb1fb52e429232a55ad41/Dockerfile

@geekscrapy
Copy link
Author

FYI: I also just tried to use FROM nginx (including installing cron in the image) and still no logs show from the cronjob.

Can I suggest this is re-opened please?

@bamarni
Copy link
Contributor

bamarni commented Jan 24, 2016

I think the main difference with the nginx image is that it only has one main process in the foreground, while in your case you have daemon.sh but also cronjobs running in the background.

For communication between them and daemon.sh, it might be more suited to use a named pipe. Eg. something like this in the beginning of daemon.sh :

mkfifo /var/log/test.log
tail -f /var/log/test.log &

@phemmer
Copy link
Contributor

phemmer commented Jan 25, 2016

The reason this doesn't work is because /dev/stdout is a link to STDOUT of the process accessing it. So by doing foo > /dev/stdout, you're saying "redirect my STDOUT to my STDOUT". Kinda doesn't do anything :-).
And since /var/log/test.log is a symlink to it, the same thing applies.

What you want is to redirect output to STDOUT of PID 1. PID 1 is the process launched by docker, and its STDOUT will be what docker picks up.
Thus if you instead do

RUN ln -sf /proc/1/fd/1 /var/log/test.log

you'll see it works just fine.

Note however this will only work if you don't launch your container with --pid=host. If you do, you'll need to set up the symlink in your daemon.sh script with something such as:

ln -sf /proc/$$/fd/1 /var/log/test.log

@geekscrapy
Copy link
Author

Ok i must be missing something, as my /dev/stdout has a symlink to /proc/1/fd/1 by default... That's what comes as vanilla with Ubuntu and debian containers. If it didn't already have the symlink I'd get what you mean, but it does :)

I believe I have already tried this but I will confirm when I have access later.

@phemmer
Copy link
Contributor

phemmer commented Jan 25, 2016

/dev/stdout is a symlink to /proc/self/fd/1, not /proc/1/fd/1. Subtle, but very significant difference.

@geekscrapy
Copy link
Author

Ok... Agree I'm seeing it now. However, I'm now getting permission errors when writing to /proc/1/fd/1 .

$ docker exec -it test1 bash
root@55a27c41b408:/# echo "log me" > /var/log/test.log 
bash: /var/log/test.log: Permission denied
root@55a27c41b408:/#

The modified Dockerfile to reflect the changes (aka what I have been taught...! Appreciate it btw!)

Dockerfile

FROM ubuntu:latest

# Run the wrapper script (to keep the container alive)
ADD daemon.sh /usr/bin/daemon.sh
RUN chmod +x /usr/bin/daemon.sh

# Create the pseudo log file to point to stdout
RUN ln -sf /proc/1/fd/1 /var/log/test.log

# Create a cronjob to echo into the logfile just created
RUN echo '* * * * * root date >> /var/log/test.log' > /etc/crontab

CMD "/usr/bin/daemon.sh"

@geekscrapy
Copy link
Author

This might have something to do with apparmor, getting these logs:

Jan 25 10:00:44 XXX kernel: [ 6227.900201] type=1400 audit(1453734044.456:897): apparmor="DENIED" operation="ptrace" profile="docker-default" pid=5966 comm="daemon.sh" requested_mask="read" denied_mask="read" peer="docker-default"

@geekscrapy
Copy link
Author

Got it. Disabling the apparmor docker profile allows this to work.

Related: #7276

Having said this, I don't like the idea of modifying the apparmor profile just for this, so I'm going to utilise @bamarni method with mkfifo for now.

Thanks!

@elifarley
Copy link

elifarley commented Jul 1, 2016

I guess there's no need to call mkfifo, since this seems to work fine:

echo "Hello" > /dev/console

Edit: Only if TTY is available (-t); See also: #6880

@bamarni
Copy link
Contributor

bamarni commented Jul 2, 2016

@elifarley : thanks for the tip, works for me too!

For the record, in my case /proc/1/fd/1 was also failing, but unlike @geekscrapy not because of apparmor. I was trying to enable altlog for pureftp (logs about file transfers) but it didn't work with /dev/stdout nor /proc/1/fd/1.

After looking at the source code here, I thought the reason it fails is because stdout is not seekable, so I ended up using a fifo (as there is an exception for ESPIPE).

Just to get the bottom of this... Does it mean that /proc/1/fd/1 is a special kernel file while /dev/console is considered as some sort of pipe?

@christhomas
Copy link

Wouldn't a PHP FPM processes stdout be where it writes the output from whatever script it runs? Therefore there is no stdout as you expect there to be. Only stderr, thats why you can write to /2, but not to /1

Isn't that how it works?

@gowtamjetti
Copy link

Hi,
When I symlink my log file to /proc/1/fd/1, it gives an error saying permission denied, as only root user and the process that has PID 1 are supposed to have permissions to write to it. How can one solve that issue? Or how did you go ahead to ensure a problem with permissions didn't occur in your case?

@zrss
Copy link

zrss commented Jan 29, 2019

quite a nice topic, thx

stoksc added a commit to determined-ai/determined that referenced this issue Sep 30, 2020
This change starts Horovod worker processes with their output streams redirected to the output streams of the main process of the container they are in, so that logs do not go through agent zero and are available through standard docker logging.

There were several ways to do the redirection. We could redirect in `worker_process.py`, either with the contextlib or dup'ing the file descriptors or do the redirection in a shell script, or you could do it in a python script (once again by dup'ing file descriptors). A python script was determined to be the simplest, to avoid `contextlib.redirect_stdout` not being respected, packaging woes of a shell script and dup'ing file descriptors in `worker_process.py` being a bit more tricky (in regard to things logging before the swap (imports) resulting in potentially misleading logs).

See moby/moby#19616 for more around what informed the choices made here.
@ghost
Copy link

ghost commented Feb 2, 2021

Hi,
When I symlink my log file to /proc/1/fd/1, it gives an error saying permission denied, as only root user and the process that has PID 1 are supposed to have permissions to write to it. How can one solve that issue? Or how did you go ahead to ensure a problem with permissions didn't occur in your case?

Did you manage to sort out the permissions issue?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

10 participants