What's ReleaseAddress / RequestAddress doing on Linux?

Hi,

We're running plain docker engine on Ubuntu 16.04 and since we upgraded to 17.03.1 ee we're experiencing an issue with IP tables, essentially, some custom DNAT IP table rules that we create for routing traffic to/from the container IP address are being removed and I my only hint is that somehow docker is cleaning them up at some point (maybe container or docker engine restart).

To make further progress in our troubleshooting I would like to know what these lines means in syslog:

Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.836206790Z" level=debug msg="ReleaseAddress(LocalDefault/174.17.0.0/16, 174.17.26.1)"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.157956063Z" level=debug msg="RequestAddress(LocalDefault/174.17.0.0/16, 174.17.26.1, map[])"

Are these doing any changes in the IP table rules (even those who are not managed by docker)?

Additional information:

Docker info output:

Containers: 313
 Running: 313
 Paused: 0
 Stopped: 0
Images: 366
Server Version: 17.03.1-ee-3
Storage Driver: aufs
 Root Dir: /opt/gp2/docker/aufs
 Backing Filesystem: extfs
 Dirs: 1310
 Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 4ab9917febca54791c5f071a9d1f404867857fcc
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
init version: 949e6fa
Security Options:
 apparmor
 seccomp
  Profile: default
Kernel Version: 4.4.0-72-generic
Operating System: Ubuntu 16.04.2 LTS
OSType: linux
Architecture: x86_64
CPUs: 128
Total Memory: 1.876 TiB
Name: docker-linux-3-dh
ID: VXXM:RN5G:WFOM:ZRTU:Q72T:OMDG:Z4LK:2TJ7:5BWZ:DLLQ:7RLL:RPFX
Docker Root Dir: /opt/gp2/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 2866
 Goroutines: 1511
 System Time: 2017-04-26T19:11:17.202712551Z
 EventsListeners: 1
Registry: https://index.docker.io/v1/
WARNING: No swap limit support
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: true

Affected rules

An example of affected rules. We should have:

root@docker-linux-3-dh:/home/ubuntu# iptables -t nat --list | grep 174.17.26.1 | grep 82 | grep DNAT
DNAT tcp – anywhere ip-10-76-32-171.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-170.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-169.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-9.ec2.internal tcp dpt:82 to:174.17.26.1:82
DNAT tcp – anywhere ip-10-76-32-9.ec2.internal tcp dpt:82 to:174.17.26.1:82
DNAT tcp – anywhere ip-10-76-32-9.ec2.internal tcp dpt:82 to:174.17.26.1:82
DNAT tcp – anywhere ip-10-76-32-173.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-172.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-155.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-154.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-153.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-158.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-157.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-156.ec2.internal tcp dpt:82 to:174.17.26.1:8
DNAT tcp – anywhere ip-10-76-32-9.ec2.internal tcp dpt:82 to:174.17.26.1:82

And we have:

root@docker-linux-3-dh:/home/ubuntu# iptables -t nat --list | grep 174.17.26.1 | grep 82 | grep DNAT
DNAT tcp – anywhere ip-10-76-32-9.ec2.internal tcp dpt:82 to:174.17.26.1:82

Note: 10.76.32.9 is the IP address the container is bound to.

Expanded log (filtering by container IP)

Apr 25 19:32:16 localhost dockerd[130068]: time="2017-04-25T19:32:16.941825519Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 2021 -j DNAT --to-destination 174.17.26.1:2021]"
Apr 25 19:32:16 localhost dockerd[130068]: time="2017-04-25T19:32:16.992041126Z" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -p tcp -d 10.76.32.9 --dport 2021 -j DNAT --to-destination 174.17.26.1:2021]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.038766162Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 2021 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.073761198Z" level=debug msg="/sbin/iptables, [--wait -t filter -D DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 2021 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.116408788Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 2021 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.176931106Z" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 2021 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.228428958Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 443 -j DNAT --to-destination 174.17.26.1:443]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.286809427Z" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -p tcp -d 10.76.32.9 --dport 443 -j DNAT --to-destination 174.17.26.1:443]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.337290891Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 443 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.371076672Z" level=debug msg="/sbin/iptables, [--wait -t filter -D DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 443 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.408517116Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 443 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.457035657Z" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 443 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.503958784Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 82 -j DNAT --to-destination 174.17.26.1:82]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.556001992Z" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -p tcp -d 10.76.32.9 --dport 82 -j DNAT --to-destination 174.17.26.1:82]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.602205915Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 82 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.635851656Z" level=debug msg="/sbin/iptables, [--wait -t filter -D DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 82 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.667843739Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 82 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.715959722Z" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 82 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.763913238Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 80 -j DNAT --to-destination 174.17.26.1:80]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.808725812Z" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -p tcp -d 10.76.32.9 --dport 80 -j DNAT --to-destination 174.17.26.1:80]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.853464780Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 80 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.886061468Z" level=debug msg="/sbin/iptables, [--wait -t filter -D DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 80 -j ACCEPT]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.921214480Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 80 -j MASQUERADE]"
Apr 25 19:32:17 localhost dockerd[130068]: time="2017-04-25T19:32:17.965875633Z" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 80 -j MASQUERADE]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.012302310Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 25 -j DNAT --to-destination 174.17.26.1:25]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.057495701Z" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -p tcp -d 10.76.32.9 --dport 25 -j DNAT --to-destination 174.17.26.1:25]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.103914708Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 25 -j ACCEPT]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.139736099Z" level=debug msg="/sbin/iptables, [--wait -t filter -D DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 25 -j ACCEPT]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.171945062Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 25 -j MASQUERADE]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.223865465Z" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 25 -j MASQUERADE]"
Apr 25 19:32:18 localhost dockerd[130068]: time="2017-04-25T19:32:18.836206790Z" level=debug msg="ReleaseAddress(LocalDefault/174.17.0.0/16, 174.17.26.1)"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.157956063Z" level=debug msg="RequestAddress(LocalDefault/174.17.0.0/16, 174.17.26.1, map[])"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.177590501Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 2021 -j DNAT --to-destination 174.17.26.1:2021]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.214941601Z" level=debug msg="/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 10.76.32.9 --dport 2021 -j DNAT --to-destination 174.17.26.1:2021]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.264738612Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 2021 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.297460690Z" level=debug msg="/sbin/iptables, [--wait -t filter -A DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 2021 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.334339693Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 2021 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.372852765Z" level=debug msg="/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 2021 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.418543324Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 443 -j DNAT --to-destination 174.17.26.1:443]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.456751360Z" level=debug msg="/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 10.76.32.9 --dport 443 -j DNAT --to-destination 174.17.26.1:443]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.500178065Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 443 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.531822924Z" level=debug msg="/sbin/iptables, [--wait -t filter -A DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 443 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.569761269Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 443 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.613255740Z" level=debug msg="/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 443 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.661770436Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 82 -j DNAT --to-destination 174.17.26.1:82]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.699942724Z" level=debug msg="/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 10.76.32.9 --dport 82 -j DNAT --to-destination 174.17.26.1:82]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.750610529Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 82 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.782628900Z" level=debug msg="/sbin/iptables, [--wait -t filter -A DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 82 -j ACCEPT]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.817801513Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 82 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.858993694Z" level=debug msg="/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 82 -j MASQUERADE]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.928164485Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 80 -j DNAT --to-destination 174.17.26.1:80]"
Apr 25 19:32:19 localhost dockerd[130068]: time="2017-04-25T19:32:19.967123245Z" level=debug msg="/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 10.76.32.9 --dport 80 -j DNAT --to-destination 174.17.26.1:80]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.016342777Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 80 -j ACCEPT]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.050984759Z" level=debug msg="/sbin/iptables, [--wait -t filter -A DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 80 -j ACCEPT]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.097932776Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 80 -j MASQUERADE]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.137385277Z" level=debug msg="/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 80 -j MASQUERADE]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.191116185Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -p tcp -d 10.76.32.9 --dport 25 -j DNAT --to-destination 174.17.26.1:25]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.237001915Z" level=debug msg="/sbin/iptables, [--wait -t nat -A DOCKER -p tcp -d 10.76.32.9 --dport 25 -j DNAT --to-destination 174.17.26.1:25]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.286096822Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 25 -j ACCEPT]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.320257578Z" level=debug msg="/sbin/iptables, [--wait -t filter -A DOCKER ! -i lmdocker0 -o lmdocker0 -p tcp -d 174.17.26.1 --dport 25 -j ACCEPT]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.356814952Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 25 -j MASQUERADE]"
Apr 25 19:32:20 localhost dockerd[130068]: time="2017-04-25T19:32:20.397782653Z" level=debug msg="/sbin/iptables, [--wait -t nat -A POSTROUTING -p tcp -s 174.17.26.1 -d 174.17.26.1 --dport 25 -j MASQUERADE]"

Start by tracing the ReleaseAddress and RequestAddress entry points in libnetwork and compare them with the iptables commands shown in the expanded log. Done means documenting whether these operations remove or recreate the reported custom DNAT rules and identifying the Docker action that triggers them.