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

Docker gets killed by SIGPIPE #7087

Closed
vincentbernat opened this Issue Jul 17, 2014 · 17 comments

Comments

Projects
None yet
@vincentbernat
Copy link
Contributor

vincentbernat commented Jul 17, 2014

Hi!

From time to time, docker running on my host is getting killed by SIGPIPE. I am running it through systemd:

docker.io.service - Docker Application Container Engine
   Loaded: loaded (/lib/systemd/system/docker.io.service; enabled)
   Active: inactive (dead) since jeu. 2014-07-17 19:33:03 CEST; 34s ago
     Docs: http://docs.docker.io
 Main PID: 29636 (code=killed, signal=PIPE)

juil. 16 00:03:34 neo docker[29636]: [466c6525] -job images() = OK (0)
juil. 16 00:03:34 neo docker[29636]: 2014/07/16 00:03:34 GET /v1.12/containers/json
juil. 16 00:03:34 neo docker[29636]: [466c6525] +job containers()
juil. 16 00:03:34 neo docker[29636]: [466c6525] -job containers() = OK (0)
juil. 16 08:48:50 neo docker[29636]: 2014/07/16 08:48:50 GET /v1.12/images/json
juil. 16 08:48:50 neo docker[29636]: [466c6525] +job images()
juil. 16 08:48:51 neo docker[29636]: [466c6525] -job images() = OK (0)
juil. 16 08:48:51 neo docker[29636]: 2014/07/16 08:48:51 GET /v1.12/containers/json
juil. 16 08:48:51 neo docker[29636]: [466c6525] +job containers()
juil. 16 08:48:51 neo docker[29636]: [466c6525] -job containers() = OK (0)

This is a very old problem that I had in early versions. I never investigated it but since it is still here, I am opening this bug report. Usually, no containers are running.

However, note that I am using 1.0.0 (from Debian unstable). 1.1.0 is not packaged yet. I have already reported the problem to Debian but got no answer yet.

@paultag

This comment has been minimized.

Copy link

paultag commented Jul 19, 2014

No diagnosis Debian side. A search reveals a similar issue, but was resolved after a systemd-44 update.

We can try setting ignore sigpipe in the service to see if that helps. I've not seen this and I run systemd :(

@vincentbernat

This comment has been minimized.

Copy link
Contributor Author

vincentbernat commented Jul 19, 2014

❦ 18 juillet 2014 18:07 -0700, Paul Tagliamonte notifications@github.com :

No diagnosis Debian side. A search reveals a similar issue, but was
resolved after a systemd-44 update.

We can try setting ignore sigpipe in the service to see if that helps.
I've not seen this and I run systemd :(

Since it seems I usually get this when using completion, I found a very
convenient way to reproduce it:

docker images | head -2

I am using the Unix socket. A usual workaround is to ignore SIGPIPE (I
do that in all my programs since there are other ways to check for EOF).

Well, I was able to reproduce it twice but then nothing more.

Don't just echo the code with comments - make every comment count.
- The Elements of Programming Style (Kernighan & Plauger)

@tianon

This comment has been minimized.

Copy link
Member

tianon commented Jul 28, 2014

I wonder if this is useful or even related: http://www.freedesktop.org/software/systemd/man/systemd.exec.html#IgnoreSIGPIPE=

IgnoreSIGPIPE=

Takes a boolean argument. If true, causes SIGPIPE to be ignored in the executed process. Defaults to true because SIGPIPE generally is useful only in shell pipelines.

Is this a recent systemd feature that might have been set to "true" by default only in newer versions of systemd, or possibly somehow got unset for Docker on your system, @vincentbernat?

@vincentbernat

This comment has been minimized.

Copy link
Contributor Author

vincentbernat commented Jul 28, 2014

❦ 28 juillet 2014 07:38 -0700, Tianon Gravi notifications@github.com :

I wonder if this is useful or even related:
http://www.freedesktop.org/software/systemd/man/systemd.exec.html#IgnoreSIGPIPE=

IgnoreSIGPIPE=

        Takes a boolean argument. If true, causes SIGPIPE to be
    ignored in the executed process. Defaults to true because
    SIGPIPE generally is useful only in shell pipelines.

Is this a recent systemd feature that might have been set to "true" by
default only in newer versions of systemd, or possibly somehow got
unset for Docker on your system, @vincentbernat?

systemctl show docker.io.service | grep SIGPIPE
IgnoreSIGPIPE=yes

So, it is set, but I am unable to reproduce the problem right now. Maybe
because of this. However, if this is the case, this should be fixed in
docker as well since not everybody uses systemd.

An easy fix would be to ignore SIGPIPE in docker. This is something
that's usually done in evented programs (I am always doing this in mine
in C). However, I don't know if this is the right idiom in Go. Moreover,
I don't find how to ignore signals in Go. It seems that we have to use a
channel just for that?

ch := make(chan os.Signal, 1) 
signal.Notify(ch, os.Signal(syscall.SIGPIPE))
for { 
    <-ch 
}

I have tried to disable IgnoreSIGPIPE but I am still unable to produce
the SIGPIPE. I thought that something like that would allow me to get
it, but nothing:

(echo 'GET /v1.12/containers/website_compass_1/json HTTP/1.0' ; echo ) | \
  socat -t 0.0001 UNIX-CONNECT:/run/docker.sock,shut-close STDIN

Use the fundamental control flow constructs.
- The Elements of Programming Style (Kernighan & Plauger)

@joeyh

This comment has been minimized.

Copy link

joeyh commented Oct 19, 2014

I have also encountered this bug. http://bugs.debian.org/764016

root@elephant:~>systemctl show docker.io.service | grep SIGPIPE
IgnoreSIGPIPE=yes

@jessfraz

This comment has been minimized.

Copy link
Contributor

jessfraz commented Feb 26, 2015

If this is a problem with the debian or ubuntu builds please file those with their bug tracker

I am not able to reproduce to latest docker version

@jessfraz jessfraz closed this Feb 26, 2015

@stefwalter

This comment has been minimized.

Copy link

stefwalter commented Mar 5, 2015

I've seen this issue on Fedora 21 with docker-io-1.5.0-1.fc21.x86_64

It doesn't seem to be Debian or Ubuntu specific. And yes:

$ systemctl show docker.service | grep PIPE
IgnoreSIGPIPE=yes
@stefwalter

This comment has been minimized.

Copy link

stefwalter commented Mar 5, 2015

The status of the docker service seems to show that it just died somewhere without leaving a coherent message:

● docker.service - Docker Application Container Engine
   Loaded: loaded (/usr/lib/systemd/system/docker.service; enabled)
   Active: inactive (dead) since Do 2015-03-05 16:45:55 UTC; 31s ago
     Docs: http://docs.docker.com
 Main PID: 25138 (code=killed, signal=PIPE)

Mär 05 16:41:55 stefw-node-1 docker[25138]: time="2015-03-05T16:41:55Z" level="info" msg="-job version() = OK (0)"
Mär 05 16:41:59 stefw-node-1 docker[25138]: time="2015-03-05T16:41:59Z" level="info" msg="GET /containers/json?all=1"
Mär 05 16:41:59 stefw-node-1 docker[25138]: time="2015-03-05T16:41:59Z" level="info" msg="+job containers()"
Mär 05 16:41:59 stefw-node-1 docker[25138]: time="2015-03-05T16:41:59Z" level="info" msg="-job containers() = OK (0)"
Mär 05 16:42:00 stefw-node-1 docker[25138]: time="2015-03-05T16:42:00Z" level="info" msg="GET /containers/json"
Mär 05 16:42:00 stefw-node-1 docker[25138]: time="2015-03-05T16:42:00Z" level="info" msg="+job containers()"
Mär 05 16:42:00 stefw-node-1 docker[25138]: time="2015-03-05T16:42:00Z" level="info" msg="-job containers() = OK (0)"
Mär 05 16:42:06 stefw-node-1 docker[25138]: time="2015-03-05T16:42:05Z" level="info" msg="GET /version"
Mär 05 16:42:06 stefw-node-1 docker[25138]: time="2015-03-05T16:42:05Z" level="info" msg="+job version()"
Mär 05 16:42:06 stefw-node-1 docker[25138]: time="2015-03-05T16:42:06Z" level="info" msg="-job version() = OK (0)"
@jimmidyson

This comment has been minimized.

Copy link

jimmidyson commented Apr 23, 2015

I have exactly the same issue as @stefwalter on Fedora 21 so agree it seems like a cross-distro issue.

@jfrazelle - could we re-open this issue please?

@LK4D4

This comment has been minimized.

Copy link
Contributor

LK4D4 commented Apr 23, 2015

Any go program will die if it will try to write to same broken pipe ten times :) I wonder where this pipe is.

@sahus5

This comment has been minimized.

Copy link

sahus5 commented Apr 23, 2015

I am also seeing this in many of my nodes in the cluster running docker 1.4.1 on SLES12

service docker status

docker.service - Docker
Loaded: loaded (/usr/lib/systemd/system/docker.service; enabled)
Active: inactive (dead) since Wed 2015-04-22 23:04:39 UTC; 22h ago
Main PID: 64423 (code=killed, signal=PIPE)

Apr 22 23:00:10 murray-mustard docker[64423]: time="2015-04-22T23:00:07Z" level="info" msg="+job top(d9e419a69bac, )"
Apr 22 23:01:19 murray-mustard docker[64423]: time="2015-04-22T23:01:19Z" level="info" msg="GET /version"
Apr 22 23:01:19 murray-mustard docker[64423]: time="2015-04-22T23:01:19Z" level="info" msg="+job version()"
Apr 22 23:01:19 murray-mustard docker[64423]: time="2015-04-22T23:01:19Z" level="info" msg="-job version() = OK (0)"
Apr 22 23:02:27 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="GET /containers/json?limit=0&all=1&since=&before=&size=0"
Apr 22 23:02:27 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="+job containers()"
Apr 22 23:02:28 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="-job containers() = OK (0)"
Apr 22 23:02:28 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="GET /containers/d9e419a69bacb4de5e740da5b2750132b3bd00873247926aaff8db3d8534d432/json"
Apr 22 23:02:28 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="+job container_inspect(d9e419a69bacb4de5e740da5b2750132b3bd00873247926aaff8db3d8534d432)"
Apr 22 23:02:28 murray-mustard docker[64423]: time="2015-04-22T23:02:27Z" level="info" msg="-job container_inspect(d9e419a69bacb4de5e740da5b2750132b3bd00873247926aaff8db3d8534d432) = OK (0)"

systemctl show docker.io.service | grep SIGPIPE

IgnoreSIGPIPE=yes

@jimmidyson

This comment has been minimized.

Copy link

jimmidyson commented May 6, 2015

Still seeing this with docker-io-1.6.0-2.git3eac457.fc21.x86_64 on Fedora 21.

● docker.service - Docker Application Container Engine
   Loaded: loaded (/usr/lib/systemd/system/docker.service; enabled)
   Active: inactive (dead) since Tue 2015-05-05 21:19:24 UTC; 11h ago
     Docs: http://docs.docker.com
  Process: 783 ExecStart=/usr/bin/docker -d $OPTIONS $DOCKER_STORAGE_OPTIONS $DOCKER_NETWORK_OPTIONS $INSECURE_REGISTRY (code=killed, signal=PIPE)
 Main PID: 783 (code=killed, signal=PIPE)

May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="+job containers()"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="-job containers() = OK (0)"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="GET /containers/json"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="+job containers()"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="-job containers() = OK (0)"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="GET /containers/json"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="+job containers()"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="-job containers() = OK (0)"
May 05 21:18:19 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="GET /containers/json"
May 05 21:19:24 jimmi-docker-2.osop.rhcloud.com docker[783]: time="2015-05-05T21:18:19Z" level=info msg="+job containers()"
@paulmenzel

This comment has been minimized.

Copy link

paulmenzel commented Sep 18, 2015

@jfrazelle, please reopen this issue as your reasoning for closing it has been proven to be incorrect.

@kbrwn

This comment has been minimized.

Copy link

kbrwn commented Oct 5, 2015

I was able to reproduce this issue on CoreOS (766.4.0 and 815.0.0) and Ubuntu 15.04. With docker 1.7.1 and docker 1.8.2. Strace of the docker daemon reveals a SIGPIPE failure when the systemd-journald.service is killed.

https://gist.github.com/kbrwn/2b9849e0e5a9823d6618

Seems like it must be related to this golang issue: golang/go#11845

@the-nw1-group

This comment has been minimized.

Copy link

the-nw1-group commented Mar 23, 2016

I'm seeing this also on Centos 7.2, since upgrading docker to 1.10.3. I couldn't find anything in the logs, and systemctl status docker shows:

[xyz@vm-nds-bld02 ~]$ systemctl status docker
● docker.service - Docker Application Container Engine
   Loaded: loaded (/usr/lib/systemd/system/docker.service; enabled; vendor preset: disabled)
  Drop-In: /etc/systemd/system/docker.service.d
           └─tls.conf
   Active: inactive (dead) since Wed 2016-03-23 09:28:08 GMT; 17min ago
     Docs: https://docs.docker.com
  Process: 17265 ExecStart=/usr/bin/docker daemon -D --tls=true --tlsverify=true --tlscacert=/etc/docker/ca.pem --tlscert=/etc/docker/server-cert.pem --tlskey=/etc/docker/server-key.pem -H=0.0.0.0:2376 (code=killed, signal=PIPE)
 Main PID: 17265 (code=killed, signal=PIPE)

Mar 23 07:27:31 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:31.903992478Z" level=debug msg="Lookup for ndspublicengagement_ui_0.0.547_autotest.: IP 172.18.0.2"
Mar 23 07:27:32 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:32.523597013Z" level=debug msg="Querying ext dns udp:10.102.16.75 for ndspublicengagement_ui_0.0.547_autotest.[28]"
Mar 23 07:27:32 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:32.523846584Z" level=debug msg="To resolve: ndspublicengagement_ui_0.0.547_autotest in "
Mar 23 07:27:32 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:32.523945911Z" level=debug msg="Lookup for ndspublicengagement_ui_0.0.547_autotest.: IP 172.18.0.2"
Mar 23 07:27:34 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:34.349977031Z" level=debug msg="Querying ext dns udp:10.102.16.75 for ndspublicengagement_ui_0.0.547_autotest.[28]"
Mar 23 07:27:34 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:34.350164918Z" level=debug msg="To resolve: ndspublicengagement_ui_0.0.547_autotest in "
Mar 23 07:27:34 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:34.350245256Z" level=debug msg="Lookup for ndspublicengagement_ui_0.0.547_autotest.: IP 172.18.0.2"
Mar 23 07:27:35 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:35.176180876Z" level=debug msg="Querying ext dns udp:10.102.16.75 for ndspublicengagement_ui_0.0.547_autotest.[28]"
Mar 23 07:27:35 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:35.176257669Z" level=debug msg="To resolve: ndspublicengagement_ui_0.0.547_autotest in "
Mar 23 07:27:35 vm-nds-bld02 docker[17265]: time="2016-03-23T07:27:35.176344040Z" level=debug msg="Lookup for ndspublicengagement_ui_0.0.547_autotest.: IP 172.18.0.2"

uname -a output:

Linux vm-nds-bld02 3.10.0-327.4.5.el7.x86_64 #1 SMP Mon Jan 25 22:07:14 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
@martynd

This comment has been minimized.

Copy link

martynd commented Sep 2, 2016

I know this comment is regarding k8s not docker, but the similarities between how it appears in the service status along with the go issue, I thought perhaps there is relevant overlap

K8s v1.3.6 on Cent7.1
● kube-apiserver.service - Kubernetes API Server Main PID: 10815 (code=killed, signal=PIPE)

It also had ignore SIGPIPE set.

The reason for my instance at least was the OOMkiller:
[2927539.378591] Out of memory: Kill process 18298 (kube-apiserver) score 209 or sacrifice child
[2927539.379046] Killed process 18298 (kube-apiserver) total-vm:7145416kB, anon-rss:7050004kB, file-rss:0kB

Since i didnt see any system logs here, just the service or docker logs I thought I would throw it out there given the similar manner of manifestation and similar lack of anything

@elouanKeryell-Even

This comment has been minimized.

Copy link

elouanKeryell-Even commented Aug 11, 2017

I'm using docker 1.12 and I'm not witnessing this issue: I manually stopped journald, and docker didn't crash.

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