Repository: moby/moby (language: go)

Issue:
Inconsistent source IPs in containers
Hi,

I'm running rsyslog in a container. Basically just an ubuntu image with rsyslogd installed and a template configuration like this:

```
$template FILENAME,"/var/log/%fromhost-ip%/%hostname%/syslog.log"
```

Exposed ports in Dockerfile: `EXPOSE     514/tcp 514/udp`

Now this works in general just fine, but I discovered some strange behavior regarding the source IP of the syslog packets: Sometimes the messages for remote systems end up in `[remote-host-ip]/[container-hostname]/syslog.log`, then after some time, they end up in `[docker0-bridges-ip]/[container-hostname]/syslog.log`. This seems to flip around from now and then.

As far as I understand, the expected behavior is:
- If you connect to a exposed port from localhost, inside the container the source IP is the IP of the docker0 bridge
- If you connect to a exposed port from a remote system, the source IP is the IP of the remote system

But it seems somehow those packets get routed via the docker0 IP and sometimes not. This makes not only running a syslog server hard but also debugging request logs in general. 



Discussion / hints:
Can you provide some data to go with this report?  If you set up your rsyslog container and start logging from a single remote host, does it initially appear to do the right thing?  How often does it appear to switch?  Can you reproduce this behavior on demand?

Start with a clean system and only a single remote logging client in order to minimize confusion.

I'll provide more details once I find some time for that. First of all I wonder how it's suppose to work. Should all remote connection have the source IP of the remote system or do they go through the userland proxy as well?

There is no "userland proxy".  Traffic generated on on your local host has the ip of the docker bridge _because that is the address of your host on the docker network_.  This is exactly like what happens if you attempt to connect any other machines that shares the same network as your host.

For "exposed" ports, externally originated traffic should hit the NAT rules in the PREROUTING chain, which perform destination NAT (`DNAT`) but do not modify the origin address...so packets coming into your Docker containers should have the origin address of the remote host.  The rules look like this (this example is forwarding host port 8080 to port 80 on a container):

```
-A DOCKER ! -i docker0 -p tcp -m tcp --dport 8080 -j DNAT --to-destination 172.17.0.49:80
```

So there's nothing in place that should be modifying the _source_ address of externally originated traffic, unless you have existing iptables rules in place outside of those installed by Docker.

@larsks But what about traffic from the host to localhost? Thought that's what ends on the 'userland proxy'. If you run:

```
$ docker run -t -i -p 2342:2342 ubuntu sh -c 'nc -k -l 2342 & watch -n1 netstat -anp'
```

Then connect on the host to it (`nc localhost 2342`) you will see the docker0 addr in netstat.

Regarding the iptables, this looks good I suppose:

```
DNAT       udp  --  anywhere             [host-ip]       udp dpt:syslog to:172.17.0.10:514
```

But I've just ran tcpdump on both the external interface and docker0: On the external interfaces, everything looks as expected: Traffic from the external host to this host's ip. But when doing a tcpdump on docker0, some packets come, as expected, from the external host's IP:

```
14:55:12.969447 IP (tos 0x0, ttl 63, id 14272, offset 0, flags [DF], proto UDP (17), length 188)
    [remote-host-ip].53522 > 172.17.0.10.syslog: SYSLOG, length: 160
    Facility local7 (23), Severity info (6)
        ...
```

But some packets come from docker0's IP:

```
14:55:12.969497 IP (tos 0x0, ttl 64, id 51319, offset 0, flags [DF], proto UDP (17), length 212)
    172.17.42.1.60426 > 172.17.0.10.syslog: SYSLOG, length: 184
    Facility local0 (16), Severity info (6)
        ...
```

That's unexpected I guess?
Maybe relevant: Those things sending the syslog messages are nginx and haproxy running in the same docker container but using host networking.
At least right now, nginx's messages come in via the remote hosts IP, haproxy's via the docker0 addr. Each of them sends their messages from a fixed port, so maybe when they started sending some iptables rules matched the one "connection" but the other ended somewhere else?

/me notes that he was completely wrong about the userland proxy, which unlike unicorns is a real actual thing listening on ports on my system.  Sorry!

So it seems that in conntrack those connections are tracked differently. They have all the correct remote connection details:

```
 src=[remote-hosts-ip] dst=[this-hosts-ip] sport=48807 dport=514
```

Those connections visible inside the container with docker0's IP have this as expected "answer packet":

```
src=172.17.0.10 dst=[remote-hosts-ip] sport=514 dport=48807
```

And those visible with the remote hosts ip expected such 'answer packet':

```
src=[this-hosts-ip] dst=[remote-hosts-ip] sport=514 dport=42542
```

But I can't say if this is a symptom or cause. If it's part of the cause, it would explain why constantly one app (-> source port) ends up with the docker0's ip and one with the remote one. But I can't really explain that since conntrack table should only be consulted for outgoing packets.

@discordianfish are you only seeing this when you restart the rsyslog container? Trying to track down a theory.

I just ran into something that looks related:

I'm running a syslog container and a haproxy sending logs via udp to it.
Now I redeployed the syslog container but it doesn't get any logs. With tcpdump I can verify that the messages get send:

```
19:07:19.840712 IP [haproxy-ip].56121 > [syslog-ip].514: SYSLOG local0.info, length: 226
19:07:19.858728 IP [haproxy-ip].56121 > [syslog-ip].514: SYSLOG local0.info, length: 263
19:07:19.858728 IP [haproxy-ip].56121 > [syslog-ip].514: SYSLOG local0.info, length: 263
```

But neither syslog nor the tcpdump inside the syslog container see those messages. If I send a message to the syslog servers IP with netcat it shows up in log and tcpdump as expected.

I suspect there is some issue with UDP connection tracking which also explains why the connections get "locked" into either the remote hosts ip or bridge ip as reported above.

I'm seeing this exact same behaviour with the source IP of packets reaching nginx inside a container. Sometimes they have 172.17.42.1 as the source address, and sometimes they have the actual remote address, and it seems to switch arbitrarily every few minutes. Is there any known workaround or fix for this, or is there any further investigation I can do that would help to find out what's wrong?

@unclejack @jfrazelle I've heard we removed the userland proxy in 1.6? Is this the case or do we need more investigations into this issue here? @icecrime: If so, can we prioritize this somehow?

FWIW I'm running docker 1.5.0 currently.

That's not until 1.7

On Saturday, April 11, 2015, George Goldberg notifications@github.com
wrote:

> FWIW I'm running docker 1.5.0 currently.
> 
> —
> Reply to this email directly or view it on GitHub
> https://github.com/docker/docker/issues/7540#issuecomment-91921317.

@jfrazelle I assume this solution to this issue is the removal of the userland proxy? Guess it doesn't make sense to spend resources on this until the userland proxy is removed.

@discordianfish Unfortunately we still cannot entirely remove userland proxy, but we have a PR under review to make it optional (we need to keep support for older RHEL). See PR #12165.

@icecrime Okay, so if we still support this we should look into this problem here.

I just noticed a pattern which may be relevant to this: I see the 172.17.42.1 source IP address when the connection from the remote host to the docker host is over IPv6. I'm not 100% about this, but it's a pattern that has held over a short spate of observations just now.

@icecrime So can we get someone actively looking into this? I just removed the next service from docker because I suspect network problems.

@discordianfish I wish we could, we just don't have any spare minute... But I haven't forgotten about this.

@discordianfish can you please confirm if you see this behavior only with userlandproxy mode enabled ?
https://github.com/docker/docker/pull/12165 brought in the support in the upcoming 1.7.0 release to make this an optional feature.

@avinson: You see this currently with heka, right? Can you confirm this?

i know it still affects heka logging as of 1.6 but i haven't tested 1.7 yet.. i'll do that asap

@mavenugo what options should i run the heka (syslog equivalent) container with to disable userlandproxy mode?

@aaron 1.7.0 has the `--userland-proxy=false` daemon flag

@icecrime Do we have documented what side effects that might have? Or does it simply require a recent kernel and things should just work?

@discordianfish There's no expected side effect that we know about.

Using docker 1.7.0, kernel 3.13.0-48-generic.
Running container with such command:
docker ----userland-proxy=false run --name name - p 80:80 -d imagename 
I do not see the correct remote IP in the container. What am I doing wrong?

I'm not sure what's going on, but I'm seeing the same thing on Docker 1.8.3 with userland proxy disabled. Confirmed the userland proxy is not running, but I still only see eg 172.17.42.1 showing as the source IP inside the container for everything. Any pointers for how I might get the real IPs to show up?

_USER POLL_

_The best way to get notified of updates is to use the _Subscribe_ button on this page._

Please don't use "+1" or "I have this too" comments on issues. We automatically
collect those comments to keep the thread short.

The people listed below have upvoted this issue by leaving a +1 comment:

@eskp

ping @mrjana @mavenugo @aboch @sanimej 

@discordianfish I am running latest docker master (1.13 dev); I have a nginx running on default bridge network. With and without userland proxy (btw disabling userland proxy is not recommended) I see the right behavior. Accessing the published port from the localhost has the source IP is that of docker0 bridge (`172.17.0.1` in my case) and  from a remote host source IP is the remote IP.

Can you give it a try with 1.12.1 and confirm if it works ok ?

@sanimej You're not using udp. See my initial description and try to reproduce with rsyslogd.
This issue is two years old, I stopped using Docker for anything udp long time ago.. So won't be able to test it.

@discordianfish Since the issue here is about the source IP the behavior should be the same for TCP and UDP. I verified for UDP as well. I will go ahead and close this issue.

Did you face any other UDP related issue with Docker ? If its something that is still seen in newer versions we can address it.

Hi,

I have a rsyslogd container as well. All logs are sent in UDP. However, this issue appears for only one source.

```
# pid=`docker inspect -f '{{.State.Pid}}' rsyslog_container`
# nsenter -t $pid -n tcpdump -i eth0 -n

IP [remote1_ip].5815 > [rsyslog_container_ip].514: SYSLOG user.info, length: 110 # expected behavior
IP [remote2_ip].27403 > [rsyslog_container_ip].514: SYSLOG user.info, length: 110 # expected behavior
IP [docker_bridge_ip].44509 > [rsyslog_container_ip].1514: UDP, length 158 # issue
```

```
# docker-compose ps
        Name                      Command               State                                             Ports                                            
----------------------------------------------------------------------------------------------------------------------------------------------------------
rsyslogd_container         rsyslogd -n                      Up      0.0.0.0:1514->1514/tcp, 0.0.0.0:1514->1514/udp, 0.0.0.0:514->514/tcp, 0.0.0.0:514->514/udp
```

Docker Version: 1.12.1

```
# docker-compose -v
docker-compose version 1.8.1
```

This is old thread nonetheless still relevant.
`conntrack -D -p udp` after the container has started fixes the issue
moby/moby#16720

Fix patch:
diff --git a/libnetwork/drivers/bridge/bridge.go b/libnetwork/drivers/bridge/bridge.go
index a9b010b69c2c5..a58e11dd948e3 100644
--- a/libnetwork/drivers/bridge/bridge.go
+++ b/libnetwork/drivers/bridge/bridge.go
@@ -1328,10 +1328,9 @@ func (d *driver) ProgramExternalConnectivity(nid, eid string, options map[string
 		}
 	}()
 
-	// Clean the connection tracker state of the host for the
-	// specific endpoint. This is needed because some flows may be
-	// bound to the local proxy and won't bre redirect to the new endpoints.
-	clearEndpointConnections(d.nlh, endpoint)
+	// Clean the connection tracker state of the host for the specific endpoint. This is needed because some flows may
+	// be bound to the local proxy, or to the host (for UDP packets), and won't be redirected to the new endpoints.
+	clearConntrackEntries(d.nlh, endpoint)
 
 	if err = d.storeUpdate(endpoint); err != nil {
 		return fmt.Errorf("failed to update bridge endpoint %.7s to store: %v", endpoint.id, err)
@@ -1366,12 +1365,10 @@ func (d *driver) RevokeExternalConnectivity(nid, eid string) error {
 
 	endpoint.portMapping = nil
 
-	// Clean the connection tracker state of the host for the specific endpoint
-	// The host kernel keeps track of the connections (TCP and UDP), so if a new endpoint gets the same IP of
-	// this one (that is going down), is possible that some of the packets would not be routed correctly inside
-	// the new endpoint
-	// Deeper details: https://github.com/docker/docker/issues/8795
-	clearEndpointConnections(d.nlh, endpoint)
+	// Clean the connection tracker state of the host for the specific endpoint. This is a precautionary measure to
+	// avoid new endpoints getting the same IP address to receive unexpected packets due to bad conntrack state leading
+	// to bad NATing.
+	clearConntrackEntries(d.nlh, endpoint)
 
 	if err = d.storeUpdate(endpoint); err != nil {
 		return fmt.Errorf("failed to update bridge endpoint %.7s to store: %v", endpoint.id, err)
diff --git a/libnetwork/drivers/bridge/setup_ip_tables.go b/libnetwork/drivers/bridge/setup_ip_tables.go
index c4bad446db35d..0591a1243c15d 100644
--- a/libnetwork/drivers/bridge/setup_ip_tables.go
+++ b/libnetwork/drivers/bridge/setup_ip_tables.go
@@ -9,6 +9,7 @@ import (
 	"net"
 
 	"github.com/docker/docker/libnetwork/iptables"
+	"github.com/docker/docker/libnetwork/types"
 	"github.com/sirupsen/logrus"
 	"github.com/vishvananda/netlink"
 )
@@ -418,14 +419,35 @@ func setupInternalNetworkRules(bridgeIface string, addr *net.IPNet, icc, insert
 	return setIcc(version, bridgeIface, icc, insert)
 }
 
-func clearEndpointConnections(nlh *netlink.Handle, ep *bridgeEndpoint) {
+// clearConntrackEntries flushes conntrack entries matching endpoint IP address
+// or matching one of the exposed UDP port.
+// In the first case, this could happen if packets were received by the host
+// between userland proxy startup and iptables setup.
+// In the latter case, this could happen if packets were received whereas there
+// were nowhere to route them, as netfilter creates entries in such case.
+// This is required because iptables NAT rules are evaluated by netfilter only
+// when creating a new conntrack entry. When Docker latter adds NAT rules,
+// netfilter ignore them for any packet matching a pre-existing conntrack entry.
+// As such, we need to flush all those conntrack entries to make sure NAT rules
+// are correctly applied to all packets.
+// See: #8795, #44688 & #44742.
+func clearConntrackEntries(nlh *netlink.Handle, ep *bridgeEndpoint) {
 	var ipv4List []net.IP
 	var ipv6List []net.IP
+	var udpPorts []uint16
+
 	if ep.addr != nil {
 		ipv4List = append(ipv4List, ep.addr.IP)
 	}
 	if ep.addrv6 != nil {
 		ipv6List = append(ipv6List, ep.addrv6.IP)
 	}
+	for _, pb := range ep.portMapping {
+		if pb.Proto == types.UDP {
+			udpPorts = append(udpPorts, pb.HostPort)
+		}
+	}
+
 	iptables.DeleteConntrackEntries(nlh, ipv4List, ipv6List)
+	iptables.DeleteConntrackEntriesByPort(nlh, types.UDP, udpPorts)
 }
diff --git a/libnetwork/iptables/conntrack.go b/libnetwork/iptables/conntrack.go
index 5abae4eede2d6..211b0859c7ea9 100644
--- a/libnetwork/iptables/conntrack.go
+++ b/libnetwork/iptables/conntrack.go
@@ -8,6 +8,7 @@ import (
 	"net"
 	"syscall"
 
+	"github.com/docker/docker/libnetwork/types"
 	"github.com/sirupsen/logrus"
 	"github.com/vishvananda/netlink"
 )
@@ -53,6 +54,42 @@ func DeleteConntrackEntries(nlh *netlink.Handle, ipv4List []net.IP, ipv6List []n
 	return totalIPv4FlowPurged, totalIPv6FlowPurged, nil
 }
 
+func DeleteConntrackEntriesByPort(nlh *netlink.Handle, proto types.Protocol, ports []uint16) error {
+	if !IsConntrackProgrammable(nlh) {
+		return ErrConntrackNotConfigurable
+	}
+
+	var totalIPv4FlowPurged uint
+	var totalIPv6FlowPurged uint
+
+	for _, port := range ports {
+		filter := &netlink.ConntrackFilter{}
+		if err := filter.AddProtocol(uint8(proto)); err != nil {
+			logrus.Warnf("Failed to delete conntrack state for %s port %d: %v", proto.String(), port, err)
+			continue
+		}
+		if err := filter.AddPort(netlink.ConntrackOrigDstPort, port); err != nil {
+			logrus.Warnf("Failed to delete conntrack state for %s port %d: %v", proto.String(), port, err)
+			continue
+		}
+
+		v4FlowPurged, err := nlh.ConntrackDeleteFilter(netlink.ConntrackTable, syscall.AF_INET, filter)
+		if err != nil {
+			logrus.Warnf("Failed to delete conntrack state for IPv4 %s port %d: %v", proto.String(), port, err)
+		}
+		totalIPv4FlowPurged += v4FlowPurged
+
+		v6FlowPurged, err := nlh.ConntrackDeleteFilter(netlink.ConntrackTable, syscall.AF_INET6, filter)
+		if err != nil {
+			logrus.Warnf("Failed to delete conntrack state for IPv6 %s port %d: %v", proto.String(), port, err)
+		}
+		totalIPv6FlowPurged += v6FlowPurged
+	}
+
+	logrus.Debugf("DeleteConntrackEntriesByPort for %s ports purged ipv4:%d, ipv6:%d", proto.String(), totalIPv4FlowPurged, totalIPv6FlowPurged)
+	return nil
+}
+
 func purgeConntrackState(nlh *netlink.Handle, family netlink.InetFamily, ipAddress net.IP) (uint, error) {
 	filter := &netlink.ConntrackFilter{}
 	// NOTE: doing the flush using the ipAddress is safe because today there cannot be multiple networks with the same subnet


Test patch: