Docker running on high CPU and crashes in the end

[michaelarnauts]

Output of docker version:

Client:
 Version:      1.10.3
 API version:  1.22
 Go version:   go1.5.3
 Git commit:   20f81dd
 Built:        Thu Mar 10 15:59:07 2016
 OS/Arch:      linux/amd64

Server:
 Version:      1.10.3
 API version:  1.22
 Go version:   go1.5.3
 Git commit:   20f81dd
 Built:        Thu Mar 10 15:59:07 2016
 OS/Arch:      linux/amd64

Output of docker info:

Containers: 13
 Running: 1
 Paused: 0
 Stopped: 12
Images: 342
Server Version: 1.10.3
Storage Driver: aufs
 Root Dir: /var/lib/docker/aufs
 Backing Filesystem: extfs
 Dirs: 324
 Dirperm1 Supported: true
Execution Driver: native-0.2
Logging Driver: json-file
Plugins: 
 Volume: local
 Network: host bridge null
Kernel Version: 4.2.0-30-generic
Operating System: Ubuntu 15.10
OSType: linux
Architecture: x86_64
CPUs: 8
Total Memory: 7.705 GiB
Name: michael-OptiPlex-9020
ID: CKKO:NBNN:RDYO:QQAK:JFAX:6NA3:DLSP:HTGG:7OFX:RI5Y:U6O7:IAKU
WARNING: No swap limit support

Additional environment details (AWS, VirtualBox, physical, etc.):
Happens with a docker running on a physical machine, but also in a VirtualBox.
CPU of physical machine: Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz

Steps to reproduce the issue:

1. Build the Dockerfile below
2. Run it
3. Observe high CPU usage of the asterisk process, but also of the docker daemon.
4. Docker daemon will keep on eating CPU and memory, until it crashes

Describe the results you received:

$ ps aux | grep asterisk
root     25881 99.2  0.5 3349604 42808 ?       Rsl  12:15   0:29 asterisk -c
$ ps aux | grep docker
root     25729 77.0  0.8 767488 72268 ?        Ssl  12:15   0:29 /usr/bin/docker daemon -H fd://
$ docker ps
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES
6cf222d88133        aa02e2b83b5c        "asterisk -c"       9 minutes ago       Up 9 minutes        80/tcp, 5060/tcp    loving_yalow
$ docker stop loving_yalow
Failed to stop container (loving_yalow): An error occurred trying to connect: Post http://%2Fvar%2Frun%2Fdocker.sock/v1.22/containers/loving_yalow/stop?t=10: net/http: transport closed before response was received

Describe the results you expected:

$ ps aux | grep asterisk
root     25881  0.2  0.5 3349604 42808 ?       Rsl  12:15   0:29 asterisk -c
$ ps aux | grep docker
root     25729  0.1  0.8 767488 72268 ?        Ssl  12:15   0:29 /usr/bin/docker daemon -H fd://

Additional information you deem important (e.g. issue happens only occasionally):

I've already tried removing all files in /var/lib/docker. Also running inside a clean Ubuntu 14.04 VirtualBox gives the same results.

Dockerfile:

FROM ubuntu:14.04
MAINTAINER Michaël Arnauts <michael.arnauts@staff.destiny.be>

# Install packages
RUN DEBIAN_FRONTEND=noninteractive apt-get update && apt-get -y install \
    asterisk \
    && apt-get clean \
    && rm -rf /var/lib/apt/lists/*

# Expose ports
EXPOSE 5060

CMD ["asterisk", "-c"]

[michaelarnauts]

Hmm, I've noticed that running asterisk with -f instead of -c, fixes this issue, but it still doesn't explain why the docker daemon keeps on running on high CPU, and keeps on allocating memory.

FROM ubuntu:14.04
MAINTAINER Michaël Arnauts <michael.arnauts@staff.destiny.be>

# Install packages
RUN DEBIAN_FRONTEND=noninteractive apt-get update && apt-get -y install \
    asterisk \
    && apt-get clean \
    && rm -rf /var/lib/apt/lists/*

# Expose ports
EXPOSE 5060

CMD ["asterisk", "-f"]

[ianblenke]

Asterisk console mode just outputs "\r\n" as fast as it possibly can. Docker just loops reading those CRLF pairs faster than it can output them. There is always something there for it to read, this is why it spins at 100%. There is no way to output it as fast as it can write it, that is why the memory footprint of the docker daemon balloons until it OOMs.

The fix is indeed to disable Asterisk console mode (don't use "-c" when running under docker, ever). I want to say this is an Asterisk bug, but even at 100% CPU use to keep up, Docker really should quash these duplicates somehow as well to avoid logging buffer explosion.

[cpuguy83]

+1 we should prevent this from breaking Docker.

[unclejack]

@michaelarnauts Could you tell me how you've started that container, please? I'm currently running an image which uses -c based on your Dockerfile and nothing is crashing here. The memory usage isn't growing for either of the two daemons (Docker and asterisk), but CPU usage is 100% of one core for each of the two daemons.

[michaelarnauts]

@ianblenke That sounds logical, although I don't see any log messages scroll by when I run a docker logs.
@unclejack I've started it with docker-compose (along with some other containers of the same type), where I just map a volume on /etc/asterisk to a local folder for easier development, but I also saw it happen when I start one just with docker run xxx. You might need to keep it running for a while, but you will see the response of a docker ps, or docker exec -it xxx bash responding slower and slower.

Edit: It also helps to run it in a VM with only one CPU core, and a limited amount of memory.

[unclejack]

@michaelarnauts Could you tell me the exact options you've passed to docker run, please? I've tried docker run -d asterisk and it ran for about 30 minutes without seeing an increase in memory usage.

[michaelarnauts]

I've started it trough docker-compose with docker-compose up.

version: '2'

services:
 core:
  build: core
  volumes:
  - ./core/config:/etc/asterisk/
  - ./core:/opt/core/
  mem_limit: 1g

With the following Dockerfile in core/.

FROM ubuntu:14.04
MAINTAINER Michaël Arnauts <michael.arnauts@staff.destiny.be>

# Install packages
RUN DEBIAN_FRONTEND=noninteractive apt-get update && apt-get -y install \
    asterisk \
    curl \
    git \
    lamp-server^ \
    libmyodbc \
    php5-curl \
    && apt-get clean \
    && rm -rf /var/lib/apt/lists/*
RUN a2enmod rewrite

# Create local user to run apache as
RUN addgroup --gid 1000 destiny \
    && adduser --gecos "" --uid 1000 --gid 1000 --disabled-password destiny \
    && echo export APACHE_RUN_USER=destiny >> /etc/apache2/envvars \
    && echo export APACHE_RUN_GROUP=destiny >> /etc/apache2/envvars

# Add files
ADD . /opt/core/
ADD config/* /etc/asterisk/
ADD docker/start.sh /start.sh

# Fix permissions
RUN chown -R asterisk:asterisk /etc/asterisk/
RUN chmod +x /start.sh

# Expose ports
EXPOSE 5060
EXPOSE 80

WORKDIR /var/lib/asterisk

CMD ["/start.sh"]

And the following core/docker/start.sh

#!/bin/bash

service apache2 start
service mysql start
exec asterisk -c

[cpuguy83]

@michaelarnauts as stated, you can't use -c otherwise it will utterly destroy the container logs consumer in docker.

[michaelarnauts]

@cpuguy83, sure -f works fine, it's what I'm using now. But a -c shouldn't crash the docker daemon.

[cpuguy83]

Yep, we know what the issue is, just not an entirely simple fix.

[cpuguy83]

This is fixed. dockerd will now break up extremely long lines so a container's output cannot overwhelm the daemon.
Should be fixed as of 1.13 IIRC.