cilium: CI: L3-Dependent L7 Egress fail

https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2303/

Stacktrace

/home/jenkins/workspace/Ginkgo-CI-Tests-Pipeline/src/github.com/cilium/cilium/test/ginkgo-ext/scopes.go:312
"app3" expects curl public URL on httpd2 ([f00d::a0f:0:0:29bf]) to succeed
Expected
    <bool>: false
to be true
/home/jenkins/workspace/Ginkgo-CI-Tests-Pipeline/src/github.com/cilium/cilium/test/runtime/Policies.go:520

Standard Output

�[1mSTEP�[0m: Setting PolicyEnforcement=default
time="2018-05-02T15:19:50Z" level=info msg="setting PolicyEnforcement=default"
time="2018-05-02T15:19:50Z" level=debug msg="running command: sudo cilium config -o json | jq -r '.status.realized[\"policy-enforcement\"]'"
time="2018-05-02T15:19:50Z" level=debug msg="running command: sudo cilium config PolicyEnforcement=default"
time="2018-05-02T15:19:55Z" level=debug msg="running command: cilium endpoint list -o jsonpath='{range [*]}{@.status.external-identifiers.container-name}{\"=\"}{@.status.state}{\"\\n\"}{end}'"
time="2018-05-02T15:19:56Z" level=info msg="'7' containers are in a 'ready' state of a total of '7' containers." functionName=WaitEndpointsReady status="map[ready:7]" test=RunPolicies
�[1mSTEP�[0m: Setting up policy: /home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json
time="2018-05-02T15:19:56Z" level=debug msg="running command: sudo cilium policy get -o json | jq '.revision'"
time="2018-05-02T15:19:56Z" level=info msg="before importing policy" file-path=/home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json policyRevision=39 test=RunPolicies
time="2018-05-02T15:19:56Z" level=info msg="validating policy before importing" file-path=/home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json test=RunPolicies
time="2018-05-02T15:19:56Z" level=debug msg="running command: sudo cilium policy validate /home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json"
time="2018-05-02T15:19:57Z" level=debug msg="running command: sudo cilium policy import /home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json"
time="2018-05-02T15:20:02Z" level=debug msg="running command: sudo cilium policy get -o json | jq '.revision'"
time="2018-05-02T15:20:03Z" level=debug msg="running command: sudo cilium policy wait 40"
time="2018-05-02T15:20:03Z" level=debug msg="running command: sudo cilium policy get -o json | jq '.revision'"
time="2018-05-02T15:20:03Z" level=info msg="policy import finished and revision increased" file-path=/home/vagrant/go/src/github.com/cilium/cilium/test/runtime/manifests/Policies-l3-dependent-l7-egress.json policyRevision=40 test=RunPolicies
time="2018-05-02T15:20:03Z" level=debug msg="running command: sudo cilium endpoint list -o jsonpath='{range [?(@.status.labels.security-relevant[0]!=\"reserved:health\")]}{@.status.external-identifiers.container-name}{\"=\"}{@.id}{\"\\n\"}{end}'"
time="2018-05-02T15:20:03Z" level=debug msg="running command: sudo docker inspect app3"
time="2018-05-02T15:20:04Z" level=debug msg="running command: sudo docker inspect httpd1"
�[1mSTEP�[0m: Client "app3" attempting to curl public URL on httpd1
time="2018-05-02T15:20:04Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://10.15.25.58:80/public"
�[1mSTEP�[0m: Client "app3" attempting to curl public URL on httpd1
time="2018-05-02T15:20:04Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://[f00d::a0f:0:0:10da]:80/public"
time="2018-05-02T15:20:04Z" level=debug msg="running command: sudo cilium endpoint get 3978 -o json"
time="2018-05-02T15:20:04Z" level=debug msg="running command: sudo docker inspect app3"
time="2018-05-02T15:20:04Z" level=debug msg="running command: sudo docker inspect httpd1"
�[1mSTEP�[0m: Client "app3" attempting to curl private URL on httpd1
time="2018-05-02T15:20:05Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://10.15.25.58:80/private"
�[1mSTEP�[0m: Client "app3" attempting to curl private URL on httpd1
time="2018-05-02T15:20:05Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://[f00d::a0f:0:0:10da]:80/private"
time="2018-05-02T15:20:05Z" level=debug msg="running command: sudo cilium endpoint get 3978 -o json"
time="2018-05-02T15:20:05Z" level=debug msg="running command: sudo docker inspect app3"
time="2018-05-02T15:20:05Z" level=debug msg="running command: sudo docker inspect httpd2"
�[1mSTEP�[0m: Client "app3" attempting to curl public URL on httpd2
time="2018-05-02T15:20:06Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://10.15.129.219:80/public"
�[1mSTEP�[0m: Client "app3" attempting to curl public URL on httpd2
time="2018-05-02T15:20:06Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://[f00d::a0f:0:0:29bf]:80/public"

Endpoint config looks good:

[
  {
    "id": 3978,
    "spec": {
      "label-configuration": {
        "user": []
      },
      "options": {
        "Conntrack": "Enabled",
        "ConntrackAccounting": "Enabled",
        "ConntrackLocal": "Disabled",
        "Debug": "Enabled",
        "DebugLB": "Disabled",
        "DropNotification": "Enabled",
        "EgressPolicy": "Enabled",
        "IngressPolicy": "Disabled",
        "NAT46": "Disabled",
        "TraceNotification": "Enabled"
      }
    },
    "status": {
      "controllers": [
        {
          "configuration": {
            "error-retry": true,
            "interval": "5m0s"
          },
          "name": "resolve-identity-3978",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-05-02T15:15:53.000Z",
            "success-count": 2
          },
          "uuid": "016e8ec4-4e1b-11e8-ac1a-0800277280d1"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "5m0s"
          },
          "name": "sync-IPv4-identity-mapping (3978)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-05-02T15:15:53.024Z",
            "success-count": 2
          },
          "uuid": "016fb513-4e1b-11e8-ac1a-0800277280d1"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "5m0s"
          },
          "name": "sync-IPv6-identity-mapping (3978)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-05-02T15:15:53.024Z",
            "success-count": 2
          },
          "uuid": "016fb5c4-4e1b-11e8-ac1a-0800277280d1"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "1m0s"
          },
          "name": "sync-identity-to-k8s-pod (3978)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-05-02T15:19:53.021Z",
            "success-count": 10
          },
          "uuid": "016fb3f5-4e1b-11e8-ac1a-0800277280d1"
        }
      ],
      "external-identifiers": {
        "container-id": "6de96faf9fa1be32456ceb6fb518a2bb41aafb5335edca035b08c31a8d4fdb1e",
        "container-name": "app3",
        "docker-endpoint-id": "3fc18ee406c6feb02bfdd00da8730ec856335b8202208940be967226439e08db",
        "docker-network-id": "0a42519156d0f48299b98978e895c5c52203f0c5b8f70dd6d3e98fb899c593e7",
        "pod-name": ":"
      },
      "health": {
        "bpf": "OK",
        "connected": true,
        "overallHealth": "OK",
        "policy": "OK"
      },
      "identity": {
        "id": 51492,
        "labels": [
          "container:id.app3"
        ],
        "labelsSHA256": "2186c66cd5d8fb631adf86d9ca4ce027fcb02f3de2e5de8868f83250f203240e"
      },
      "labels": {
        "derived": [],
        "disabled": [],
        "realized": {
          "user": []
        },
        "security-relevant": [
          "container:id.app3"
        ]
      },
      "log": [
        {
          "code": "OK",
          "message": "Successfully regenerated endpoint program due to endpoint policy updated \u0026 changes were needed",
          "state": "ready",
          "timestamp": "2018-05-02T15:20:01Z"
        }
      ],
      "networking": {
        "addressing": [
          {
            "ipv4": "10.15.251.95",
            "ipv6": "f00d::a0f:0:0:f8a"
          }
        ],
        "host-mac": "02:41:b2:63:f2:8b",
        "interface-index": 169,
        "interface-name": "lxc3fc18",
        "mac": "9e:b7:7c:7f:8a:16"
      },
      "policy": {
        "proxy-statistics": [
          {
            "allocated-proxy-port": 12908,
            "location": "egress",
            "port": 80,
            "protocol": "http",
            "statistics": {
              "requests": {
                "denied": 2,
                "forwarded": 2,
                "received": 4
              },
              "responses": {
                "forwarded": 2,
                "received": 2
              }
            }
          }
        ],
        "realized": {
          "allowed-egress-identities": [
            5572
          ],
          "allowed-ingress-identities": [
            1
          ],
          "build": 40,
          "cidr-policy": {
            "egress": [],
            "ingress": []
          },
          "id": 51492,
          "l4": {
            "egress": [
              {
                "derived-from-rules": [
                  [],
                  []
                ],
                "rule": "{\n  \"port\": 80,\n  \"protocol\": \"TCP\",\n  \"l7-rules\": [\n    {\n      \"any.id.httpd1=\": {\n        \"http\": [\n          {\n            \"path\": \"/public\",\n            \"method\": \"GET\"\n          }\n        ]\n      }\n    },\n    {\n      \"any.id.httpd2=\": {\n        \"http\": [\n          {}\n        ]\n      }\n    }\n  ]\n}"
              }
            ],
            "ingress": []
          },
          "policy-enabled": "egress",
          "policy-revision": 40
        },
        "spec": {
          "allowed-egress-identities": [
            5572
          ],
          "allowed-ingress-identities": [
            1
          ],
          "build": 40,
          "cidr-policy": {
            "egress": [],
            "ingress": []
          },
          "id": 51492,
          "l4": {
            "egress": [
              {
                "derived-from-rules": [
                  [],
                  []
                ],
                "rule": "{\n  \"port\": 80,\n  \"protocol\": \"TCP\",\n  \"l7-rules\": [\n    {\n      \"any.id.httpd1=\": {\n        \"http\": [\n          {\n            \"path\": \"/public\",\n            \"method\": \"GET\"\n          }\n        ]\n      }\n    },\n    {\n      \"any.id.httpd2=\": {\n        \"http\": [\n          {}\n        ]\n      }\n    }\n  ]\n}"
              }
            ],
            "ingress": []
          },
          "policy-enabled": "egress",
          "policy-revision": 40
        }
      },
      "realized": {
        "label-configuration": {
          "user": []
        },
        "options": {
          "Conntrack": "Enabled",
          "ConntrackAccounting": "Enabled",
          "ConntrackLocal": "Disabled",
          "Debug": "Enabled",
          "DebugLB": "Disabled",
          "DropNotification": "Enabled",
          "EgressPolicy": "Enabled",
          "IngressPolicy": "Disabled",
          "NAT46": "Disabled",
          "TraceNotification": "Enabled"
        }
      },
      "state": "ready"
    }
  }
]

Connection using IPv4 works, it didn’t work using Ipv6:

time="2018-05-02T15:20:06Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://10.15.129.219:80/public"
cmd: "docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://10.15.129.219:80/public" exitCode: 0 
 { 'val': 'this is public' }

time="2018-05-02T15:20:06Z" level=debug msg="running command: docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://[f00d::a0f:0:0:29bf]:80/public"
cmd: "docker exec -i  app3 curl -s --fail --connect-timeout 5 --max-time 5 http://[f00d::a0f:0:0:29bf]:80/public" exitCode: 22 

test_results_Ginkgo-CI-Tests-Pipeline_2303.zip