Fix flakiness with TestSidecarHTTPHealthCheck by markmandel · Pull Request #313 · agones-dev/agones

markmandel · 2018-07-31T23:18:40Z

I believe that this is starting at the same time as another
http server on the same port, and having a collision.

Removing the parrallel marker should fix this.

I believe that this is starting at the same time as another http server on the same port, and having a collision. Removing the parrallel marker should fix this.

agones-bot · 2018-07-31T23:26:18Z

Build Succeeded 👏

Build Id: 611fe503-354b-4e12-99ab-6bc930b3b9de

The following development artifacts have been built, and will exist for the next 30 days:

image: gcr.io/agones-images/agones-controller:0.4.0-bb6c95e
image: gcr.io/agones-images/agones-sdk:0.4.0-bb6c95e
Linux C++ SDK (build: dev): agonessdk-0.4.0-bb6c95e-dev-linux-arch_64.tar.gz
Linux C++ SDK (build: runtime): agonessdk-0.4.0-bb6c95e-runtime-linux-arch_64.tar.gz
Linux C++ SDK (source): agonessdk-0.4.0-bb6c95e-src.zip
SDK Server: agonessdk-server-0.4.0-bb6c95e.zip

agones-bot · 2018-08-01T15:49:33Z

Build Failed 😱

Build Id: 23c6dfe3-5390-4a6f-98b0-6fadca94ad11

Build Logs

starting build "23c6dfe3-5390-4a6f-98b0-6fadca94ad11"

FETCHSOURCE
Initialized empty Git repository in /workspace/.git/
From https://source.developers.google.com/p/agones-images/r/agones
 * branch            b85aaf338784271c73b8a4454b0265e2ed27b24b -> FETCH_HEAD
HEAD is now at b85aaf3 Merge branch 'master' into flaky/test-sidecar-http
BUILD
Starting Step #0
Step #0: Already have image (with digest): ubuntu
Finished Step #0
Starting Step #1
Step #1: Already have image (with digest): gcr.io/cloud-builders/docker
Step #1: Sending build context to Docker daemon  110.4MB

Step #1: Step 1/3 : FROM gcr.io/cloud-builders/docker
Step #1:  ---> 6251f212f23b
Step #1: Step 2/3 : RUN apt-get install make
Step #1:  ---> Running in 45e5aba000e9
Step #1: Reading package lists...
Step #1: Building dependency tree...
Step #1: Reading state information...
Step #1: make is already the newest version (4.1-6).
Step #1: 0 upgraded, 0 newly installed, 0 to remove and 16 not upgraded.
Step #1: Removing intermediate container 45e5aba000e9
Step #1:  ---> ebb240d873e9
Step #1: Step 3/3 : ENTRYPOINT ["/usr/bin/make"]
Step #1:  ---> Running in b6a907acd785
Step #1: Removing intermediate container b6a907acd785
Step #1:  ---> ead4faf95536
Step #1: Successfully built ead4faf95536
Step #1: Successfully tagged make-docker:latest
Finished Step #1
Starting Step #2
Step #2: Already have image: make-docker
Step #2: docker pull gcr.io/agones-images/agones-build:7baad3fcaa && docker tag gcr.io/agones-images/agones-build:7baad3fcaa agones-build:7baad3fcaa
Step #2: 7baad3fcaa: Pulling from agones-images/agones-build
Step #2: cc1a78bfd46b: Pulling fs layer
Step #2: 65ec5fb8fee4: Pulling fs layer
Step #2: f792a8d67267: Pulling fs layer
Step #2: c61ddf10ea29: Pulling fs layer
Step #2: f11e4b9dca6d: Pulling fs layer
Step #2: f5de62cd774a: Pulling fs layer
Step #2: 84fd27122697: Pulling fs layer
Step #2: 0c424a61cc39: Pulling fs layer
Step #2: b5bfc6f2e8cf: Pulling fs layer
Step #2: 3b2702a6ad68: Pulling fs layer
Step #2: 5ab6afc7d65b: Pulling fs layer
Step #2: 24f531f817dd: Pulling fs layer
Step #2: 438f29967585: Pulling fs layer
Step #2: 84919d2a889b: Pulling fs layer
Step #2: 8e059271ff11: Pulling fs layer
Step #2: 6f621b6c2140: Pulling fs layer
Step #2: 2cc115bfdcc4: Pulling fs layer
Step #2: c83e29de64eb: Pulling fs layer
Step #2: 67b0b15947b1: Pulling fs layer
Step #2: c61ddf10ea29: Waiting
Step #2: 88d3d110e8a5: Pulling fs layer
Step #2: f11e4b9dca6d: Waiting
Step #2: 438f29967585: Waiting
Step #2: f5de62cd774a: Waiting
Step #2: 3b2702a6ad68: Waiting
Step #2: 84fd27122697: Waiting
Step #2: 5ab6afc7d65b: Waiting
Step #2: 24f531f817dd: Waiting
Step #2: 0c424a61cc39: Waiting
Step #2: 84919d2a889b: Waiting
Step #2: b5bfc6f2e8cf: Waiting
Step #2: 8e059271ff11: Waiting
Step #2: 6f621b6c2140: Waiting
Step #2: 67b0b15947b1: Waiting
Step #2: 88d3d110e8a5: Waiting
Step #2: c83e29de64eb: Waiting
Step #2: cc1a78bfd46b: Verifying Checksum
Step #2: cc1a78bfd46b: Download complete
Step #2: c61ddf10ea29: Verifying Checksum
Step #2: c61ddf10ea29: Download complete
Step #2: 65ec5fb8fee4: Verifying Checksum
Step #2: 65ec5fb8fee4: Download complete
Step #2: f5de62cd774a: Verifying Checksum
Step #2: f5de62cd774a: Download complete
Step #2: f11e4b9dca6d: Verifying Checksum
Step #2: f11e4b9dca6d: Download complete
Step #2: 0c424a61cc39: Verifying Checksum
Step #2: 0c424a61cc39: Download complete
Step #2: b5bfc6f2e8cf: Verifying Checksum
Step #2: b5bfc6f2e8cf: Download complete
Step #2: cc1a78bfd46b: Pull complete
Step #2: 3b2702a6ad68: Verifying Checksum
Step #2: 3b2702a6ad68: Download complete
Step #2: 5ab6afc7d65b: Verifying Checksum
Step #2: 5ab6afc7d65b: Download complete
Step #2: 84fd27122697: Download complete
Step #2: 438f29967585: Verifying Checksum
Step #2: 438f29967585: Download complete
Step #2: 24f531f817dd: Verifying Checksum
Step #2: 24f531f817dd: Download complete
Step #2: 84919d2a889b: Verifying Checksum
Step #2: 84919d2a889b: Download complete
Step #2: 8e059271ff11: Verifying Checksum
Step #2: 8e059271ff11: Download complete
Step #2: 6f621b6c2140: Verifying Checksum
Step #2: 6f621b6c2140: Download complete
Step #2: 2cc115bfdcc4: Verifying Checksum
Step #2: 67b0b15947b1: Download complete
Step #2: c83e29de64eb: Verifying Checksum
Step #2: c83e29de64eb: Download complete
Step #2: 88d3d110e8a5: Verifying Checksum
Step #2: 88d3d110e8a5: Download complete
Step #2: 65ec5fb8fee4: Pull complete
Step #2: f792a8d67267: Verifying Checksum
Step #2: f792a8d67267: Download complete
Step #2: f792a8d67267: Pull complete
Step #2: c61ddf10ea29: Pull complete
Step #2: f11e4b9dca6d: Pull complete
Step #2: f5de62cd774a: Pull complete
Step #2: 84fd27122697: Pull complete
Step #2: 0c424a61cc39: Pull complete
Step #2: b5bfc6f2e8cf: Pull complete
Step #2: 3b2702a6ad68: Pull complete
Step #2: 5ab6afc7d65b: Pull complete
Step #2: 24f531f817dd: Pull complete
Step #2: 438f29967585: Pull complete
Step #2: 84919d2a889b: Pull complete
Step #2: 8e059271ff11: Pull complete
Step #2: 6f621b6c2140: Pull complete
Step #2: 2cc115bfdcc4: Pull complete
Step #2: c83e29de64eb: Pull complete
Step #2: 67b0b15947b1: Pull complete
Step #2: 88d3d110e8a5: Pull complete
Step #2: Digest: sha256:3b0633d147975b433dda6e16d40c801c793181fc0f7d9d3f704479605690080f
Step #2: Status: Downloaded newer image for gcr.io/agones-images/agones-build:7baad3fcaa
Finished Step #2
Starting Step #3 - "lint"
Step #3 - "lint": Already have image: make-docker
Step #3 - "lint": mkdir -p ~/.kube
Step #3 - "lint": mkdir -p /workspace/build//.config/gcloud
Step #3 - "lint": docker run --rm -v /workspace/build//.config/gcloud:/root/.config/gcloud -v ~/.kube:/root/.kube -v /workspace:/go/src/agones.dev/agones -w /go/src/agones.dev/agones  agones-build:7baad3fcaa bash -c \
Step #3 - "lint": 	"/root/gen-lint-exclude.sh && gometalinter --config .exclude.gometalinter.json --deadline=15m -t --skip vendor ./..."
Finished Step #3 - "lint"
Starting Step #5 - "build"
Starting Step #4 - "tests"
Step #4 - "tests": Already have image: make-docker
Step #5 - "build": Already have image: make-docker
Step #4 - "tests": mkdir -p ~/.kube
Step #5 - "build": mkdir -p ~/.kube
Step #5 - "build": mkdir -p /workspace/build//.config/gcloud
Step #4 - "tests": mkdir -p /workspace/build//.config/gcloud
Step #4 - "tests": docker run --rm -v /workspace/build//.config/gcloud:/root/.config/gcloud -v ~/.kube:/root/.kube -v /workspace:/go/src/agones.dev/agones agones-build:7baad3fcaa go test -race agones.dev/agones/...
Step #5 - "build": docker run --rm -e "CGO_ENABLED=0" -v /workspace/build//.config/gcloud:/root/.config/gcloud -v ~/.kube:/root/.kube -v /workspace:/go/src/agones.dev/agones agones-build:7baad3fcaa go build \
Step #5 - "build": 	-o /go/src/agones.dev/agones/cmd/controller/bin/controller -a -ldflags "-X agones.dev/agones/pkg.Version=0.4.0-b85aaf3" -installsuffix cgo agones.dev/agones/cmd/controller
Step #4 - "tests": warning: ignoring symlink /go/src/agones.dev/agones/vendor/github.com/prometheus/procfs/fixtures/self
Step #4 - "tests": ?   	agones.dev/agones	[no test files]
Step #5 - "build": docker build /workspace/cmd/controller/ --tag=gcr.io/agones-images/agones-controller:0.4.0-b85aaf3 
Step #5 - "build": Sending build context to Docker daemon  41.79MB

Step #4 - "tests": ?   	agones.dev/agones/cmd/controller	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/cmd/sdk-server	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/examples/simple-udp/client	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/examples/simple-udp/server	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/examples/xonotic	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/apis	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/apis/stable	[no test files]
Step #4 - "tests": ok  	agones.dev/agones/pkg/apis/stable/v1alpha1	1.060s
Step #4 - "tests": ?   	agones.dev/agones/pkg/client	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/clientset/versioned	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/clientset/versioned/fake	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/clientset/versioned/scheme	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/clientset/versioned/typed/stable/v1alpha1	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/clientset/versioned/typed/stable/v1alpha1/fake	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/informers/externalversions	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/informers/externalversions/internalinterfaces	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/informers/externalversions/stable	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/informers/externalversions/stable/v1alpha1	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/client/listers/stable/v1alpha1	[no test files]
Step #5 - "build": Step 1/6 : FROM alpine:3.7
Step #5 - "build": 3.7: Pulling from library/alpine
Step #5 - "build": 911c6d0c7995: Pulling fs layer
Step #5 - "build": 911c6d0c7995: Verifying Checksum
Step #5 - "build": 911c6d0c7995: Download complete
Step #5 - "build": 911c6d0c7995: Pull complete
Step #5 - "build": Digest: sha256:5ce5f501c457015c4b91f91a15ac69157d9b06f1a75cf9107bf2b62e0843983a
Step #5 - "build": Status: Downloaded newer image for alpine:3.7
Step #5 - "build":  ---> 791c3e2ebfcb
Step #5 - "build": Step 2/6 : RUN apk --update add ca-certificates &&     adduser -D agones
Step #5 - "build":  ---> Running in 652ef15a6ad1
Step #5 - "build": fetch http://dl-cdn.alpinelinux.org/alpine/v3.7/main/x86_64/APKINDEX.tar.gz
Step #5 - "build": fetch http://dl-cdn.alpinelinux.org/alpine/v3.7/community/x86_64/APKINDEX.tar.gz
Step #5 - "build": (1/1) Installing ca-certificates (20171114-r0)
Step #5 - "build": Executing busybox-1.27.2-r11.trigger
Step #5 - "build": Executing ca-certificates-20171114-r0.trigger
Step #5 - "build": OK: 5 MiB in 14 packages
Step #5 - "build": Removing intermediate container 652ef15a6ad1
Step #5 - "build":  ---> a82dd7787a11
Step #5 - "build": Step 3/6 : COPY ./bin/controller /home/agones/controller
Step #5 - "build":  ---> d43606237d65
Step #5 - "build": Step 4/6 : RUN chown -R agones /home/agones &&     chmod o+x /home/agones/controller
Step #5 - "build":  ---> Running in 044572bfc52b
Step #5 - "build": Removing intermediate container 044572bfc52b
Step #5 - "build":  ---> d6f8672bf36d
Step #5 - "build": Step 5/6 : USER agones
Step #5 - "build":  ---> Running in 67ed35a3c966
Step #5 - "build": Removing intermediate container 67ed35a3c966
Step #5 - "build":  ---> d64c82711587
Step #5 - "build": Step 6/6 : ENTRYPOINT ["/home/agones/controller"]
Step #5 - "build":  ---> Running in 2fc4a7c823bf
Step #5 - "build": Removing intermediate container 2fc4a7c823bf
Step #5 - "build":  ---> 792fa3881b69
Step #5 - "build": Successfully built 792fa3881b69
Step #5 - "build": Successfully tagged gcr.io/agones-images/agones-controller:0.4.0-b85aaf3
Step #5 - "build": docker run --rm -e "CGO_ENABLED=0" -v /workspace/build//.config/gcloud:/root/.config/gcloud -v ~/.kube:/root/.kube -v /workspace:/go/src/agones.dev/agones agones-build:7baad3fcaa go build \
Step #5 - "build": 	-o /go/src/agones.dev/agones/cmd/sdk-server/bin/sdk-server.linux.amd64 -a -ldflags "-X agones.dev/agones/pkg.Version=0.4.0-b85aaf3" -installsuffix cgo agones.dev/agones/cmd/sdk-server
Step #4 - "tests": ok  	agones.dev/agones/pkg/fleetallocation	11.860s
Step #4 - "tests": ok  	agones.dev/agones/pkg/fleets	2.522s
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Adding first fixture","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"crd":"","level":"info","msg":"custom resource definition established","source":"*gameservers.Controller","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","source":"*gameservers.Controller","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Running","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:14Z","workers":1}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:14Z","workers":1}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"default/test","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:14Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:14Z","workers":1}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"modify copyFixture","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"default/test","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"default/test","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Syncing Create State","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"creating Pod for GameServer","pod":{"metadata":{"generateName":"test-","namespace":"default","creationTimestamp":null,"labels":{"stable.agones.dev/gameserver":"test","stable.agones.dev/role":"gameserver"},"annotations":{"stable.agones.dev/container":"container"},"ownerReferences":[{"apiVersion":"stable.agones.dev/v1alpha1","kind":"GameServer","name":"test","uid":"","controller":true,"blockOwnerDeletion":true}]},"spec":{"containers":[{"name":"container","image":"container/image","ports":[{"hostPort":9999,"containerPort":7777,"protocol":"UDP"}],"resources":{},"livenessProbe":{"httpGet":{"path":"/gshealthz","port":8080},"initialDelaySeconds":5,"periodSeconds":5,"failureThreshold":3}},{"name":"agones-gameserver-sidecar","image":"sidecar:dev","env":[{"name":"GAMESERVER_NAME","value":"test"},{"name":"POD_NAMESPACE","valueFrom":{"fieldRef":{"fieldPath":"metadata.namespace"}}}],"resources":{},"livenessProbe":{"httpGet":{"path":"/healthz","port":8080},"initialDelaySeconds":3,"periodSeconds":3}}],"serviceAccountName":"agones-sdk"},"status":{}},"source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Syncing Create State","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Syncing Create State","source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"creating Pod for GameServer","pod":{"metadata":{"generateName":"test-","namespace":"default","creationTimestamp":null,"labels":{"stable.agones.dev/gameserver":"test","stable.agones.dev/role":"gameserver"},"annotations":{"stable.agones.dev/container":"container"},"ownerReferences":[{"apiVersion":"stable.agones.dev/v1alpha1","kind":"GameServer","name":"test","uid":"","controller":true,"blockOwnerDeletion":true}]},"spec":{"containers":[{"name":"container","image":"container/image","ports":[{"hostPort":9999,"containerPort":7777,"protocol":"UDP"}],"resources":{},"livenessProbe":{"httpGet":{"path":"/gshealthz","port":8080},"initialDelaySeconds":5,"periodSeconds":5,"failureThreshold":3}},{"name":"agones-gameserver-sidecar","image":"sidecar:dev","env":[{"name":"GAMESERVER_NAME","value":"test"},{"name":"POD_NAMESPACE","valueFrom":{"fieldRef":{"fieldPath":"metadata.namespace"}}}],"resources":{},"livenessProbe":{"httpGet":{"path":"/healthz","port":8080},"initialDelaySeconds":3,"periodSeconds":3}}],"serviceAccountName":"agones-sdk"},"status":{}},"source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"gameserver":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"error","msg":"Pod created is invalid","pod":null,"source":"*gameservers.Controller","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z","workers":1}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"GameServer container has terminated","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"default/test","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Synchronising","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Ready","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Marking GameServer as Unhealthy","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.HealthController","source":"*gameservers.HealthController","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Ready request has been received!","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Shutdown request has been received!","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Health Ping Received!","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Health stream closed.","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"getting GameServer details","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","maxPort":110,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:15Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":0}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":0}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":1}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":2}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":3}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":4}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":5}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":6}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":7}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":8}
Step #4 - "tests": {"i":1,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":9}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":1}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":2}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":3}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":4}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":5}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":6}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":7}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":8}
Step #4 - "tests": {"i":0,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":9}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":0}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":1}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":2}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":3}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":4}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":5}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":6}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":7}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":8}
Step #4 - "tests": {"i":2,"level":"info","msg":"allocating!","time":"2018-08-01T15:49:16Z","x":9}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Running","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z","workers":1}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"node1","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Already added node to port allocations. Skipping","node":"node1","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"node2","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Already added node to port allocations. Skipping","node":"node2","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"adding n3","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"node3","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"node3","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Adding Node to port allocations","node":"node3","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"unscheduling n3","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"SYNC+ALL","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"SYNC+ALL","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"scheduling n3","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"SYNC+ALL","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"SYNC+ALL","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"deleting n3","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"key":"SYNC+ALL","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"SYNC+ALL","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:16Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:17Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:17Z"}
Step #4 - "tests": {"level":"info","msg":"Starting SDKServer http health check...","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:17Z"}
Step #4 - "tests": {"level":"info","msg":"Starting GameServer health checking","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:17Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc4202e4440), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:17Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:17Z","workers":1}
Step #4 - "tests": {"failureCount":1,"level":"info","msg":"GameServer Health Check failed","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"being marked as not healthy","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"key":"Unhealthy","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420142e20), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:18Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Unhealthy","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"error":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","level":"error","msg":"","obj":"Unhealthy","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"could not retrieve GameServer default/test: gameserver.stable.agones.dev \"test\" not found","stack":["agones.dev/agones/pkg/gameservers.(*SDKServer).updateState\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:185","agones.dev/agones/pkg/gameservers.NewSDKServer.func4\n\t/go/src/agones.dev/agones/pkg/gameservers/sdkserver.go:135","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).processNextWorkItem\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:107","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).runWorker\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:83","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).(agones.dev/agones/pkg/util/workerqueue.runWorker)-fm\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:134","agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait.Until\n\t/go/src/agones.dev/agones/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88","agones.dev/agones/pkg/util/workerqueue.(*WorkerQueue).run\n\t/go/src/agones.dev/agones/pkg/util/workerqueue/workerqueue.go:135","runtime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361"],"time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"failureCount":2,"level":"info","msg":"GameServer Health Check failed","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"being marked as not healthy","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"Unhealthy","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420558280), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"error":"http: Server closed","level":"info","msg":"health check: http server closed","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Health Ping Received","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Health Ping Received","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420854200), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Received Ready request, adding to queue","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"RequestReady","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting SDKServer http health check...","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting GameServer health checking","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420320dc0), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Test Running","test":"enabled, over timeout","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Health Ping Received","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node3","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.GameServerController","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420142820), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node3","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"node3","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Ready","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"State already unhealthy. Skipping update.","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z","workers":1}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"RequestReady","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"RequestReady","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"error":"http: Server closed","level":"info","msg":"health check: http server closed","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Received Shutdown request, adding to queue","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"Shutdown","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting SDKServer http health check...","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting GameServer health checking","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc420143580), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Synchronising","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"dynamic","containerPort":7777,"hostPort":20,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Syncing Port Allocation State","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"dynamic","containerPort":7777,"hostPort":20,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Creating","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Syncing Create State","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"creating Pod for GameServer","pod":{"metadata":{"generateName":"test-","namespace":"default","creationTimestamp":null,"labels":{"stable.agones.dev/gameserver":"test","stable.agones.dev/role":"gameserver"},"annotations":{"stable.agones.dev/container":"container"},"ownerReferences":[{"apiVersion":"stable.agones.dev/v1alpha1","kind":"GameServer","name":"test","uid":"","controller":true,"blockOwnerDeletion":true}]},"spec":{"containers":[{"name":"container","image":"container/image","ports":[{"hostPort":20,"containerPort":7777,"protocol":"UDP"}],"resources":{},"livenessProbe":{"httpGet":{"path":"/gshealthz","port":8080},"initialDelaySeconds":5,"periodSeconds":5,"failureThreshold":3}},{"name":"agones-gameserver-sidecar","image":"sidecar:dev","env":[{"name":"GAMESERVER_NAME","value":"test"},{"name":"POD_NAMESPACE","valueFrom":{"fieldRef":{"fieldPath":"metadata.namespace"}}}],"resources":{},"livenessProbe":{"httpGet":{"path":"/healthz","port":8080},"initialDelaySeconds":3,"periodSeconds":3}}],"serviceAccountName":"agones-sdk"},"status":{}},"source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Synchronising","source":"*gameservers.HealthController","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":50,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Resetting Port Allocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"gs3","uid":"3","creationTimestamp":null},"spec":{"ports":[{"portPolicy":"dynamic","containerPort":0,"hostPort":10}],"health":{},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":null}}},"status":{"state":"Ready","ports":[{"port":10}],"address":"","nodeName":"node2"}},"level":"info","msg":"syncing deleted GameServer","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z","workers":1}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Processing obj","obj":"Shutdown","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Updating state","source":"*gameservers.SDKServer","state":"Shutdown","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"...shutting down workers","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"error":"http: Server closed","level":"info","msg":"health check: http server closed","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gameServerName":"test","level":"info","msg":"created GameServer sidecar","namespace":"default","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting SDKServer http health check...","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Starting GameServer health checking","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"default\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:(*fields.hasTerm)(0xc4203216c0), ResourceVersion:\"\"}}","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Synchronising","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"GameServer is no longer available for syncing","source":"*gameservers.Controller","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"gs":"no","level":"info","msg":"Did not allocate this GameServer. Ignoring for DeAllocation","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/mutate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"groupKind":{"Group":"stable.agones.dev","Kind":"GameServer"},"level":"info","msg":"Added webhook handler","op":"CREATE","path":"/validate","source":"*webhooks.WebHook","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"info","msg":"Wait for cache sync","time":"2018-08-01T15:49:19Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Pod: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"pods\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"key":"default/test","level":"info","msg":"Synchronising","source":"*gameservers.HealthController","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"key":"node1","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"key":"node2","level":"info","msg":"Enqueuing key","queue":"stable.agones.dev.PortAllocator","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"gs":{"metadata":{"name":"test","namespace":"default","creationTimestamp":null,"finalizers":["stable.agones.dev"]},"spec":{"container":"container","ports":[{"portPolicy":"static","containerPort":7777,"hostPort":9999,"protocol":"UDP"}],"health":{"periodSeconds":5,"failureThreshold":3,"initialDelaySeconds":5},"template":{"metadata":{"creationTimestamp":null},"spec":{"containers":[{"name":"container","image":"container/image","resources":{}}]}}},"status":{"state":"Ready","ports":null,"address":"","nodeName":""}},"level":"info","msg":"Marking GameServer as Unhealthy","source":"*gameservers.HealthController","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": E0801 15:49:20.031451    4211 event.go:260] Could not construct reference to: '&v1alpha1.GameServer{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"test", GenerateName:"", Namespace:"default", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Initializers:(*v1.Initializers)(nil), Finalizers:[]string{"stable.agones.dev"}, ClusterName:""}, Spec:v1alpha1.GameServerSpec{Container:"container", GameServerPort:(*v1alpha1.GameServerPort)(nil), Ports:[]v1alpha1.GameServerPort{v1alpha1.GameServerPort{Name:"", PortPolicy:"static", ContainerPort:7777, HostPort:9999, Protocol:"UDP"}}, Health:v1alpha1.Health{Disabled:false, PeriodSeconds:5, FailureThreshold:3, InitialDelaySeconds:5}, Template:v1.PodTemplateSpec{ObjectMeta:v1.ObjectMeta{Name:"", GenerateName:"", Namespace:"", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Initializers:(*v1.Initializers)(nil), Finalizers:[]string(nil), ClusterName:""}, Spec:v1.PodSpec{Volumes:[]v1.Volume(nil), InitContainers:[]v1.Container(nil), Containers:[]v1.Container{v1.Container{Name:"container", Image:"container/image", Command:[]string(nil), Args:[]string(nil), WorkingDir:"", Ports:[]v1.ContainerPort(nil), EnvFrom:[]v1.EnvFromSource(nil), Env:[]v1.EnvVar(nil), Resources:v1.ResourceRequirements{Limits:v1.ResourceList(nil), Requests:v1.ResourceList(nil)}, VolumeMounts:[]v1.VolumeMount(nil), VolumeDevices:[]v1.VolumeDevice(nil), LivenessProbe:(*v1.Probe)(nil), ReadinessProbe:(*v1.Probe)(nil), Lifecycle:(*v1.Lifecycle)(nil), TerminationMessagePath:"", TerminationMessagePolicy:"", ImagePullPolicy:"", SecurityContext:(*v1.SecurityContext)(nil), Stdin:false, StdinOnce:false, TTY:false}}, RestartPolicy:"", TerminationGracePeriodSeconds:(*int64)(nil), ActiveDeadlineSeconds:(*int64)(nil), DNSPolicy:"", NodeSelector:map[string]string(nil), ServiceAccountName:"", DeprecatedServiceAccount:"", AutomountServiceAccountToken:(*bool)(nil), NodeName:"", HostNetwork:false, HostPID:false, HostIPC:false, ShareProcessNamespace:(*bool)(nil), SecurityContext:(*v1.PodSecurityContext)(nil), ImagePullSecrets:[]v1.LocalObjectReference(nil), Hostname:"", Subdomain:"", Affinity:(*v1.Affinity)(nil), SchedulerName:"", Tolerations:[]v1.Toleration(nil), HostAliases:[]v1.HostAlias(nil), PriorityClassName:"", Priority:(*int32)(nil), DNSConfig:(*v1.PodDNSConfig)(nil)}}}, Status:v1alpha1.GameServerStatus{State:"Ready", Ports:[]v1alpha1.GameServerStatusPort(nil), Address:"", NodeName:""}}' due to: 'selfLink was empty, can't make reference'. Will not report event: 'Warning' 'Unhealthy' 'GameServer container terminated'
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/vendor/k8s.io/client-go/informers/factory.go:87: Failed to watch *v1.Node: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"\", Version:\"v1\", Resource:\"nodes\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"level":"info","msg":"Starting workers...","queue":"stable.agones.dev.default.test","source":"*gameservers.SDKServer","time":"2018-08-01T15:49:20Z","workers":1}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"level":"info","maxPort":20,"minPort":10,"msg":"Starting","source":"*gameservers.PortAllocator","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": {"level":"error","msg":"agones.dev/agones/pkg/client/informers/externalversions/factory.go:74: Failed to watch *v1alpha1.GameServer: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:\"\", Verb:\"watch\", Resource:schema.GroupVersionResource{Group:\"stable.agones.dev\", Version:\"v1alpha1\", Resource:\"gameservers\"}, Subresource:\"\"}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:\"\"}}","time":"2018-08-01T15:49:20Z"}
Step #4 - "tests": panic: runtime error: invalid memory address or nil pointer dereference [recovered]
Step #4 - "tests": 	panic: runtime error: invalid memory address or nil pointer dereference
Step #4 - "tests": [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x1799682]
Step #4 - "tests": 
Step #4 - "tests": goroutine 575 [running]:
Step #4 - "tests": testing.tRunner.func1(0xc42093e2d0)
Step #4 - "tests": 	/usr/local/go/src/testing/testing.go:742 +0x567
Step #4 - "tests": panic(0x192f9a0, 0x2520230)
Step #4 - "tests": 	/usr/local/go/src/runtime/panic.go:502 +0x24a
Step #4 - "tests": agones.dev/agones/pkg/gameservers.(*Controller).address(0xc42055c0b0, 0xc420a1f880, 0xc420b14730, 0xc4203f48c0, 0xc4203f46e0, 0x1c78780)
Step #4 - "tests": 	/go/src/agones.dev/agones/pkg/gameservers/controller.go:585 +0x4d2
Step #4 - "tests": agones.dev/agones/pkg/gameservers.TestControllerAddress.func1(0xc42093e2d0)
Step #4 - "tests": 	/go/src/agones.dev/agones/pkg/gameservers/controller_test.go:709 +0x709
Step #4 - "tests": testing.tRunner(0xc42093e2d0, 0xc420ac9990)
Step #4 - "tests": 	/usr/local/go/src/testing/testing.go:777 +0x16e
Step #4 - "tests": created by testing.(*T).Run
Step #4 - "tests": 	/usr/local/go/src/testing/testing.go:824 +0x565
Step #4 - "tests": FAIL	agones.dev/agones/pkg/gameservers	5.811s
Step #4 - "tests": ok  	agones.dev/agones/pkg/gameserversets	2.913s
Step #4 - "tests": ?   	agones.dev/agones/pkg/sdk	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/testing	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/util	[no test files]
Step #4 - "tests": ok  	agones.dev/agones/pkg/util/crd	4.051s
Step #4 - "tests": ?   	agones.dev/agones/pkg/util/runtime	[no test files]
Step #4 - "tests": ?   	agones.dev/agones/pkg/util/signals	[no test files]
Step #4 - "tests": ok  	agones.dev/agones/pkg/util/webhooks	1.130s
Step #4 - "tests": ok  	agones.dev/agones/pkg/util/workerqueue	2.074s
Step #4 - "tests": ok  	agones.dev/agones/sdks/go	1.035s
Step #4 - "tests": Makefile:109: recipe for target 'test-go' failed
Step #4 - "tests": make: *** [test-go] Error 1
Finished Step #4 - "tests"
Finished Step #5 - "build"
ERROR
ERROR: build step 4 "make-docker" failed: exit status 2

agones-bot · 2018-08-01T16:03:45Z

Build Succeeded 👏

Build Id: 3cfcdb88-01c4-4c0c-afcf-2a411f061766

The following development artifacts have been built, and will exist for the next 30 days:

image: gcr.io/agones-images/agones-controller:0.4.0-b85aaf3
image: gcr.io/agones-images/agones-sdk:0.4.0-b85aaf3
Linux C++ SDK (build: dev): agonessdk-0.4.0-b85aaf3-dev-linux-arch_64.tar.gz
Linux C++ SDK (build: runtime): agonessdk-0.4.0-b85aaf3-runtime-linux-arch_64.tar.gz
Linux C++ SDK (source): agonessdk-0.4.0-b85aaf3-src.zip
SDK Server: agonessdk-server-0.4.0-b85aaf3.zip

Fix flakyness with TestSidecarHTTPHealthCheck

bb6c95e

I believe that this is starting at the same time as another http server on the same port, and having a collision. Removing the parrallel marker should fix this.

markmandel added the kind/cleanup Refactoring code, fixing up documentation, etc label Jul 31, 2018

markmandel added this to the 0.4.0 milestone Jul 31, 2018

cyriltovena approved these changes Jul 31, 2018

View reviewed changes

Merge branch 'master' into flaky/test-sidecar-http

b85aaf3

markmandel merged commit 84b60d5 into agones-dev:master Aug 1, 2018

markmandel deleted the flaky/test-sidecar-http branch August 1, 2018 16:25

Navigation Menu

Repository navigation

Fix flakiness with TestSidecarHTTPHealthCheck - #313

Fix flakiness with TestSidecarHTTPHealthCheck#313
markmandel merged 2 commits into
agones-dev:masterfrom
markmandel:flaky/test-sidecar-http

markmandel commented Jul 31, 2018

Uh oh!

agones-bot commented Jul 31, 2018

Uh oh!

agones-bot commented Aug 1, 2018

Uh oh!

agones-bot commented Aug 1, 2018

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Conversation

markmandel commented Jul 31, 2018

Uh oh!

agones-bot commented Jul 31, 2018

Uh oh!

agones-bot commented Aug 1, 2018

Uh oh!

agones-bot commented Aug 1, 2018

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants