CI: Upgrade test is broken

The upgrade test from stable to latest is broken. It was noticed when commit 7e4436b9 was merged which introduced a change which is not upgrade compatible. The commit changed the default IPv6 prefix which will prevent cilium-agent from starting up if it was previously started with a different IPv6 prefix.

Build: https://jenkins.cilium.io/view/PR/job/Cilium-PR-Ginkgo-Tests-Validated/3737
Issue:
Cilium log:
2018-06-01T11:10:56.076038134Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_tunnel_map
2018-06-01T11:10:56.07833049Z level=debug msg="os.Hostname() returned" nodeName=k8s2
2018-06-01T11:10:56.082503204Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_lxc
2018-06-01T11:10:56.178745946Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_ipcache
2018-06-01T11:10:56.178916042Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_metrics
2018-06-01T11:10:56.179299518Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_proxy4
2018-06-01T11:10:56.179347959Z level=debug msg="bpffs is not mounted yet; adding to list of maps to open once it is mounted" bpfMapName=cilium_proxy6
2018-06-01T11:10:56.182999682Z level=info msg="     _ _ _"
2018-06-01T11:10:56.18304058Z level=info msg=" ___|_| |_|_ _ _____"
2018-06-01T11:10:56.183064391Z level=info msg="|  _| | | | | |     |"
2018-06-01T11:10:56.18311991Z level=info msg="|___|_|_|_|___|_|_|_|"
2018-06-01T11:10:56.18317952Z level=info msg="Cilium 1.0.90 a57af48fa 2018-06-01T10:41:37+00:00 go version go1.9 linux/amd64"
2018-06-01T11:10:56.192266657Z level=info msg="cilium-envoy  version: a57af48faca97adc7ac6d16eec9d1f3ac9e4fa8d/1.7.0-dev/Distribution/RELEASE"
2018-06-01T11:10:56.212281217Z level=info msg="clang (3.8.1) and kernel (4.9.17) versions: OK!"
2018-06-01T11:10:56.214700151Z level=info msg="linking environment: OK!"
2018-06-01T11:10:56.738763617Z level=info msg="bpf_requirements check: OK!"
2018-06-01T11:10:56.738893306Z level=debug msg="bpf_features check: Some features may be limited:"
2018-06-01T11:10:56.738941381Z level=debug msg="BPF/probes: Kernel config not found."
2018-06-01T11:10:56.739000312Z level=debug msg="HAVE_LPM_MAP_TYPE: Your kernel doesn't support LPM trie maps for BPF, thus switching back to using hash table for CIDR policies. Recommendation is to run 4.11+ kernels."
2018-06-01T11:10:56.739046975Z level=debug msg="HAVE_LRU_MAP_TYPE: Your kernel doesn't support LRU maps for BPF, thus switching back to using hash table for the cilium connection tracker. Recommendation is to run 4.10+ kernels."
2018-06-01T11:10:56.745125284Z level=info msg="Map type mismatch for BPF map" file-path=/sys/fs/bpf/tc/globals/cilium_ipcache new="Longest prefix match trie" old=Hash
2018-06-01T11:10:56.745207889Z level=info msg="Flags mismatch for BPF map" file-path=/sys/fs/bpf/tc/globals/cilium_ipcache new=1 old=0
2018-06-01T11:10:56.745250084Z level=info msg="Removing map to allow for property upgrade (expect map data loss)" file-path=/sys/fs/bpf/tc/globals/cilium_ipcache
2018-06-01T11:10:56.745340018Z level=debug msg="Kernel does not support LPM maps, creating hash table for cilium_ipcache instead." error="Unable to create map: invalid argument"
2018-06-01T11:10:56.77543212Z level=info msg="Mounted BPF filesystem /sys/fs/bpf"
2018-06-01T11:10:56.776547084Z level=info msg="Waiting for etcd client to be ready"
2018-06-01T11:10:56.777926383Z level=debug msg="Updated controller" name=kvstore-etcd-session-renew subsys=controller uuid=75034f65-658c-11e8-a42d-080027aa233b
2018-06-01T11:10:56.778211873Z level=debug msg="Performing status check to etcd"
2018-06-01T11:10:56.778255118Z level=debug msg="Checking status to etcd endpoint http://k8s1:9732"
2018-06-01T11:10:56.780268326Z level=debug msg="Successfully verified version of etcd endpoint" etcdEndpoint="http://k8s1:9732" version=3.1.0
2018-06-01T11:10:56.780462258Z level=debug msg="Updated controller" name=kvstore-lease-keepalive subsys=controller uuid=7503b2ec-658c-11e8-a42d-080027aa233b
2018-06-01T11:10:56.78075157Z level=info msg="Valid label prefix configuration:"
2018-06-01T11:10:56.780761167Z level=info msg=" - :io.kubernetes.pod.namespace"
2018-06-01T11:10:56.780765249Z level=info msg=" - :io.cilium.k8s.namespace.labels"
2018-06-01T11:10:56.780768717Z level=info msg=" - !:io.kubernetes"
2018-06-01T11:10:56.780913745Z level=info msg=" - !:.*kubernetes.io"
2018-06-01T11:10:56.780921773Z level=info msg=" - !:pod-template-generation"
2018-06-01T11:10:56.780925406Z level=info msg=" - !:pod-template-hash"
2018-06-01T11:10:56.780928099Z level=info msg=" - !:controller-revision-hash"
2018-06-01T11:10:56.780987433Z level=info msg=" - !:annotation.cilium.io/"
2018-06-01T11:10:56.780995181Z level=info msg=" - !:annotation.cilium-identity"
2018-06-01T11:10:56.780998694Z level=info msg=" - !:annotation.sidecar.istio.io"
2018-06-01T11:10:56.781159598Z level=info msg="Container runtime options set: endpoint=/var/run/containerd/containerd.sock,endpoint=/var/run/crio/crio.sock,endpoint=unix:///var/run/docker.sock"
2018-06-01T11:10:56.781167101Z level=info msg="Initializing daemon"
2018-06-01T11:10:56.812705141Z level=info msg="Clearing leftover Cilium veths"
2018-06-01T11:10:56.812730315Z level=info msg="Launching endpoint builder workers"
2018-06-01T11:10:56.812733993Z level=debug msg="Creating worker threads" count=4
2018-06-01T11:10:56.812737024Z level=info msg="Waiting for k8s api-server to be ready..." subsys=k8s
2018-06-01T11:10:56.816353449Z level=info msg="Connected to k8s api-server" ipAddr="https://<IP_ADDRESS>:443" subsys=k8s
2018-06-01T11:10:56.821814603Z level=info msg="Retrieved node information from kubernetes" nodeName=k8s2 subsys=k8s
2018-06-01T11:10:56.821835091Z level=info msg="Received own node information from API server" ipAddr.ipv4=<IP_ADDRESS> ipAddr.ipv6="<nil>" nodeName=k8s2 subsys=k8s
2018-06-01T11:10:56.821838259Z level=info msg="Retrieved IPv4 allocation range for node. Using it for ipv4-range" node=k8s2 v4Prefix=<IP_ADDRESS>/16
2018-06-01T11:10:56.821994255Z level=info msg="Retrieved IPv6 allocation range for node. Using it for ipv6-range" node=k8s2 v6Prefix="f00d::a0f:0:0:0/96"
2018-06-01T11:10:56.822008835Z level=info msg="Automatically retrieved IP for node. Using it for ipv4-node" ipAddr=<IP_ADDRESS> node=k8s2
2018-06-01T11:10:56.822037664Z level=info msg="k8s mode: Allowing localhost to reach local endpoints"
2018-06-01T11:10:56.822050928Z level=info msg="Initializing node addressing"
2018-06-01T11:10:56.822188042Z level=info msg="Annotating k8s node with CIDR ranges"
2018-06-01T11:10:56.822233948Z level=debug msg="Updating node annotations with node CIDRs" nodeName=k8s2 subsys=k8s v4Prefix=<IP_ADDRESS>/16 v4healthIP.IPv4="<nil>" v6Prefix="f00d::a0f:0:0:0/96" v6healthIP.IPv6="<nil>"
2018-06-01T11:10:56.822239375Z level=info msg="Initializing IPAM"
2018-06-01T11:10:56.822250901Z level=info msg="Restoring endpoints from former life..."
2018-06-01T11:10:56.822534103Z level=debug msg="Reading directory" endpointID=173 file-path=/var/run/cilium/state/173/lxc_config.h
2018-06-01T11:10:56.822542999Z level=debug msg="Found endpoint C header file" endpointID=173 file-path=/var/run/cilium/state/173/lxc_config.h
2018-06-01T11:10:56.823106198Z level=debug msg="Reading directory" endpointID=29898 file-path=/var/run/cilium/state/29898/lxc_config.h
2018-06-01T11:10:56.823238872Z level=debug msg="Found endpoint C header file" endpointID=29898 file-path=/var/run/cilium/state/29898/lxc_config.h
2018-06-01T11:10:56.826156525Z level=debug msg="Restoring endpoint" endpointID=173
2018-06-01T11:10:56.826177991Z level=debug msg="Restoring endpoint from previous cilium instance" code=OK containerID=cba2f80484 endpointID=173 endpointState=restoring ipv4=<IP_ADDRESS> ipv6="f00d::a0f:0:0:ad" k8sPodName=":" policyRevision=0 type=0
2018-06-01T11:10:56.827054989Z level=debug msg="Updated controller" name="sync-to-k8s-ciliumendpoint (173)" subsys=controller uuid=750ac3b6-658c-11e8-a42d-080027aa233b
2018-06-01T11:10:56.827076923Z level=info msg="Interface cilium_health could not be found for endpoint being restored, ignoring" endpointID=29898
2018-06-01T11:10:56.827081452Z level=debug msg="Deleting endpoint" code=OK containerID=cilium-loc endpointID=29898 endpointState=disconnecting ipv4=<IP_ADDRESS> ipv6="f00d::a0f:0:0:74ca" k8sPodName=":" policyRevision=0 type=0
2018-06-01T11:10:56.831406025Z panic: runtime error: invalid memory address or nil pointer dereference
2018-06-01T11:10:56.831429186Z [signal SIGSEGV: segmentation violation code=0x1 addr=0x90 pc=0x1bd5ac5]
2018-06-01T11:10:56.831432798Z
2018-06-01T11:10:56.831435361Z goroutine 1 [running]:
2018-06-01T11:10:56.83143825Z github.com/cilium/cilium/pkg/kvstore/allocator.(*Allocator).Release(0x0, 0x3bddc80, 0xc421040150, 0x41c0060, 0xc42228d180)
2018-06-01T11:10:56.831441766Z 	/go/src/github.com/cilium/cilium/pkg/kvstore/allocator/allocator.go:624 +0x65
2018-06-01T11:10:56.8314452Z github.com/cilium/cilium/pkg/identity.(*Identity).Release(0xc421c62080, 0x74ca, 0x7ffff7ffabf6)
2018-06-01T11:10:56.831448481Z 	/go/src/github.com/cilium/cilium/pkg/identity/allocator.go:148 +0x9b
2018-06-01T11:10:56.831451695Z github.com/cilium/cilium/pkg/endpoint.(*Endpoint).LeaveLocked(0xc4200f9680, 0x3beadc0, 0xc42228d0e0, 0x3bdec80, 0xc4200461e0, 0xc42228b7b0)
2018-06-01T11:10:56.831467453Z 	/go/src/github.com/cilium/cilium/pkg/endpoint/endpoint.go:1693 +0x24a
2018-06-01T11:10:56.831471086Z main.(*Daemon).deleteEndpointQuiet(0xc42228d0e0, 0xc4200f9680, 0x45, 0xc42310b418, 0x1)
2018-06-01T11:10:56.831474492Z 	/go/src/github.com/cilium/cilium/daemon/endpoint.go:455 +0x34b
2018-06-01T11:10:56.831477736Z main.(*Daemon).restoreOldEndpoints(0xc42228d0e0, 0xc420d42100, 0x15, 0x1, 0xc420e97cb0, 0xc420e97f20, 0x0, 0x0, 0x0)
2018-06-01T11:10:56.831481082Z 	/go/src/github.com/cilium/cilium/daemon/state.go:81 +0x6d1
2018-06-01T11:10:56.831484318Z main.NewDaemon(0xc4204ba140, 0xc421689be8, 0x1)
2018-06-01T11:10:56.831487446Z 	/go/src/github.com/cilium/cilium/daemon/daemon.go:1147 +0x866
2018-06-01T11:10:56.831490624Z main.runDaemon()
2018-06-01T11:10:56.831493704Z 	/go/src/github.com/cilium/cilium/daemon/main.go:694 +0x9c
2018-06-01T11:10:56.831496891Z main.glob..func1(0x3ba4800, 0xc420113400, 0x0, 0x5)
2018-06-01T11:10:56.831500068Z 	/go/src/github.com/cilium/cilium/daemon/main.go:128 +0x30
2018-06-01T11:10:56.83150337Z github.com/cilium/cilium/vendor/github.com/spf13/cobra.(*Command).execute(0x3ba4800, 0xc4200100d0, 0x5, 0x5, 0x3ba4800, 0xc4200100d0)
2018-06-01T11:10:56.831508751Z 	/go/src/github.com/cilium/cilium/vendor/github.com/spf13/cobra/command.go:648 +0x234
2018-06-01T11:10:56.831512078Z github.com/cilium/cilium/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x3ba4800, 0xc421493020, 0x27ffd40, 0xc420447478)
2018-06-01T11:10:56.831515415Z 	/go/src/github.com/cilium/cilium/vendor/github.com/spf13/cobra/command.go:735 +0x2fe
2018-06-01T11:10:56.831518684Z github.com/cilium/cilium/vendor/github.com/spf13/cobra.(*Command).Execute(0x3ba4800, 0x0, 0xc42024d300)
2018-06-01T11:10:56.831522054Z 	/go/src/github.com/cilium/cilium/vendor/github.com/spf13/cobra/command.go:693 +0x2b
2018-06-01T11:10:56.831525104Z main.main()
2018-06-01T11:10:56.831529299Z 	/go/src/github.com/cilium/cilium/daemon/main.go:142 +0x13a

Attached logs:
f0c5341e_K8sValidatedUpdates_Updating_Cilium_stable_to_master.zip

@eloycoto That is not the build that succeeded, the bug above was fixed in commit f23357fa5b. The PR was merged with a green build.

Another failure:
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2693/testReport/k8s-1/10/K8sValidatedUpdates_Updating_Cilium_stable_to_master/
Stacktrace
/home/jenkins/workspace/Ginkgo-CI-Tests-Pipeline/src/github.com/cilium/cilium/test/ginkgo-ext/scopes.go:373
Cannot curl app1-service
Expected command: kubectl exec -n default app2-5b59d5764b-8c6vn -- curl -s --fail --connect-timeout 5 --max-time 5 http://app1-service.default.svc.cluster.local/public
To succeed, but it failed:
Exitcode: 28
Stdout:

Stderr:
 	 command terminated with exit code 28

/home/jenkins/workspace/Ginkgo-CI-Tests-Pipeline/src/github.com/cilium/cilium/test/k8sT/Updates.go:120

Standard Output
STEP: Checking that installed image is "cilium/cilium:v1.0.0"
STEP: Creating some endpoints and L7 policy
===================== TEST FAILED =====================
cmd: kubectl get pods -o wide --all-namespaces
NAMESPACE     NAME                           READY     STATUS    RESTARTS   AGE       IP              NODE
default       app1-c4954c58c-blwc7           1/1       Running   0          1m        <IP_ADDRESS>      k8s1
default       app1-c4954c58c-hkx2l           1/1       Running   0          1m        <IP_ADDRESS>     k8s1
default       app2-5b59d5764b-8c6vn          1/1       Running   0          1m        <IP_ADDRESS>      k8s1
default       app3-6d745c45f6-4smzm          1/1       Running   0          1m        <IP_ADDRESS>      k8s1
kube-system   cilium-5klx7                   1/1       Running   0          1m        <IP_ADDRESS>   k8s1
kube-system   cilium-h968w                   1/1       Running   0          1m        <IP_ADDRESS>   k8s2
kube-system   etcd-k8s1                      1/1       Running   0          16m       <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running   0          15m       <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running   0          15m       <IP_ADDRESS>   k8s1
kube-system   kube-dns-59d8c5f9b5-wj989      2/3       Running   0          16m       <IP_ADDRESS>     k8s2
kube-system   kube-proxy-x2bdw               1/1       Running   0          8m        <IP_ADDRESS>   k8s2
kube-system   kube-proxy-zrb4c               1/1       Running   0          16m       <IP_ADDRESS>   k8s1
kube-system   kube-scheduler-k8s1            1/1       Running   0          15m       <IP_ADDRESS>   k8s1

cmd: kubectl exec -n kube-system cilium-5klx7 -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])               IPv6                 IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
173        Disabled           Disabled          2618       k8s:id=app2                               f00d::a0a:0:0:ad     <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
13949      Enabled            Disabled          36013      k8s:id=app1                               f00d::a0a:0:0:367d   <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
29381      Disabled           Disabled          56464      k8s:id=app3                               f00d::a0a:0:0:72c5   <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
29898      Disabled           Disabled          51351      reserved:health                           f00d::a0a:0:0:74ca   <IP_ADDRESS>   ready
48896      Enabled            Disabled          36013      k8s:id=app1                               f00d::a0a:0:0:bf00   <IP_ADDRESS>   ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp

cmd: kubectl exec -n kube-system cilium-h968w -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])                   IPv6                   IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
26743      Disabled           Disabled          6044       k8s:io.kubernetes.pod.namespace=kube-system   f00d::a0a:100:0:6877   <IP_ADDRESS>   ready
                                                           k8s:k8s-app=kube-dns
29898      Disabled           Disabled          51351      reserved:health                               f00d::a0a:100:0:74ca   <IP_ADDRESS>   ready

===================== EXITING REPORT GENERATION =====================

Related to https://github.com/cilium/cilium/issues/3993#issuecomment-394645783

@eloycoto are you sure this is related to #3993 ? Please provide more context.

New fail after EndpointWaitUntilReady is introduced:
https://jenkins.cilium.io/job/cilium-ginkgo/job/cilium/job/master/974/testReport/junit/k8s-1/7/K8sValidatedUpdates_Updating_Cilium_stable_to_master/
f0c5341e_K8sValidatedUpdates_Updating_Cilium_stable_to_master(2).zip
Pods are not ready after timeot:
/home/jenkins/workspace/cilium-ginkgo_cilium_master-QVKDPVJ2A6E272IRUX7X6DCB5FBLCQDKRTOMHPZS7ZECX3RM5C3A/src/github.com/cilium/cilium/test/ginkgo-ext/scopes.go:373
Cilium is not ready after timeout
Expected
    <*errors.errorString | 0xc420584fc0>: {
        s: "Timeout reached: could not get Pods",
    }
to be nil
/home/jenkins/workspace/cilium-ginkgo_cilium_master-QVKDPVJ2A6E272IRUX7X6DCB5FBLCQDKRTOMHPZS7ZECX3RM5C3A/src/github.com/cilium/cilium/test/k8sT/Updates.go:158

Pod list:
cmd: kubectl get pods -o wide --all-namespaces
NAMESPACE     NAME                           READY     STATUS    RESTARTS   AGE       IP              NODE
default       app1-3318830813-4c3cq          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app1-3318830813-hv6zr          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app2-3691078314-qrdzw          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app3-753781860-8dzzn           1/1       Running   0          9m        <IP_ADDRESS>     k8s1
kube-system   cilium-5xm73                   1/1       Running   0          5m        <IP_ADDRESS>   k8s2
kube-system   cilium-j5tqp                   0/1       Running   1          5m        <IP_ADDRESS>   k8s1
kube-system   etcd-k8s1                      1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-dns-1992960195-w0vp9      3/3       Running   0          47m       <IP_ADDRESS>      k8s2
kube-system   kube-proxy-d2k7g               1/1       Running   0          19m       <IP_ADDRESS>   k8s2
kube-system   kube-proxy-ng786               1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-scheduler-k8s1            1/1       Running   0          47m       <IP_ADDRESS>   k8s1

There is no error message in the cilium-j5tqp pod + Status is working:
2018-06-06T15:58:10.713567432Z level=info msg="Initializing Cilium API"
2018-06-06T15:58:10.778078443Z level=debug msg="Skipping network because of gateway mismatch" endpointID=2202fb39d8e660da813f2d1dcf288a4ea2d16922f72eed00c42ad5ebc229fcbc obj="&{<nil> [] [] f6e6d0c360d327873487a7e33493c6328b5566ee95b59a06f9cdd8ce0549064d 2202fb39d8e660da813f2d1dcf288a4ea2d16922f72eed00c42ad5ebc229fcbc   0   0 }" subsys=workload-watcher
2018-06-06T15:58:10.778364892Z level=debug msg="IP address assigned by Cilium could not be derived from container event" containerID=dea75c4e93 subsys=workload-watcher
2018-06-06T15:58:10.778563764Z level=debug msg="Trying to associate container with existing endpoint" containerID=dea75c4e93 containerName=/k8s_POD_kube-proxy-ng786_kube-system_6366240c-699c-11e8-b69f-080027aa233b_0 endpointID=0 identityLabels="k8s:io.kubernetes.pod.namespace=kube-system,k8s:k8s-app=kube-proxy" maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-06T15:58:10.77874528Z level=debug msg="Matching cilium endpoint for container create event does not exist yet" containerID=dea75c4e93 maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-06T15:58:10.779167938Z level=info msg="No request received to manage networking for container" containerID=dea75c4e93 maxRetry=20 subsys=workload-watcher willRetry=false
2018-06-06T15:58:10.790883429Z level=info msg="Daemon initialization completed"
2018-06-06T15:58:10.791659125Z level=info msg="Serving cilium at unix:///var/run/cilium/cilium.sock"

That is at 15:58, and the test failed on 16:02.
The container status was incorrect:
                "containerStatuses": [
                    {
                        "containerID": "docker://5592677bbf99296af0334a0f1b363639652a488e07783df6d0eebbd4e5d94868",
                        "image": "k8s1:5000/cilium/cilium-dev:latest",
                        "imageID": "docker-pullable://k8s1:5000/cilium/cilium-dev@sha256:255dc85f775c5888b1a42958110571420561a360c69fff8449cba61216b7f982",
                        "lastState": {
                            "terminated": {
                                "containerID": "docker://228bf1d7f7ecfbd9a6aef6914de2cc7c19c71c7056950208b2b2dcde9a885038",
                                "exitCode": 1,
                                "finishedAt": "2018-06-06T15:57:50Z",
                                "reason": "Error",
                                "startedAt": "2018-06-06T15:57:28Z"
                            }
                        },
                        "name": "cilium-agent",
                        "ready": false,
                        "restartCount": 1,
                        "state": {
                            "running": {
                                "startedAt": "2018-06-06T15:57:51Z"
                            }
                        }
                    }
                ],

And the describe is like this:
Events:
  FirstSeen	LastSeen	Count	From		SubObjectPath				Type		Reason			Message
  ---------	--------	-----	----		-------------				--------	------			-------
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "etc-cni-netd"
  7m		7m		1	kubelet, k8s1	spec.initContainers{clean-cilium-state}	Normal		Created			Created container
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "cilium-run"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "docker-socket"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "bpf-maps"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "etcd-config-path"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "cilium-token-9kjrg"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "etcd-secrets"
  7m		7m		1	kubelet, k8s1						Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "cni-path"
  7m		7m		1	kubelet, k8s1	spec.initContainers{clean-cilium-state}	Normal		Pulled			Container image "docker.io/library/busybox:1.28.4" already present on machine
  7m		7m		1	kubelet, k8s1	spec.initContainers{clean-cilium-state}	Normal		Started			Started container
  6m		6m		3	kubelet, k8s1	spec.containers{cilium-agent}		Warning		Unhealthy		Readiness probe failed: Get http:///var/run/cilium/cilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory
Is the agent running?

  7m	6m	2	kubelet, k8s1	spec.containers{cilium-agent}	Normal	Pulling	pulling image "k8s1:5000/cilium/cilium-dev:latest"
  7m	6m	2	kubelet, k8s1	spec.containers{cilium-agent}	Normal	Pulled	Successfully pulled image "k8s1:5000/cilium/cilium-dev:latest"
  7m	6m	2	kubelet, k8s1	spec.containers{cilium-agent}	Normal	Created	Created container
  7m	6m	2	kubelet, k8s1	spec.containers{cilium-agent}	Normal	Started	Started container

Looking at the previous logs for cilium-j5tqp, there are worrisome messages containing the string error:
2018-06-06T15:57:36.080906507Z level=debug msg="Kernel does not support LPM maps, creating hash table for cilium_ipcache instead." error="Unable to create map: invalid argument"
2018-06-06T15:57:44.637098593Z level=warning msg="Regeneration of endpoint program failed" containerID=f2160697b6 endpointID=173 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.637870436Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=f2160697b6 endpointID=173 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.640465834Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.657958911Z level=warning msg="Regeneration of endpoint program failed" containerID=08cd77e1b4 endpointID=29381 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.65818144Z level=warning msg="Regeneration of endpoint program failed" containerID=534d48a041 endpointID=13949 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.658452356Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=08cd77e1b4 endpointID=29381 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.658744918Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=534d48a041 endpointID=13949 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.659185614Z level=warning msg="Regeneration of endpoint program failed" containerID=bd1258b3a6 endpointID=25729 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.659521Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=bd1258b3a6 endpointID=25729 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.660356648Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.661009274Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.661034861Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.988753975Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:45.986878378Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:46.988249833Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:47.989442781Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:48.990853838Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:49.99653886Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:50.201106156Z level=fatal msg="Cilium endpoint failed to run" error="stat /var/run/cilium/state/health-endpoint.pid: no such file or directory"

And for the logs of the pod (i.e., just logs, not previous logs):
2018-06-06T15:57:56.055403189Z level=debug msg="Kernel does not support LPM maps, creating hash table for cilium_ipcache instead." error="Unable to create map: invalid argument"
2018-06-06T15:57:57.039276368Z level=warning msg="Regeneration of endpoint program failed" containerID=08cd77e1b4 endpointID=29381 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0
2018-06-06T15:57:57.039293541Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=08cd77e1b4 endpointID=29381 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:57.040529938Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:57.050352649Z level=warning msg="Regeneration of endpoint program failed" containerID=bd1258b3a6 endpointID=25729 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0
2018-06-06T15:57:57.050703775Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=bd1258b3a6 endpointID=25729 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:57.057970708Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:57.070487847Z level=warning msg="Regeneration of endpoint program failed" containerID=f2160697b6 endpointID=173 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0
2018-06-06T15:57:57.074183873Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=f2160697b6 endpointID=173 endpointState=waiting-to-regenerate ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=5 type=200
2018-06-06T15:57:57.074947778Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:58:02.192161224Z level=warning msg="Regeneration of endpoint program failed" containerID=bd1258b3a6 endpointID=25729 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=5
2018-06-06T15:58:02.192196796Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=bd1258b3a6 endpointID=25729 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=5 type=200
2018-06-06T15:58:02.19238231Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:58:02.199880723Z level=warning msg="Regeneration of endpoint program failed" containerID=534d48a041 endpointID=13949 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0
2018-06-06T15:58:02.200015701Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=534d48a041 endpointID=13949 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:58:02.201103552Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:58:02.211041979Z level=warning msg="Regeneration of endpoint program failed" containerID=f2160697b6 endpointID=173 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=5
2018-06-06T15:58:02.21105408Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=f2160697b6 endpointID=173 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=5 type=200
2018-06-06T15:58:02.211064857Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:58:02.513964882Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:03.525528978Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:04.525756962Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:05.52717656Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:06.536157753Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:07.539025085Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:08.543481248Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:09.545963248Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:58:10.569603681Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"

I have bee looking into this and will have an update of my initial investigation posted here shortly.

Looking into the build @eloycoto referenced here: https://github.com/cilium/cilium/issues/4329#issuecomment-395146609
I filed https://github.com/cilium/cilium/issues/4390 to address an issue discovered in this PR, but I am unsure whether it is the actual cause of the test failure here (cilium not being ready).

As @eloycoto mentioned, the pod cilium-j5tqp is in not-ready state:
cmd: "kubectl get pods -o wide --all-namespaces" exitCode: 0
 NAMESPACE     NAME                           READY     STATUS    RESTARTS   AGE       IP              NODE
default       app1-3318830813-4c3cq          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app1-3318830813-hv6zr          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app2-3691078314-qrdzw          1/1       Running   0          9m        <IP_ADDRESS>      k8s1
default       app3-753781860-8dzzn           1/1       Running   0          9m        <IP_ADDRESS>     k8s1
kube-system   cilium-5xm73                   1/1       Running   0          5m        <IP_ADDRESS>   k8s2
kube-system   cilium-j5tqp                   0/1       Running   1          5m        <IP_ADDRESS>   k8s1
kube-system   etcd-k8s1                      1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-dns-1992960195-w0vp9      3/3       Running   0          47m       <IP_ADDRESS>      k8s2
kube-system   kube-proxy-d2k7g               1/1       Running   0          19m       <IP_ADDRESS>   k8s2
kube-system   kube-proxy-ng786               1/1       Running   0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-scheduler-k8s1            1/1       Running   0          47m       <IP_ADDRESS>   k8s1

What's odd is that in test-output.log, right after the above command to get the pods via kubectl which shows that the aforementioned cilium pod is not ready, we can see that the cilium API is being served:
time="2018-06-06T16:02:33Z" level=debug msg="running command: kubectl exec -n kube-system cilium-j5tqp -- cilium endpoint list"
cmd: "kubectl exec -n kube-system cilium-j5tqp -- cilium endpoint list" exitCode: 0
 ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])               IPv6                 IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
173        Enabled            Disabled          53110      k8s:id=app1                               f00d::a0a:0:0:ad     <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
13949      Enabled            Disabled          53110      k8s:id=app1                               f00d::a0a:0:0:367d   <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
25729      Disabled           Disabled          40510      k8s:id=app3                               f00d::a0a:0:0:6481   <IP_ADDRESS>   ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
29381      Disabled           Disabled          31359      k8s:id=app2                               f00d::a0a:0:0:72c5   <IP_ADDRESS>    ready
                                                           k8s:io.kubernetes.pod.namespace=default
                                                           k8s:zgroup=testapp
53495      Disabled           Disabled          4          reserved:health                           f00d::a0a:0:0:d0f7   <IP_ADDRESS>    ready

From cilium-bugtool  for that pod, cilium status returns:
# cilium status --verbose

KVStore:                Ok   etcd: 1/1 connected: http://k8s1:9732 - 3.1.0 (Leader)
ContainerRuntime:       Ok   docker daemon: OK
Kubernetes:             Ok   OK
Kubernetes APIs:        ["core/v1::Node", "CustomResourceDefinition", "cilium/v2::CiliumNetworkPolicy", "networking.k8s.io/v1::NetworkPolicy", "core/v1::Service", "core/v1::Endpoint"]
Cilium:                 Ok   OK
NodeMonitor:            Disabled
Cilium health daemon:   Ok
IPv4 address pool:      7/255 allocated
<IP_ADDRESS>
<IP_ADDRESS>
<IP_ADDRESS>
<IP_ADDRESS>
<IP_ADDRESS>
<IP_ADDRESS>
<IP_ADDRESS>
IPv6 address pool:   6/4294967295 allocated
f00d::a0a:0:0:ad
f00d::a0a:0:0:367d
f00d::a0a:0:0:6481
f00d::a0a:0:0:72c5
f00d::a0a:0:0:8ad6
f00d::a0a:0:0:d0f7
Controller Status:   21/21 healthy
Name                                        Last success   Last error   Count   Message
ipcache-bpf-garbage-collection              51s ago        never        0       no error
kvstore-etcd-session-renew                  never          never        0       no error
kvstore-lease-keepalive                     57s ago        never        0       no error
lxcmap-bpf-host-sync                        6s ago         never        0       no error
metricsmap-bpf-prom-sync                    5s ago         never        0       no error
resolve-identity-53495                      51s ago        never        0       no error
sync-IPv4-identity-mapping (53495)          50s ago        never        0       no error
sync-IPv6-identity-mapping (53495)          51s ago        never        0       no error
sync-cnp-policy-status (v2 default/rule1)   5m21s ago      never        0       no error
sync-identity-to-k8s-pod (53495)            51s ago        never        0       no error
sync-policymap-13949                        39s ago        never        0       no error
sync-policymap-173                          39s ago        never        0       no error
sync-policymap-25729                        39s ago        never        0       no error
sync-policymap-29381                        39s ago        never        0       no error
sync-policymap-53495                        39s ago        never        0       no error
sync-to-k8s-ciliumendpoint (13949)          10s ago        never        0       no error
sync-to-k8s-ciliumendpoint (173)            10s ago        never        0       no error
sync-to-k8s-ciliumendpoint (25729)          10s ago        never        0       no error
sync-to-k8s-ciliumendpoint (29381)          10s ago        never        0       no error
sync-to-k8s-ciliumendpoint (53495)          8s ago         never        0       no error
sync-to-k8s-ciliumendpoint-gc (k8s1)        43s ago        never        0       no error
Proxy Status:   OK, ip <IP_ADDRESS>, port-range 10000-20000
Cluster health:      0/2 reachable   (2018-06-06T16:03:14Z)
Name               IP              Reachable   Endpoints reachable
k8s1 (localhost)   <IP_ADDRESS>   false       false
k8s2               <IP_ADDRESS>   false       false

Of note, the two pods are not reachable via the `Cluster health` section at the bottom. However, @joestringer said that the end "cluster health section" showing that the localhost / k8s2 are not reachable should not cause `cilium status` to return with error.

From the pods_status.txt as @eloycoto pointed out above, the events for this pod that have occurred:
Conditions:
  Type		Status
  Initialized 	True
  Ready 	False
  PodScheduled 	True
...

The count is 3, and it looks like the last status check occurred 6 minutes ago if I am reading the output correctly?
 Does the readiness probe backoff after restarting the pod?

Now I'm looking into why the pod restarted. To do this, I looked into the logs for the previous instance of the pod cilium-j5tqp-previous.log and searched for error:
2018-06-06T15:57:36.080906507Z level=debug msg="Kernel does not support LPM maps, creating hash table for cilium_ipcache instead." error="Unable to create map: invalid argument"
2018-06-06T15:57:44.637098593Z level=warning msg="Regeneration of endpoint program failed" containerID=f2160697b6 endpointID=173 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.637870436Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=f2160697b6 endpointID=173 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.640465834Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.657958911Z level=warning msg="Regeneration of endpoint program failed" containerID=08cd77e1b4 endpointID=29381 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.65818144Z level=warning msg="Regeneration of endpoint program failed" containerID=534d48a041 endpointID=13949 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.658452356Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=08cd77e1b4 endpointID=29381 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.658744918Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=534d48a041 endpointID=13949 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.659185614Z level=warning msg="Regeneration of endpoint program failed" containerID=bd1258b3a6 endpointID=25729 error="can't update network policy, proxy disabled" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0
2018-06-06T15:57:44.659521Z level=debug msg="Error regenerating endpoint: can't update network policy, proxy disabled" code=Failure containerID=bd1258b3a6 endpointID=25729 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0 type=200
2018-06-06T15:57:44.660356648Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.661009274Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.661034861Z level=warning msg="Unable to send monitor notification" error="monitor pipe not opened"
2018-06-06T15:57:44.988753975Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:45.986878378Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:46.988249833Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:47.989442781Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:48.990853838Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:49.99653886Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:50.201106156Z level=fatal msg="Cilium endpoint failed to run" error="stat /var/run/cilium/state/health-endpoint.pid: no such file or directory"

I had to do some correlation in the previous logs to figure out what the endpoint ID of the health endpoint was, but found it:
2018-06-06T15:57:45.154823083Z level=info msg="Identity of endpoint changed" containerID=cilium-loc endpointID=55782 identity=4 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" oldIdentity="no identity" policyRevision=0

The only logs for that endpoint ID:
2018-06-06T15:57:45.087849991Z level=debug msg="Updated controller" name="sync-to-k8s-ciliumendpoint (55782)" subsys=controller uuid=5a07783b-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.08891714Z level=info msg="New endpoint" containerID=cilium-loc endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.089786172Z level=debug msg="Assigning security relevant label" containerID=cilium-loc endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" labels="reserved:health" policyRevision=0
2018-06-06T15:57:45.090423482Z level=debug msg="Endpoint has reserved identity, changing synchronously" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.091017907Z level=debug msg="Resolving identity for labels" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.124632935Z level=debug msg="Assigned new identity to endpoint" containerID=cilium-loc endpointID=55782 identity=4 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.141880261Z level=debug msg="Set identity for this endpoint" code=OK containerID=cilium-loc endpointID=55782 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0 type=0
2018-06-06T15:57:45.145030962Z level=debug msg="Updated controller" name="sync-identity-to-k8s-pod (55782)" subsys=controller uuid=5a107344-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.152868453Z level=debug msg="Updated controller" name="sync-IPv4-identity-mapping (55782)" subsys=controller uuid=5a11a17d-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.153493329Z level=debug msg="Updated controller" name="sync-IPv6-identity-mapping (55782)" subsys=controller uuid=5a11c5df-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.154823083Z level=info msg="Identity of endpoint changed" containerID=cilium-loc endpointID=55782 identity=4 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" oldIdentity="no identity" policyRevision=0
2018-06-06T15:57:45.158478904Z level=debug msg="Triggering regeneration due to new identity" code=OK containerID=cilium-loc endpointID=55782 endpointState=waiting-to-regenerate ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0 type=0
2018-06-06T15:57:45.158836876Z level=debug msg="Updated controller" name=resolve-identity-55782 subsys=controller uuid=5a12865b-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.160505148Z level=debug msg="Endpoint labels unchanged, skipping resolution of identity" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.193305826Z level=debug msg="Deleting CEP on first run" containerID=cilium-loc controller="sync-to-k8s-ciliumendpoint (55782)" endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0

The code which causes the agent to exit: https://github.com/cilium/cilium/blob/91287b9f0665ddd22fa4933eece6ae276e4157af/cilium-health/launch/endpoint.go#L191-L202
So, after 5 seconds, the health endpoint could not be started. Given that that log was at 15:57:50.201106156, let's see what happened in the preceding five seconds via the logs to try to see what caused such a large delay in starting the health endpoint.
The health daemon is "launched:
2018-06-06T15:57:44.974999455Z level=info msg="Launching Cilium health daemon"
2018-06-06T15:57:44.975008114Z level=info msg="Launching Cilium health endpoint"

This corresponds to the following code:
https://github.com/cilium/cilium/blob/91287b9f0665ddd22fa4933eece6ae276e4157af/daemon/main.go#L714-L717
But there is a log message which indicates difficulty connecting to the local Cilium instance:
2018-06-06T15:57:44.988753975Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"

This is OK though because the Cilium API isn't available yet, and the code expects this:
https://github.com/cilium/cilium/blob/91287b9f0665ddd22fa4933eece6ae276e4157af/cilium-health/launch/launcher.go#L50-L60
All of the logs from between when the health daemon was "launched" and when the agent crashed over a five-second period:
2018-06-06T15:57:44.974999455Z level=info msg="Launching Cilium health daemon"
2018-06-06T15:57:44.975008114Z level=info msg="Launching Cilium health endpoint"
2018-06-06T15:57:44.975433302Z level=debug msg="Didn't find existing link"
2018-06-06T15:57:44.988753975Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:45.01214938Z level=debug msg="Created veth pair" vethPair="[cilium cilium_health]"
2018-06-06T15:57:45.087849991Z level=debug msg="Updated controller" name="sync-to-k8s-ciliumendpoint (55782)" subsys=controller uuid=5a07783b-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.08891714Z level=info msg="New endpoint" containerID=cilium-loc endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.089786172Z level=debug msg="Assigning security relevant label" containerID=cilium-loc endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" labels="reserved:health" policyRevision=0
2018-06-06T15:57:45.090423482Z level=debug msg="Endpoint has reserved identity, changing synchronously" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.091017907Z level=debug msg="Resolving identity for labels" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.092479491Z level=debug msg="Resolving identity" identityLabels="reserved:health"
2018-06-06T15:57:45.100098876Z level=debug msg="Resolved reserved identity" identity=health identityLabels="reserved:health" isNew=false
2018-06-06T15:57:45.124632935Z level=debug msg="Assigned new identity to endpoint" containerID=cilium-loc endpointID=55782 identity=4 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.141880261Z level=debug msg="Set identity for this endpoint" code=OK containerID=cilium-loc endpointID=55782 endpointState=ready ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0 type=0
2018-06-06T15:57:45.145030962Z level=debug msg="Updated controller" name="sync-identity-to-k8s-pod (55782)" subsys=controller uuid=5a107344-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.152868453Z level=debug msg="Updated controller" name="sync-IPv4-identity-mapping (55782)" subsys=controller uuid=5a11a17d-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.153493329Z level=debug msg="Updated controller" name="sync-IPv6-identity-mapping (55782)" subsys=controller uuid=5a11c5df-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.154823083Z level=info msg="Identity of endpoint changed" containerID=cilium-loc endpointID=55782 identity=4 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" oldIdentity="no identity" policyRevision=0
2018-06-06T15:57:45.158478904Z level=debug msg="Triggering regeneration due to new identity" code=OK containerID=cilium-loc endpointID=55782 endpointState=waiting-to-regenerate ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0 type=0
2018-06-06T15:57:45.158836876Z level=debug msg="Updated controller" name=resolve-identity-55782 subsys=controller uuid=5a12865b-69a2-11e8-972e-080027aa233b
2018-06-06T15:57:45.160505148Z level=debug msg="Endpoint labels unchanged, skipping resolution of identity" containerID=cilium-loc endpointID=55782 identityLabels="reserved:health" ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.177721567Z level=debug msg="upserting IP->ID mapping to kvstore" identity=health ipAddr="f00d::a0a:0:0:d9e6" ipMask="<nil>" modification=Upsert
2018-06-06T15:57:45.182187982Z level=debug msg="upserting IP->ID mapping to kvstore" identity=health ipAddr=<IP_ADDRESS> ipMask="<nil>" modification=Upsert
2018-06-06T15:57:45.184374602Z level=debug msg="Received event from etcd: {Header:{ClusterId:3373127551666285087 MemberId:13506963981489885289 Revision:260 RaftTerm:3} Events:[0xc4221a3da0] CompactRevision:0 Canceled:false Created:false closeErr:<nil> cancelReason:}" prefix=cilium/state/ip/v1 revision=260 watcher=endpointIPWatcher
2018-06-06T15:57:45.184424385Z level=debug msg="Emitting create event for cilium/state/ip/v1/default/f00d::a0a:0:0:d9e6=[123 34 73 80 34 58 34 102 48 48 100 58 58 97 48 97 58 48 58 48 58 100 57 101 54 34 44 34 77 97 115 107 34 58 110 117 108 108 44 34 73 68 34 58 52 44 34 77 101 116 97 100 97 116 97 34 58 34 99 105 108 105 117 109 45 103 108 111 98 97 108 58 100 101 102 97 117 108 116 58 107 56 115 49 58 53 53 55 56 50 34 125]" prefix=cilium/state/ip/v1 revision=260 watcher=endpointIPWatcher
2018-06-06T15:57:45.184557985Z level=debug msg="received event" key="cilium/state/ip/v1/default/f00d::a0a:0:0:d9e6" kvstore-event=create
2018-06-06T15:57:45.184897677Z level=debug msg="Removing from ipcache layer" ipAddr="f00d::a0a:0:0:d9e6"
2018-06-06T15:57:45.184934018Z level=debug msg="Upserting into ipcache layer" identity=health ipAddr="f00d::a0a:0:0:d9e6"
2018-06-06T15:57:45.185114029Z level=debug msg="endpoint IP cache state change" identity=health ipAddr="f00d::a0a:0:0:d9e6" ipMask="<nil>" modification=Upsert oldIdentity=0
2018-06-06T15:57:45.185148975Z level=debug msg="1 resource names requested, filtering resources" xdsClientNode="<nil>" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.185167621Z level=debug msg="resource found, last modified in version 28" xdsClientNode="<nil>" xdsResourceName=4 xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.185184336Z level=debug msg="returning 1 resources out of 1 requested" xdsClientNode="<nil>" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.185355014Z level=debug msg="preparing new cache transaction: upserting 1 entries, deleting 0 entries" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=29
2018-06-06T15:57:45.185387946Z level=debug msg="updating resource in cache" xdsResourceName=4 xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=29
2018-06-06T15:57:45.185405027Z level=debug msg="committing cache transaction and notifying of new version" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=29
2018-06-06T15:57:45.185420044Z level=debug msg="daemon notified of IP-Identity cache state change" identity=health ipAddr="f00d::a0a:0:0:d9e6" ipMask="<nil>" modification=Upsert
2018-06-06T15:57:45.193305826Z level=debug msg="Deleting CEP on first run" containerID=cilium-loc controller="sync-to-k8s-ciliumendpoint (55782)" endpointID=55782 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:d9e6" k8sPodName=":" policyRevision=0
2018-06-06T15:57:45.218063689Z level=debug msg="Received event from etcd: {Header:{ClusterId:3373127551666285087 MemberId:13506963981489885289 Revision:261 RaftTerm:3} Events:[0xc421b428a0] CompactRevision:0 Canceled:false Created:false closeErr:<nil> cancelReason:}" prefix=cilium/state/ip/v1 revision=261 watcher=endpointIPWatcher
2018-06-06T15:57:45.218132123Z level=debug msg="Emitting create event for cilium/state/ip/v1/default/<IP_ADDRESS>=[123 34 73 80 34 58 34 49 48 46 49 48 46 48 46 50 50 54 34 44 34 77 97 115 107 34 58 110 117 108 108 44 34 73 68 34 58 52 44 34 77 101 116 97 100 97 116 97 34 58 34 99 105 108 105 117 109 45 103 108 111 98 97 108 58 100 101 102 97 117 108 116 58 107 56 115 49 58 53 53 55 56 50 34 125]" prefix=cilium/state/ip/v1 revision=261 watcher=endpointIPWatcher
2018-06-06T15:57:45.218156324Z level=debug msg="received event" key=cilium/state/ip/v1/default/<IP_ADDRESS> kvstore-event=create
2018-06-06T15:57:45.21829075Z level=debug msg="Removing from ipcache layer" ipAddr=<IP_ADDRESS>
2018-06-06T15:57:45.218382148Z level=debug msg="Upserting into ipcache layer" identity=health ipAddr=<IP_ADDRESS>
2018-06-06T15:57:45.218403598Z level=debug msg="endpoint IP cache state change" identity=health ipAddr=<IP_ADDRESS> ipMask="<nil>" modification=Upsert oldIdentity=0
2018-06-06T15:57:45.218484808Z level=debug msg="1 resource names requested, filtering resources" xdsClientNode="<nil>" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.218508207Z level=debug msg="resource found, last modified in version 29" xdsClientNode="<nil>" xdsResourceName=4 xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.218525384Z level=debug msg="returning 1 resources out of 1 requested" xdsClientNode="<nil>" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo="<nil>"
2018-06-06T15:57:45.218617742Z level=debug msg="preparing new cache transaction: upserting 1 entries, deleting 0 entries" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=30
2018-06-06T15:57:45.21863964Z level=debug msg="updating resource in cache" xdsResourceName=4 xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=30
2018-06-06T15:57:45.218684101Z level=debug msg="committing cache transaction and notifying of new version" xdsTypeURL=type.googleapis.com/cilium.NetworkPolicyHosts xdsVersionInfo=30
2018-06-06T15:57:45.218765423Z level=debug msg="daemon notified of IP-Identity cache state change" identity=health ipAddr=<IP_ADDRESS> ipMask="<nil>" modification=Upsert
2018-06-06T15:57:45.986878378Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:46.345965235Z level=debug msg="Performing status check to etcd"
2018-06-06T15:57:46.346035135Z level=debug msg="Checking status to etcd endpoint http://k8s1:9732"
2018-06-06T15:57:46.596310716Z level=debug msg="Skipping CiliumEndpoint update because it has no k8s pod name" containerID=534d48a041 controller="sync-to-k8s-ciliumendpoint (13949)" endpointID=13949 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:367d" k8sPodName=":" policyRevision=0
2018-06-06T15:57:46.608960302Z level=debug msg="Skipping CiliumEndpoint update because it has no k8s pod name" containerID=f2160697b6 controller="sync-to-k8s-ciliumendpoint (173)" endpointID=173 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:ad" k8sPodName=":" policyRevision=0
2018-06-06T15:57:46.631989778Z level=debug msg="Skipping CiliumEndpoint update because it has no k8s pod name" containerID=bd1258b3a6 controller="sync-to-k8s-ciliumendpoint (25729)" endpointID=25729 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:6481" k8sPodName=":" policyRevision=0
2018-06-06T15:57:46.654491583Z level=debug msg="Skipping CiliumEndpoint update because it has no k8s pod name" containerID=08cd77e1b4 controller="sync-to-k8s-ciliumendpoint (29381)" endpointID=29381 ipv4=<IP_ADDRESS> ipv6="f00d::a0a:0:0:72c5" k8sPodName=":" policyRevision=0
2018-06-06T15:57:46.764534264Z level=info msg="Serving cilium node monitor at unix:///var/run/cilium/monitor.sock"
2018-06-06T15:57:46.78260507Z level=info msg="Beginning to read cilium agent events"
2018-06-06T15:57:46.988249833Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:47.989442781Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:48.990853838Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:49.99653886Z level=debug msg="Cannot establish connection to local cilium instance" error="Get http://%2Fvar%2Frun%2Fcilium%2Fcilium.sock/v1/healthz: dial unix /var/run/cilium/cilium.sock: connect: no such file or directory"
2018-06-06T15:57:50.201106156Z level=fatal msg="Cilium endpoint failed to run" error="stat /var/run/cilium/state/health-endpoint.pid: no such file or directory"

Nothing happens over five seconds for starting the health endpoint, and I'm unable to deduce why :( @joestringer can you look into why the health endpoint cannot start here? Let me know how I can help.

Multiple issues here:

health endpoint could not be synchronously started after five seconds, and thus the readiness check failed in Kubernetes, causing Cilium to restart.
After restart, it appears that K8s doesn't check if cilium is ready, even though it is. Thus, the tests fail.

I also think https://github.com/cilium/cilium/issues/4329#issuecomment-394281615 needs to be triaged separately to determine what the root cause of that failure is, as it is not a "pods not ready" issue.

@ianvernon around the https://github.com/cilium/cilium/issues/4329#issuecomment-394281615 I think that it is ready as soon the PR get merged: https://github.com/cilium/cilium/pull/4355 so I don't think that it's a issue right now.
That PR should fix that one. IMHO.

Got a new one in Update, but it is a DNS issue:
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2726/testReport/junit/k8s-1/7/K8sValidatedUpdates_Updating_Cilium_stable_to_master/

Removing myself from assignment because I have been asked to work on other urgent issues.

It makes sense to see if we hit this again after merging #4398.

I've just trigger a lot of new builds for master to see if we hit the issue again(from 2755 onwards).

Hi!
I think that the PR #4398 added a regression in Cilium. With this change, we
restored the endpoints in  other order, but not sure if it's the correct one:
First scenario: Not all endpoints are in Cilium endpoint list
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2758/testReport/junit/k8s-1/7/K8sValidatedChaosTest_Endpoint_can_still_connect_while_Cilium_is_not_running/
If you see the list of endpoints in this build the DNS is not in there, but test
pods are in place:
cmd: kubectl get pods -o wide --all-namespaces
NAMESPACE     NAME                           READY     STATUS    RESTARTS   AGE       IP              NODE
default       testclient-c3g5m               1/1       Running   0          58s       <IP_ADDRESS>     k8s1
default       testclient-qchbd               1/1       Running   0          58s       <IP_ADDRESS>     k8s2
default       testds-3qh7s                   1/1       Running   0          58s       <IP_ADDRESS>     k8s2
default       testds-m30c8                   1/1       Running   0          58s       <IP_ADDRESS>      k8s1
kube-system   cilium-q0bgq                   1/1       Running   0          1m        <IP_ADDRESS>   k8s1
kube-system   cilium-z34hw                   1/1       Running   0          1m        <IP_ADDRESS>   k8s2
kube-system   etcd-k8s1                      1/1       Running   0          7m        <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running   0          8m        <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running   0          8m        <IP_ADDRESS>   k8s1
kube-system   kube-dns-1992960195-dc6rh      3/3       Running   0          8m        <IP_ADDRESS>       k8s1
kube-system   kube-proxy-mpxcl               1/1       Running   0          8m        <IP_ADDRESS>   k8s1
kube-system   kube-proxy-w8lfk               1/1       Running   0          1m        <IP_ADDRESS>   k8s2
kube-system   kube-scheduler-k8s1            1/1       Running   0          7m        <IP_ADDRESS>   k8s1

cmd: kubectl exec -n kube-system cilium-q0bgq -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])               IPv6                 IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
32166      Disabled           Disabled          9833       k8s:io.kubernetes.pod.namespace=default   f00d::a0a:0:0:7da6   <IP_ADDRESS>   ready
                                                           k8s:zgroup=testDSClient
38184      Disabled           Disabled          4          reserved:health                           f00d::a0a:0:0:9528   <IP_ADDRESS>   ready
55347      Disabled           Disabled          25980      k8s:io.kubernetes.pod.namespace=default   f00d::a0a:0:0:d833   <IP_ADDRESS>    ready
                                                           k8s:zgroup=testDS

cmd: kubectl exec -n kube-system cilium-z34hw -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])               IPv6                   IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
25433      Disabled           Disabled          9833       k8s:io.kubernetes.pod.namespace=default   f00d::a0a:100:0:6359   <IP_ADDRESS>   ready
                                                           k8s:zgroup=testDSClient
25466      Disabled           Disabled          4          reserved:health                           f00d::a0a:100:0:637a   <IP_ADDRESS>    ready
54015      Disabled           Disabled          25980      k8s:io.kubernetes.pod.namespace=default   f00d::a0a:100:0:d2ff   <IP_ADDRESS>   ready
                                                           k8s:zgroup=testDs

What happens with DNS pods?
2018-06-08T07:16:39.065439831Z level=debug msg="IP address assigned by Cilium could not be derived from container event" containerID=b59a3f6469 subsys=workload-watcher
2018-06-08T07:16:39.065538658Z level=debug msg="Trying to associate container with existing endpoint" containerID=b59a3f6469 containerName=/k8s_sidecar_kube-dns-1992960195-dc6rh_kube-system_da90d86f-6aea-11e8-af26-0800274fedc6_0 endpointID=0 identityLabels="container:annotation.io.kubernetes.container.hash=2071da7c,container:annotation.io.kubernetes.container.ports=[{\"name\":\"metrics\",\"containerPort\":10054,\"protocol\":\"TCP\"}],container:annotation.io.kubernetes.container.restartCount=0,container:annotation.io.kubernetes.container.terminationMessagePath=/dev/termination-log,container:annotation.io.kubernetes.container.terminationMessagePolicy=File,container:annotation.io.kubernetes.pod.terminationGracePeriod=30,k8s:io.kubernetes.pod.namespace=kube-system,k8s:k8s-app=kube-dns" maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-08T07:16:39.065628952Z level=debug msg="Matching cilium endpoint for container create event does not exist yet" containerID=b59a3f6469 maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-08T07:16:39.065743078Z level=info msg="No request received to manage networking for container" containerID=b59a3f6469 maxRetry=20 subsys=workload-watcher willRetry=false

There is no more relevant logs for kube-dns pod, but after a 600 seconds
kube-dns pods are not present.
This is an example with Kube-dns, but can be any other pod
Second scenario: Ready pods are only the health ones, no pods are regenerated.
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2760/testReport/junit/k8s-1/7/K8sValidatedTunnelTest_Geneve_Check_Geneve_mode/
We use to wait until all pods are in ready state, and the Cilium endpoints are
ready. In this case, the Pod is Ready but the endpoint is not ready in Cilium,
and the endpoint is not present at all. Similar to one, but here no endpoints
are present. This issue is the same to scenario 1, but in this case no endpoints
are being restored correctly.
NAMESPACE     NAME                           READY     STATUS    RESTARTS   AGE       IP              NODE
default       testclient-jws2m               1/1       Running   0          46s       <IP_ADDRESS>       k8s2
default       testclient-vsp9n               1/1       Running   0          46s       <IP_ADDRESS>       k8s1
default       testds-qv03x                   1/1       Running   0          46s       <IP_ADDRESS>       k8s1
default       testds-t47sc                   1/1       Running   0          46s       <IP_ADDRESS>       k8s2
kube-system   cilium-9xjtz                   1/1       Running   0          45s       <IP_ADDRESS>   k8s2
kube-system   cilium-pm6r8                   1/1       Running   0          45s       <IP_ADDRESS>   k8s1
kube-system   etcd-k8s1                      1/1       Running   0          8m        <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running   0          9m        <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running   0          9m        <IP_ADDRESS>   k8s1
kube-system   kube-dns-1992960195-z04sn      3/3       Running   0          9m        <IP_ADDRESS>       k8s1
kube-system   kube-proxy-qg1t0               1/1       Running   0          9m        <IP_ADDRESS>   k8s1
kube-system   kube-proxy-vqp8r               1/1       Running   0          3m        <IP_ADDRESS>   k8s2
kube-system   kube-scheduler-k8s1            1/1       Running   0          9m        <IP_ADDRESS>   k8s1

cmd: kubectl exec -n kube-system cilium-9xjtz -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])   IPv6                   IPv4         STATUS
           ENFORCEMENT        ENFORCEMENT
23462      Disabled           Disabled          4          reserved:health               f00d::a0a:100:0:5ba6   <IP_ADDRESS>   ready

cmd: kubectl exec -n kube-system cilium-pm6r8 -- cilium endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])   IPv6                 IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
5730       Disabled           Disabled          4          reserved:health               f00d::a0a:0:0:1662   <IP_ADDRESS>   ready

In this case, the logs for testds-qv03x are:
Describe
Name:		testds-qv03x
Namespace:	default
Node:		k8s1/<IP_ADDRESS>
Start Time:	Fri, 08 Jun 2018 07:17:58 +0000
Labels:		controller-revision-hash=1795033029
		pod-template-generation=1
		zgroup=testDS
Annotations:	kubernetes.io/created-by={"kind":"SerializedReference","apiVersion":"v1","reference":{"kind":"DaemonSet","namespace":"default","name":"testds","uid":"123614f9-6aec-11e8-800c-0800274fedc6","apiVersion"...
Status:		Running
IP:		<IP_ADDRESS>
Created By:	DaemonSet/testds
Controlled By:	DaemonSet/testds
Containers:
  web:
    Container ID:	docker://f2500e3bd4c333d1aacbd48eb6bb153347ee54f5e316bc0a663cdd4a793f1649
    Image:		docker.io/cilium/demo-httpd
    Image ID:		docker-pullable://cilium/demo-httpd@sha256:647bc288a4ed0ac1c4361c76cc97171176edada2bf5f10946b7a84d2a7f33fe0
    Port:		80/TCP
    State:		Running
      Started:		Fri, 08 Jun 2018 07:18:00 +0000
    Ready:		True
    Restart Count:	0
    Environment:	<none>
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-bqv6n (ro)
Conditions:
  Type		Status
  Initialized 	True
  Ready 	True
  PodScheduled 	True
Volumes:
  default-token-bqv6n:
    Type:	Secret (a volume populated by a Secret)
    SecretName:	default-token-bqv6n
    Optional:	false
QoS Class:	BestEffort
Node-Selectors:	<none>
Tolerations:	node-role.kubernetes.io/master:NoSchedule
		node.alpha.kubernetes.io/notReady:NoExecute
		node.alpha.kubernetes.io/unreachable:NoExecute
		node.cloudprovider.kubernetes.io/uninitialized=true:NoSchedule
Events:
  FirstSeen	LastSeen	Count	From		SubObjectPath		Type		Reason			Message
  ---------	--------	-----	----		-------------		--------	------			-------
  1m		1m		1	kubelet, k8s1				Normal		SuccessfulMountVolume	MountVolume.SetUp succeeded for volume "default-token-bqv6n"
  59s		59s		1	kubelet, k8s1	spec.containers{web}	Normal		Pulling			pulling image "docker.io/cilium/demo-httpd"
  58s		58s		1	kubelet, k8s1	spec.containers{web}	Normal		Pulled			Successfully pulled image "docker.io/cilium/demo-httpd"
  58s		58s		1	kubelet, k8s1	spec.containers{web}	Normal		Created			Created container
  58s		58s		1	kubelet, k8s1	spec.containers{web}	Normal		Started			Started container

Logs:
2018-06-08T07:18:11.527640771Z level=info msg="Serving cilium health at unix:///var/run/cilium/health.sock"
2018-06-08T07:18:11.683161851Z level=debug msg="IP address assigned by Cilium could not be derived from container event" containerID=f2500e3bd4 subsys=workload-watcher
2018-06-08T07:18:11.683273092Z level=debug msg="Trying to associate container with existing endpoint" containerID=f2500e3bd4 containerName=/k8s_web_testds-qv03x_default_1238febd-6aec-11e8-800c-0800274fedc6_0 endpointID=0 identityLabels="container:annotation.io.kubernetes.container.hash=6e1193e8,container:annotation.io.kubernetes.container.ports=[{\"containerPort\":80,\"protocol\":\"TCP\"}],container:annotation.io.kubernetes.container.restartCount=0,container:annotation.io.kubernetes.container.terminationMessagePath=/dev/termination-log,container:annotation.io.kubernetes.container.terminationMessagePolicy=File,container:annotation.io.kubernetes.pod.terminationGracePeriod=30,container:id.service1,k8s:io.kubernetes.pod.namespace=default,k8s:zgroup=testDS" maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-08T07:18:11.683285143Z level=debug msg="Matching cilium endpoint for container create event does not exist yet" containerID=f2500e3bd4 maxRetry=20 retry=1 subsys=workload-watcher willRetry=false
2018-06-08T07:18:11.683330048Z level=info msg="No request received to manage networking for container" containerID=f2500e3bd4 maxRetry=20 subsys=workload-watcher willRetry=false

No more logs, that the situation is like the scenario 1. The only difference is
that Cilium retrieves the exec event:
2018-06-08T07:18:36.93047792Z level=debug msg="Queueing container event" containerID=f2500e3bd4 event="exec_create: ping -W 2 -c 5 <IP_ADDRESS>" subsys=workload-watcher
2018-06-08T07:18:36.931564871Z level=debug msg="Queueing container event" containerID=f2500e3bd4 event="exec_start: ping -W 2 -c 5 <IP_ADDRESS>" subsys=workload-watcher

Conclusion
The main problem is on Restore endpoints, in the first scenario the Kube-dns
issues was in place when Cilium restart, and the new pods are being created
correctly.
On the second scenario, all the pods had been restored by the new Cilium pod, so
no one is restored at all.
Builds that failed because of this fail:

https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2754/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2755/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2756/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2757/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2758/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2759/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2760/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2761/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2762/
https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2763/

@eloycoto The problem may be that we are not waiting long enough to correlate CNI request and runtime requests.

I don't think so :\
One of the problems is that docker.handleCreateWorkload is called with
retry=false, by watcherState.syncWithRuntime()[0], so I made a test and set the
retry to True, but it fails too.
If we set the retry to true, it'll do 10 loops, and there is a sleep in
there[1], so I don't think that it's a wait thing (I also try to sleep for more time).
I think that the problem is  on daemon/state.go
[regenerateRestoredEndpoints, restoreOldEndpoints] I think that is where
the problem borns, but I'm not sure about this one.
[0] https://github.com/cilium/cilium/blob/master/pkg/workloads/watcher_state.go#L133
[1] https://github.com/cilium/cilium/blob/master/pkg/workloads/docker.go#L404

I agree that #4398 may have caused this issue.
The following log pasted above appears to be the smoking gun:
Matching cilium endpoint for container create event does not exist yet

In daemon/daemon.go:NewDaemon():
Occurs right after daemon object is created:
workloads.Init(&d)

Previously, the insertion into endpointmanager occurred in this function:
restoredEndpoints, err := d.restoreOldEndpoints(option.Config.StateDir, true)

But now it occurs in this function:
d.regenerateRestoredEndpoints(restoredEndpoints)

The aforementioned log message
Matching cilium endpoint for container create event does not exist yet

only appears when a lookup for the endpoint corresponding to a workload-related event fails (i.e., the endpoint is not in endpointmanager). I'm betting that there is a significant enough delay in the initialization of the workload subsystem in Cilium, and the addition of endpoints into endpointmanager in d.regenerateRestoredEndpoints that some pods which should be managed by Cilium, are ignored, which appears to be the case due to the following log message:
No request received to manage networking for container

There are several ways to potentially fix the following:

Initialize the workload subsystem later while bootstrapping the daemon. I'm unsure of how the ordering of the boostrapping of this subsystem is related to other parts of bootstrapping the daemon.
Revert the change in #4398 , and add a new field (boolean flag which can be set only once with a sync.Once into endpoint which marks the endpoints as "readyToRegenerate". This will mean that endpoints are inserted into the endpointmanager earlier to avoid being dropped / ignored by Cilium, but that they will not be regenerated and cause the issues which #4398 was trying to fix. I'm unsure how this affects the initial datapath programs for the endpoints, though.

Thoughts?

Around the solutions:

I don't think that fix the problem at all. If the endpointmanager is empty,
the test will see that all endpoints are in ready state, because all other
endpoints maybe are not part of endpointmanager, so test will be flaky.

On the restoreOldEndpoints the endpoint is in a "Other/restoring" state.
I think that it's the right status, and no actions should be taken until the
endpoint is restored. So maybe the best solution is to wait to apply the policy
until the endpoint is restored?

Regards

@joestringer and I outlined exactly when certain (relevant) subsystems are initialized in Cilium:

start cilium

initEnv
runDaemon

New Daemon

workloads.Setup
workloads.Init
restoreOldEndpoints
initialize IPAM
initialize identity kvstore watcher
initialize proxy
regenerate restored endpoints

we asynchronously add endpoints into the endpoint manager in goroutines for each endpoint. This means that the function could return and bootstrapping of the daemon could continue before all endpoints are inserted into endpointmanager

workloads.EnableEventListener

This is where we actually listen for workload related events. Thus, since in regenerateRestoredEndpoints, we trigger goroutines to add into endpointmanger / regenerate each endpoint, it is possible that we may execute the code in workloads.EnableEventListener before executing the goroutines scheduled in regenerateRestoredEndpoints.

serve cilium API

Thus, @joestringer and I concluded that restored endpoints should be inserted into endpointmanager synchronously instead of in goroutines inside regenerateRestoredEndpoints.

A new failure:
Link:https://jenkins.cilium.io/job/Ginkgo-CI-Tests-Pipeline/2848/testReport/junit/k8s-1/10/K8sValidatedUpdates_Updating_Cilium_stable_to_master/
Attach:
f0c5341e_K8sValidatedUpdates_Updating_Cilium_stable_to_master(4).zip
Kubedns-Output:
I0611 10:06:10.032217       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
E0611 10:06:10.309043       1 reflector.go:201] k8s.io/dns/pkg/dns/dns.go:189: Failed to list *v1.Endpoints: Get https://<IP_ADDRESS>:443/api/v1/endpoints?resourceVersion=0: dial tcp <IP_ADDRESS>:443: getsockopt: no route to host
E0611 10:06:10.309199       1 reflector.go:201] k8s.io/dns/pkg/dns/dns.go:192: Failed to list *v1.Service: Get https://<IP_ADDRESS>:443/api/v1/services?resourceVersion=0: dial tcp <IP_ADDRESS>:443: getsockopt: no route to host
I0611 10:06:10.520891       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:11.016878       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:11.309268       1 reflector.go:236] Listing and watching *v1.Endpoints from k8s.io/dns/pkg/dns/dns.go:189
I0611 10:06:11.310819       1 reflector.go:236] Listing and watching *v1.Service from k8s.io/dns/pkg/dns/dns.go:192
I0611 10:06:11.516901       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:12.017002       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:12.516931       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:13.016964       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
E0611 10:06:13.383298       1 reflector.go:201] k8s.io/dns/pkg/dns/dns.go:192: Failed to list *v1.Service: Get https://<IP_ADDRESS>:443/api/v1/services?resourceVersion=0: dial tcp <IP_ADDRESS>:443: getsockopt: no route to host
E0611 10:06:13.383347       1 reflector.go:201] k8s.io/dns/pkg/dns/dns.go:189: Failed to list *v1.Endpoints: Get https://<IP_ADDRESS>:443/api/v1/endpoints?resourceVersion=0: dial tcp <IP_ADDRESS>:443: getsockopt: no route to host
I0611 10:06:13.519719       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...
I0611 10:06:14.017076       1 dns.go:219] Waiting for [endpoints services] to be initialized from apiserver...

Sidecar One:
I0611 10:04:39.144590       1 main.go:51] Version v<IP_ADDRESS>
I0611 10:04:39.144647       1 server.go:45] Starting server (options {DnsMasqPort:53 DnsMasqAddr:<IP_ADDRESS> DnsMasqPollIntervalMs:5000 Probes:[{Label:kubedns Server:<IP_ADDRESS>:10053 Name:kubernetes.default.svc.cluster.local. Interval:5s Type:33} {Label:dnsmasq Server:<IP_ADDRESS>:53 Name:kubernetes.default.svc.cluster.local. Interval:5s Type:33}] PrometheusAddr:<IP_ADDRESS> PrometheusPort:10054 PrometheusPath:/metrics PrometheusNamespace:kubedns})
I0611 10:04:39.144671       1 dnsprobe.go:75] Starting dnsProbe {Label:kubedns Server:<IP_ADDRESS>:10053 Name:kubernetes.default.svc.cluster.local. Interval:5s Type:33}
I0611 10:04:39.144699       1 dnsprobe.go:75] Starting dnsProbe {Label:dnsmasq Server:<IP_ADDRESS>:53 Name:kubernetes.default.svc.cluster.local. Interval:5s Type:33}
panic: counter cannot decrease in value

goroutine 1 [running]:
k8s.io/dns/vendor/github.com/prometheus/client_golang/prometheus.(*counter).Add(0xc4203ab480, 0xc054000000000000)
	/go/src/k8s.io/dns/vendor/github.com/prometheus/client_golang/prometheus/counter.go:71 +0xc5
k8s.io/dns/pkg/sidecar.exportMetrics(0xc420068398)
	/go/src/k8s.io/dns/pkg/sidecar/server.go:86 +0x1b0
k8s.io/dns/pkg/sidecar.(*server).runMetrics(0xc42033c3f0, 0xc420164460)
	/go/src/k8s.io/dns/pkg/sidecar/server.go:68 +0x1d8
k8s.io/dns/pkg/sidecar.(*server).Run(0xc42033c3f0, 0xc420164460)
	/go/src/k8s.io/dns/pkg/sidecar/server.go:53 +0x2e5
main.main()
	/go/src/k8s.io/dns/cmd/sidecar/main.go:56 +0x1fb

Kubedns is on K8s2:
cmd: "kubectl get pods -o wide --all-namespaces" exitCode: 0 stdout:
NAMESPACE     NAME                           READY     STATUS             RESTARTS   AGE       IP              NODE
default       app1-c4954c58c-24pz5           1/1       Running            0          7m        <IP_ADDRESS>     k8s1
default       app1-c4954c58c-fwsvd           1/1       Running            0          7m        <IP_ADDRESS>      k8s1
default       app2-5b59d5764b-h2ch8          1/1       Running            0          7m        <IP_ADDRESS>      k8s1
default       app3-6d745c45f6-bvl7x          1/1       Running            0          7m        <IP_ADDRESS>      k8s1
kube-system   cilium-clj28                   1/1       Running            0          8m        <IP_ADDRESS>   k8s1
kube-system   cilium-k2vgj                   1/1       Running            0          8m        <IP_ADDRESS>   k8s2
kube-system   etcd-k8s1                      1/1       Running            0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-apiserver-k8s1            1/1       Running            0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-controller-manager-k8s1   1/1       Running            0          47m       <IP_ADDRESS>   k8s1
kube-system   kube-dns-59d8c5f9b5-jlw59      2/3       CrashLoopBackOff   12         48m       <IP_ADDRESS>     k8s2
kube-system   kube-proxy-9vrw4               1/1       Running            0          41m       <IP_ADDRESS>   k8s2
kube-system   kube-proxy-qx4c9               1/1       Running            0          48m       <IP_ADDRESS>   k8s1
kube-system   kube-scheduler-k8s1            1/1       Running            0          47m       <IP_ADDRESS>   k8s1

K8s can't reach local endpoints:
KVStore:                Ok   etcd: 1/1 connected: http://k8s1:9732 - 3.1.0 (Leader)
ContainerRuntime:       Ok
Kubernetes:             Ok   OK
Kubernetes APIs:        ["core/v1::Service", "core/v1::Endpoint", "core/v1::Node", "CustomResourceDefinition", "cilium/v2::CiliumNetworkPolicy", "networking.k8s.io/v1::NetworkPolicy"]
Cilium:                 Ok   OK
NodeMonitor:            Listening for events on 2 CPUs with 64x4096 of shared memory
Cilium health daemon:   Ok
IPv4 address pool:      3/255 allocated
IPv6 address pool:      3/4294967295 allocated
Controller Status:      14/14 healthy
  Name                                        Last success   Last error   Count   Message
  kvstore-lease-keepalive                     3m2s ago       never        0       no error
  resolve-identity-29898                      2m58s ago      never        0       no error
  sync-IPv4-identity-mapping (29898)          2m58s ago      never        0       no error
  sync-identity-to-k8s-pod (16253)            59s ago        never        0       no error
  sync-IPv4-identity-mapping (16253)          2m59s ago      never        0       no error
  sync-to-k8s-ciliumendpoint (29898)          7s ago         never        0       no error
  sync-to-k8s-ciliumendpoint-gc (k8s2)        56s ago        never        0       no error
  sync-to-k8s-ciliumendpoint (16253)          8s ago         never        0       no error
  ipcache-bpf-garbage-collection              2m59s ago      never        0       no error
  sync-IPv6-identity-mapping (16253)          2m59s ago      never        0       no error
  sync-identity-to-k8s-pod (29898)            58s ago        never        0       no error
  sync-cnp-policy-status (v2 default/rule1)   7m29s ago      never        0       no error
  kvstore-etcd-session-renew                  never          never        0       no error
  sync-IPv6-identity-mapping (29898)          2m58s ago      never        0       no error
Proxy Status:   OK, ip <IP_ADDRESS>, port-range 10000-20000
Cluster health:      0/2 reachable   (2018-06-11T10:05:10Z)
  Name               IP              Reachable   Endpoints reachable
  k8s2 (localhost)   <IP_ADDRESS>   true        false
  k8s1               <IP_ADDRESS>   true        false

Endpoint list
ENDPOINT   POLICY (ingress)   POLICY (egress)   IDENTITY   LABELS (source:key[=value])                   IPv6                   IPv4          STATUS
           ENFORCEMENT        ENFORCEMENT
16253      Disabled           Disabled          62374      k8s:io.kubernetes.pod.namespace=kube-system   f00d::a0a:100:0:3f7d   <IP_ADDRESS>   ready
                                                           k8s:k8s-app=kube-dns
29898      Disabled           Disabled          62375      reserved:health                               f00d::a0a:100:0:74ca   <IP_ADDRESS>   ready

BPF Endpoint List 16253
IP ADDRESS             LOCAL ENDPOINT INFO
fd04::12               (localhost)
<IP_ADDRESS>            id=29898 ifindex=121 mac=00:00:00:00:62:72 nodemac=13:A3:00:00:7A:CF seclabel=0xf3a7 portMaps=(empty)
<IP_ADDRESS>          (localhost)
f00d::a0a:100:0:74ca   id=29898 ifindex=121 mac=00:00:00:00:62:72 nodemac=13:A3:00:00:7A:CF seclabel=0xf3a7 portMaps=(empty)
<IP_ADDRESS>            id=16253 ifindex=14  mac=00:00:00:00:86:A1 nodemac=FE:C5:00:00:D2:0B seclabel=0xf3a6 portMaps=(empty)
f00d::a0a:100:0:8ad6   (localhost)
f00d::a0a:100:0:3f7d   id=16253 ifindex=14  mac=00:00:00:00:86:A1 nodemac=FE:C5:00:00:D2:0B seclabel=0xf3a6 portMaps=(empty)

BPF Policy Get 16253
DIRECTION   LABELS (source:key[=value])   PORT/PROTO   BYTES   PACKETS
Ingress     reserved:host                 ANY          0       0

The endpoint status:
[
  {
    "id": 16253,
    "spec": {
      "label-configuration": {
        "user": []
      },
      "options": {
        "Conntrack": "Enabled",
        "ConntrackAccounting": "Enabled",
        "ConntrackLocal": "Disabled",
        "Debug": "Enabled",
        "DebugLB": "Disabled",
        "DropNotification": "Enabled",
        "EgressPolicy": "Disabled",
        "IngressPolicy": "Disabled",
        "NAT46": "Disabled",
        "TraceNotification": "Enabled"
      }
    },
    "status": {
      "controllers": [
        {
          "configuration": {
            "error-retry": true,
            "interval": "5m0s"
          },
          "name": "sync-IPv4-identity-mapping (16253)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-06-11T10:03:05.478Z",
            "success-count": 2
          },
          "uuid": "efa281ad-6d5d-11e8-a500-080027aa233b"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "5m0s"
          },
          "name": "sync-IPv6-identity-mapping (16253)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-06-11T10:03:05.474Z",
            "success-count": 2
          },
          "uuid": "efa2830b-6d5d-11e8-a500-080027aa233b"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "1m0s"
          },
          "name": "sync-identity-to-k8s-pod (16253)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-06-11T10:06:05.579Z",
            "success-count": 9
          },
          "uuid": "efa27fea-6d5d-11e8-a500-080027aa233b"
        },
        {
          "configuration": {
            "error-retry": true,
            "interval": "10s"
          },
          "name": "sync-to-k8s-ciliumendpoint (16253)",
          "status": {
            "last-failure-timestamp": "0001-01-01T00:00:00.000Z",
            "last-success-timestamp": "2018-06-11T10:06:06.532Z",
            "success-count": 49
          },
          "uuid": "efa07567-6d5d-11e8-a500-080027aa233b"
        }
      ],
      "external-identifiers": {
        "container-id": "bf1980a8b47019cf3adce19b5fbed7e4d53b08be4fbcd1e7f05a694efb7120e2",
        "container-name": "k8s_POD_kube-dns-59d8c5f9b5-jlw59_kube-system_4ce725fd-6d58-11e8-8a83-080027aa233b_0",
        "pod-name": "kube-system:kube-dns-59d8c5f9b5-jlw59"
      },
      "health": {
        "bpf": "OK",
        "connected": true,
        "overallHealth": "OK",
        "policy": "OK"
      },
      "identity": {
        "id": 62374,
        "labels": [
          "k8s:io.kubernetes.pod.namespace=kube-system",
          "k8s:k8s-app=kube-dns"
        ],
        "labelsSHA256": "1b2bafe403e0d433f8307836b07ade2cf802511501f880917e128b7f663ac313"
      },
      "labels": {
        "derived": [
          "container:annotation.kubernetes.io/config.seen=2018-06-11T09:25:00.599673688Z",
          "container:annotation.kubernetes.io/config.source=api",
          "container:annotation.scheduler.alpha.kubernetes.io/critical-pod",
          "container:io.kubernetes.container.name=POD",
          "container:io.kubernetes.docker.type=podsandbox",
          "container:io.kubernetes.pod.name=kube-dns-59d8c5f9b5-jlw59",
          "container:io.kubernetes.pod.uid=4ce725fd-6d58-11e8-8a83-080027aa233b",
          "k8s:pod-template-hash=1584719561"
        ],
        "disabled": [],
        "realized": {
          "user": []
        },
        "security-relevant": [
          "k8s:io.kubernetes.pod.namespace=kube-system",
          "k8s:k8s-app=kube-dns"
        ]
      },
      "log": [
        {
          "code": "OK",
          "message": "Successfully regenerated endpoint program due to endpoint policy updated & changes were needed",
          "state": "ready",
          "timestamp": "2018-06-11T10:03:10Z"
        }
      ],
      "networking": {
        "addressing": [
          {
            "ipv4": "<IP_ADDRESS>",
            "ipv6": "f00d::a0a:100:0:3f7d"
          }
        ],
        "host-mac": "d2:0b:50:07:e8:e9",
        "interface-index": 14,
        "interface-name": "lxcbf198",
        "mac": "86:a1:aa:94:fe:c5"
      },
      "policy": {
        "proxy-statistics": [],
        "realized": {
          "allowed-egress-identities": [],
          "allowed-ingress-identities": [
            1
          ],
          "build": 10,
          "cidr-policy": {
            "egress": [],
            "ingress": []
          },
          "id": 62374,
          "l4": {
            "egress": [],
            "ingress": []
          },
          "policy-enabled": "none",
          "policy-revision": 10
        },
        "spec": {
          "allowed-egress-identities": [],
          "allowed-ingress-identities": [
            1
          ],
          "build": 10,
          "cidr-policy": {
            "egress": [],
            "ingress": []
          },
          "id": 62374,
          "l4": {
            "egress": [],
            "ingress": []
          },
          "policy-enabled": "none",
          "policy-revision": 10
        }
      },
      "realized": {
        "label-configuration": {
          "user": []
        },
        "options": {
          "Conntrack": "Enabled",
          "ConntrackAccounting": "Enabled",
          "ConntrackLocal": "Disabled",
          "Debug": "Enabled",
          "DebugLB": "Disabled",
          "DropNotification": "Enabled",
          "EgressPolicy": "Disabled",
          "IngressPolicy": "Disabled",
          "NAT46": "Disabled",
          "TraceNotification": "Enabled"
        }
      },
      "state": "ready"
    }
  }
]

This is a bit weird, endpoint does not have any policy, but there is the init policy in place
The logs that say that egress is disabled:
2018-06-11T09:58:05.476172062Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDSClient] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=13775 policyRevision=0
2018-06-11T09:58:05.476175939Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDSClient] []}" endpointID=16253 policyID=13775 policyRevision=0
2018-06-11T09:58:05.476179328Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDSClient]" policyID=13775
2018-06-11T09:58:05.476182236Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [k8s:k8s-app=kube-dns k8s:io.kubernetes.pod.namespace=kube-system] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=62374 policyRevision=0
2018-06-11T09:58:05.476185792Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [k8s:k8s-app=kube-dns k8s:io.kubernetes.pod.namespace=kube-system] []}" endpointID=16253 policyID=62374 policyRevision=0
2018-06-11T09:58:05.476189232Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[k8s:k8s-app=kube-dns k8s:io.kubernetes.pod.namespace=kube-system]" policyID=62374
2018-06-11T09:58:05.476192201Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDS] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=8915 policyRevision=0
2018-06-11T09:58:05.476195735Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDS] []}" endpointID=16253 policyID=8915 policyRevision=0
2018-06-11T09:58:05.476201831Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[k8s:io.kubernetes.pod.namespace=default k8s:zgroup=testDS]" policyID=8915
2018-06-11T09:58:05.476204814Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [reserved:host] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=host policyRevision=0
2018-06-11T09:58:05.476208071Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [reserved:host] []}" endpointID=16253 policyID=host policyRevision=0
2018-06-11T09:58:05.476211311Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[reserved:host]" policyID=host
2018-06-11T09:58:05.476214025Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [reserved:world] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=world policyRevision=0
2018-06-11T09:58:05.476220308Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [reserved:world] []}" endpointID=16253 policyID=world policyRevision=0
2018-06-11T09:58:05.476223785Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[reserved:world]" policyID=world
2018-06-11T09:58:05.476226491Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [reserved:health] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=health policyRevision=0
2018-06-11T09:58:05.47622966Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [reserved:health] []}" endpointID=16253 policyID=health policyRevision=0
2018-06-11T09:58:05.476233009Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[reserved:health]" policyID=health
2018-06-11T09:58:05.476235913Z level=debug msg="Evaluating ingress context for source PolicyID" containerID=bf1980a8b4 endpointID=16253 ingress_context="{0 0 <nil> [reserved:cluster] [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] []}" policyID=cluster policyRevision=0
2018-06-11T09:58:05.476239278Z level=debug msg="Evaluating egress context for source PolicyID" containerID=bf1980a8b4 egress_context="{0 0 <nil> [k8s:io.kubernetes.pod.namespace=kube-system k8s:k8s-app=kube-dns] [reserved:cluster] []}" endpointID=16253 policyID=cluster policyRevision=0
2018-06-11T09:58:05.476242608Z level=debug msg="egress verdict: denied" endpointID=16253 labels="[reserved:cluster]" policyID=cluster

@eloycoto the failure outlined in comment https://github.com/cilium/cilium/issues/4329#issuecomment-396208508 looks like it's #3878 .
To summarize what was discussed in the Cilium weekly developer meeting: I'm concerned that this ticket is becoming a catch-all for any failure of the upgrade test, and as such we are losing sight into what failures are actually being hit. I.e., the test could be failing for multiple reasons, but we are grouping them all together under one umbrella, which makes it very hard to track what this ticket is actually doing. If there is a new issue with a test, I am of the opinion that we should file new issues accordingly. Otherwise, legitimate failures get buried / lost track of.
As such, AFAICT the issues that this ticket covers / has covered are:

(1) https://github.com/cilium/cilium/issues/4329#issue-328566225 : the upgrade test passed, but it shouldn't have - from what I gleamed from the Cilium weekly meeting discussion, this still needs to be looked into (i.e., why did the upgrade test pass when it should have failed)?
(2) https://github.com/cilium/cilium/issues/4329#issuecomment-395696104 : potential fix is #4421 , but this is hard to say because CI was severely unstable and suffered regressions, which have been fixed. However, #4421 definitely is the right fix a potential race condition in Cilium.
(3) https://github.com/cilium/cilium/issues/4329#issuecomment-396208508 : same issue as #3878 (?) and possibly related-to #4455  (?)
(4) https://github.com/cilium/cilium/issues/4329#issuecomment-395240453 : we aren't sure why the health endpoint was unable to come up, but we did discover https://github.com/cilium/cilium/pull/4398, which may have been the cause. @tgraf ( https://github.com/cilium/cilium/issues/4329#issuecomment-395502512 ) said that makes the most sense to look deeper into this if such a failure (Cilium pod not going into a ready state) occurs again with #4398 merged.

To summarize: (1) is still not fully RCA'd, (2) is still up in the air because CI wasn't stable at time of filing, (3) is being tracked separately, and (4) has not been observed since #4398 was merged.
As such, in my opinion, this ticket should only track (1), which means that this is more a post-mortem than anything else. Is this still a release-blocker ? @tgraf said he would manually test upgrade from 1.0 --> 1.1 due to lack of failure of upgrade in (1).

Will test upgrade manually for 1.1 releases. Test needs to be verified for 1.2 release.

The original purpose of this ticket has been resolved