Docker Community Forums

Share and learn in the Docker community.

Docker.log filling hard drive


(Breerly) #1

Expected behavior

docker.log is managed so that it does not grow without bounds

Actual behavior

docker.log grows without bounds, taking 310GB of space.

Information

~ » pinata diagnose -u
OS X: version 10.11.5 (build: 15F34)
Docker.app: version v1.11.1-beta13
Running diagnostic tests:
[OK]      Moby booted
[OK]      driver.amd64-linux
[OK]      vmnetd
[OK]      osxfs
[OK]      db
[OK]      slirp
[OK]      menubar
[OK]      environment
[OK]      Docker
[OK]      VT-x

Steps to reproduce the behavior

Use docker for several months, behold logs:

~ » head -n 50 ~/.Trash/docker.log
time="2016-04-15T23:59:27.173802745Z" level=warning msg="/!\\ DON'T BIND ON ANY IP ADDRESS WITHOUT setting -tlsverify IF YOU DON'T KNOW WHAT YOU'RE DOING /!\\"
time="2016-04-15T23:59:27.174235875Z" level=debug msg="Listener created for HTTP on tcp (0.0.0.0:2375)"
time="2016-04-15T23:59:27.174549371Z" level=debug msg="docker group found. gid: 50"
time="2016-04-15T23:59:27.174865704Z" level=debug msg="Listener created for HTTP on unix (/var/run/docker.sock)"
time="2016-04-15T23:59:27.175557681Z" level=info msg="New containerd process, pid: 1334\n"
time="2016-04-15T23:59:27.176863889Z" level=debug msg="containerd connection state change: TRANSIENT_FAILURE"
time="2016-04-15T23:59:27Z" level=debug msg="containerd: read past events" count=0
time="2016-04-15T23:59:27Z" level=debug msg="containerd: supervisor running" cpus=4 memory=2003 runtime=docker-runc runtimeArgs=[] stateDir="/run/containerd"
time="2016-04-15T23:59:27Z" level=debug msg="containerd: grpc api on /var/run/docker/libcontainerd/docker-containerd.sock"
time="2016-04-15T23:59:28.183278947Z" level=debug msg="Using default logging driver json-file"
time="2016-04-15T23:59:28.183892913Z" level=debug msg="Golang's threads limit set to 13950"
time="2016-04-15T23:59:28.184481428Z" level=debug msg="[graphdriver] trying provided driver \"aufs\""
time="2016-04-15T23:59:28.183569605Z" level=debug msg="received past containerd event: &types.Event{Type:\"live\", Id:\"\", Status:0x0, Pid:\"\", Timestamp:0x57118060}"
time="2016-04-15T23:59:28.188150821Z" level=debug msg="Using graph driver aufs"
time="2016-04-15T23:59:28.240670780Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2016-04-15T23:59:28.241574965Z" level=debug msg="Option DefaultDriver: bridge"
time="2016-04-15T23:59:28.242174071Z" level=debug msg="Option DefaultNetwork: bridge"
time="2016-04-15T23:59:28.244704424Z" level=warning msg="Running modprobe nf_nat failed with message: `modprobe: WARNING: Module nf_nat not found in directory /lib/modules/4.4.6`, error: exit status 1"
time="2016-04-15T23:59:28.246441041Z" level=warning msg="Running modprobe xt_conntrack failed with message: `modprobe: WARNING: Module xt_conntrack not found in directory /lib/modules/4.4.6`, error: exit status 1"
time="2016-04-15T23:59:28.246827832Z" level=debug msg="Fail to initialize firewalld: Failed to connect to D-Bus system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory, using raw iptables instead"
time="2016-04-15T23:59:28.248327421Z" level=debug msg="/sbin/iptables, [--wait --version]"
time="2016-04-15T23:59:28.249666995Z" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2016-04-15T23:59:28.251046386Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER]"
time="2016-04-15T23:59:28.252266732Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER]"
time="2016-04-15T23:59:28.253494347Z" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING]"
time="2016-04-15T23:59:28.254657266Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT]"
time="2016-04-15T23:59:28.255732199Z" level=debug msg="/sbin/iptables, [--wait -t nat -F DOCKER]"
time="2016-04-15T23:59:28.256856242Z" level=debug msg="/sbin/iptables, [--wait -t nat -X DOCKER]"
time="2016-04-15T23:59:28.257972517Z" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER]"
time="2016-04-15T23:59:28.259420282Z" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER]"
time="2016-04-15T23:59:28.260526285Z" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION]"
time="2016-04-15T23:59:28.261637088Z" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION]"
time="2016-04-15T23:59:28.262750665Z" level=debug msg="/sbin/iptables, [--wait -t nat -n -L DOCKER]"
time="2016-04-15T23:59:28.263838945Z" level=debug msg="/sbin/iptables, [--wait -t nat -N DOCKER]"
time="2016-04-15T23:59:28.264908432Z" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER]"
time="2016-04-15T23:59:28.266024150Z" level=debug msg="/sbin/iptables, [--wait -t filter -N DOCKER]"
time="2016-04-15T23:59:28.267060969Z" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION]"
time="2016-04-15T23:59:28.268078243Z" level=debug msg="/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION]"
time="2016-04-15T23:59:28.269396074Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -j RETURN]"
time="2016-04-15T23:59:28.270736900Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -j RETURN]"
time="2016-04-15T23:59:28.307260189Z" level=debug msg="Registering ipam driver: \"default\""
time="2016-04-15T23:59:28.308173508Z" level=debug msg="Registering ipam driver: \"null\""
time="2016-04-15T23:59:28.314791128Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2016-04-15T23:59:28.315405397Z" level=debug msg="Allocating IPv4 pools for network bridge (027f14e8a6bbfd6016bf8cd244af926c83e34694eb68218934fef012de589730)"
time="2016-04-15T23:59:28.315884837Z" level=debug msg="RequestPool(LocalDefault, 172.17.0.0/16, , map[], false)"
time="2016-04-15T23:59:28.320349514Z" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway])"
time="2016-04-15T23:59:28.321559849Z" level=debug msg="Setting bridge mac address to 02:42:be:98:84:23"
time="2016-04-15T23:59:28.321884059Z" level=debug msg="Assigning address to bridge interface docker0: 172.17.0.1/16"
time="2016-04-15T23:59:28.322180230Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2016-04-15T23:59:28.323504964Z" level=debug msg="/sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"


~ » tail -n 50 ~/.Trash/docker.log
time="2016-05-10T18:57:35.852263725Z" level=debug msg="Query python-sync.local.[1] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.852655954Z" level=debug msg="client dns id 22630, changed id 16239"
time="2016-05-10T18:57:35.853099051Z" level=debug msg="dns msg id 32153, client id 30556"
time="2016-05-10T18:57:35.854039480Z" level=debug msg="dns msg id 16239, client id 22630"
time="2016-05-10T18:57:35.854660904Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.855079497Z" level=debug msg="Lookup name python-sync. present without IPv6 address"
time="2016-05-10T18:57:35.854850008Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.855743051Z" level=debug msg="Lookup for python-sync.: IP [172.18.0.5]"
time="2016-05-10T18:57:35.857955262Z" level=debug msg="Name To resolve: node."
time="2016-05-10T18:57:35.858257039Z" level=debug msg="Lookup for node.: IP [172.18.0.6]"
time="2016-05-10T18:57:35.858022434Z" level=debug msg="Name To resolve: node."
time="2016-05-10T18:57:35.858815404Z" level=debug msg="Lookup name node. present without IPv6 address"
time="2016-05-10T18:57:35.861868126Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.862284475Z" level=debug msg="Query python-sync.local.[28] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.862639830Z" level=debug msg="client dns id 55090, changed id 45098"
time="2016-05-10T18:57:35.862145360Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.863301307Z" level=debug msg="Query python-sync.local.[1] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.863603660Z" level=debug msg="client dns id 50176, changed id 50804"
time="2016-05-10T18:57:35.864014103Z" level=debug msg="dns msg id 45098, client id 55090"
time="2016-05-10T18:57:35.864894789Z" level=debug msg="dns msg id 50804, client id 50176"
time="2016-05-10T18:57:35.865531619Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.865816644Z" level=debug msg="Lookup name python-sync. present without IPv6 address"
time="2016-05-10T18:57:35.865768373Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.866379714Z" level=debug msg="Lookup for python-sync.: IP [172.18.0.5]"
time="2016-05-10T18:57:35.868894778Z" level=debug msg="Name To resolve: node."
time="2016-05-10T18:57:35.869190814Z" level=debug msg="Lookup for node.: IP [172.18.0.6]"
time="2016-05-10T18:57:35.874932001Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.875376847Z" level=debug msg="Query python-sync.local.[28] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.875808057Z" level=debug msg="client dns id 36712, changed id 17"
time="2016-05-10T18:57:35.875196013Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.876447690Z" level=debug msg="Query python-sync.local.[1] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.876766023Z" level=debug msg="client dns id 18111, changed id 20351"
time="2016-05-10T18:57:35.877261195Z" level=debug msg="dns msg id 17, client id 36712"
time="2016-05-10T18:57:35.877862303Z" level=debug msg="dns msg id 20351, client id 18111"
time="2016-05-10T18:57:35.878364626Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.878641767Z" level=debug msg="Lookup for python-sync.: IP [172.18.0.5]"
time="2016-05-10T18:57:35.878365047Z" level=debug msg="Name To resolve: python-sync."
time="2016-05-10T18:57:35.879218209Z" level=debug msg="Lookup name python-sync. present without IPv6 address"
time="2016-05-10T18:57:35.881643595Z" level=debug msg="Name To resolve: go."
time="2016-05-10T18:57:35.882041721Z" level=debug msg="Lookup name go. present without IPv6 address"
time="2016-05-10T18:57:35.881808711Z" level=debug msg="Name To resolve: go."
time="2016-05-10T18:57:35.882667043Z" level=debug msg="Lookup for go.: IP [172.18.0.2]"
time="2016-05-10T18:57:35.885785006Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.886243060Z" level=debug msg="Query python-sync.local.[1] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.886733069Z" level=debug msg="client dns id 13536, changed id 55705"
time="2016-05-10T18:57:35.885892868Z" level=debug msg="Name To resolve: python-sync.local."
time="2016-05-10T18:57:35.887703012Z" level=debug msg="Query python-sync.local.[28] from 172.18.0.7:57321, forwarding to udp:192.168.65.1"
time="2016-05-10T18:57:35.888176455Z" level=debug msg="client dns id 45555, changed id 26846"
time="2016-05-10T18:57:35.888623341Z" level=debug msg="dns msg id 55705, client id 13536"
time="2016-05-10T18:57:35.889502003Z" level=debug msg="dns %

(Alexandre) #2

Hi,

Many people experience the same problem. There’s a thread about it here:

HTH,
Alexandre