This job view page is being replaced by Spyglass soon. Check out the new job view.
PRjberkhahn: Bump kube 1.15
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2019-08-09 23:48
Elapsed30m18s
Revision71333a887ed33fc3ed5c3d9655bcb12e920fba96
Refs 2683

No Test Failures!


Error lines from build-log.txt

... skipping 133 lines ...
+ /go/src/github.com/kubernetes-sigs/service-catalog/bin/conversion-gen --v 1 --logtostderr --extra-peer-dirs k8s.io/api/core/v1,k8s.io/apimachinery/pkg/apis/meta/v1,k8s.io/apimachinery/pkg/conversion,k8s.io/apimachinery/pkg/runtime --go-header-file vendor/github.com/kubernetes/repo-infra/verify/boilerplate/boilerplate.go.txt --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/servicecatalog --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/servicecatalog/v1beta1 --output-file-base zz_generated.conversion
+ /go/src/github.com/kubernetes-sigs/service-catalog/bin/defaulter-gen --v 1 --logtostderr --go-header-file vendor/github.com/kubernetes/repo-infra/verify/boilerplate/boilerplate.go.txt --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings/v1alpha1 --extra-peer-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings --extra-peer-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings/v1alpha1 --output-file-base zz_generated.defaults
+ /go/src/github.com/kubernetes-sigs/service-catalog/bin/deepcopy-gen --v 1 --logtostderr --go-header-file vendor/github.com/kubernetes/repo-infra/verify/boilerplate/boilerplate.go.txt --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings/v1alpha1 --bounding-dirs github.com/kubernetes-sigs/service-catalog --output-file-base zz_generated.deepcopy
+ /go/src/github.com/kubernetes-sigs/service-catalog/bin/conversion-gen --v 1 --logtostderr --extra-peer-dirs k8s.io/api/core/v1,k8s.io/apimachinery/pkg/apis/meta/v1,k8s.io/apimachinery/pkg/conversion,k8s.io/apimachinery/pkg/runtime --go-header-file vendor/github.com/kubernetes/repo-infra/verify/boilerplate/boilerplate.go.txt --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings/v1alpha1 --output-file-base zz_generated.conversion
+ REPORT_FILENAME=./api_violations.txt
+ KNOWN_VIOLATION_FILENAME=./contrib/build/violation_exceptions.txt
+ API_RULE_CHECK_FAILURE_MESSAGE='Error: API rules check failed. Reported violations "./api_violations.txt" differ from known violations "./contrib/build/violation_exceptions.txt". Please fix API source file if new violation is detected, or update known violations "./contrib/build/violation_exceptions.txt" if existing violation is being fixed. Please refer to k8s.io/kubernetes/api/api-rules/README.md and https://github.com/kubernetes/kube-openapi/tree/master/pkg/generators/rules for more information about the API rules being enforced.'
+ /go/src/github.com/kubernetes-sigs/service-catalog/bin/openapi-gen --v 3 --logtostderr --go-header-file vendor/github.com/kubernetes/repo-infra/verify/boilerplate/boilerplate.go.txt --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/servicecatalog/v1beta1,k8s.io/api/core/v1,k8s.io/apimachinery/pkg/api/resource,k8s.io/apimachinery/pkg/apis/meta/v1,k8s.io/apimachinery/pkg/version,k8s.io/apimachinery/pkg/runtime --input-dirs github.com/kubernetes-sigs/service-catalog/pkg/apis/settings/v1alpha1 --output-package github.com/kubernetes-sigs/service-catalog/pkg/openapi --report-filename ./api_violations.txt
I0809 23:51:19.920913      85 parse.go:419] type checker: /usr/local/go/src/internal/bytealg/bytealg.go:14:39: cannot use cpu.X86.HasSSE2 (variable of type bool) as unsafe.ArbitraryType value in argument to unsafe.Offsetof
I0809 23:51:19.921020      85 parse.go:419] type checker: /usr/local/go/src/internal/bytealg/bytealg.go:14:23: unsafe.Offsetof(cpu.X86.HasSSE2) (value of type uintptr) is not constant
I0809 23:51:19.921041      85 parse.go:419] type checker: /usr/local/go/src/internal/bytealg/bytealg.go:15:39: cannot use cpu.X86.HasSSE42 (variable of type bool) as unsafe.ArbitraryType value in argument to unsafe.Offsetof
I0809 23:51:19.921052      85 parse.go:419] type checker: /usr/local/go/src/internal/bytealg/bytealg.go:15:23: unsafe.Offsetof(cpu.X86.HasSSE42) (value of type uintptr) is not constant
I0809 23:51:19.921066      85 parse.go:419] type checker: /usr/local/go/src/internal/bytealg/bytealg.go:16:39: cannot use cpu.X86.HasAVX2 (variable of type bool) as unsafe.ArbitraryType value in argument to unsafe.Offsetof
... skipping 1229 lines ...
I0810 00:16:15.707953       1 etcd_config.go:131] Finished installing API groups
I0810 00:16:15.715688       1 run_server.go:117] Running the API server
I0810 00:16:19.558302       1 secure_serving.go:116] Serving securely on 127.0.0.1:33151
I0810 00:16:19.559231       1 util.go:242] Starting shared informers
I0810 00:16:19.559380       1 util.go:247] Started shared informers
I0810 00:16:19.610965       1 framework.go:170] Found server after 0 tries and duration 11.711945778s
E0810 00:16:19.750688       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:16:20.758541       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:21.046286       1 controller.go:249] Starting service-catalog controller
I0810 00:16:21.231164       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:16:21.297006       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:16:21.381332       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
I0810 00:16:21.432507       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v48: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:21.432384766 +0000 UTC m=+303.145636763
E0810 00:16:21.760045       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:21.985151       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v54: Provision request for ServiceInstance in-flight to Broker
I0810 00:16:22.066765       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v55: The instance was provisioned successfully
I0810 00:16:22.660425       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v57: Binding request for ServiceBinding in-flight to Broker
I0810 00:16:22.663615       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v57: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:22.660399333 +0000 UTC m=+304.373651030
E0810 00:16:22.765949       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:22.830010       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v58: Injected bind result
I0810 00:16:23.613387       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v60: Unbind request for ServiceBinding in-flight to Broker
I0810 00:16:23.774633       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v61: The binding was deleted successfully
E0810 00:16:23.805599       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:23.859541       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v61: Cleared finalizer
I0810 00:16:24.361713       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v63: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:16:24.498791       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v64: The instance was deprovisioned successfully
I0810 00:16:24.672161       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v64: Cleared finalizer
E0810 00:16:24.810338       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:25.335160       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v66: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:16:25.309215125 +0000 UTC m=+307.022466856
I0810 00:16:25.542343       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
I0810 00:16:25.724493       1 controller.go:283] Shutting down service-catalog controller
I0810 00:16:25.822256       1 secure_serving.go:160] Stopped listening on 127.0.0.1:33151
I0810 00:16:25.844683       1 controller.go:300] Shutdown service-catalog controller
--- PASS: TestCreateServiceBindingSuccess (17.97s)
... skipping 57 lines ...
I0810 00:16:32.711862       1 etcd_config.go:131] Finished installing API groups
I0810 00:16:32.720313       1 run_server.go:117] Running the API server
I0810 00:16:36.865186       1 secure_serving.go:116] Serving securely on 127.0.0.1:34445
I0810 00:16:36.898683       1 util.go:242] Starting shared informers
I0810 00:16:36.903563       1 util.go:247] Started shared informers
I0810 00:16:36.914413       1 framework.go:170] Found server after 0 tries and duration 11.026686817s
E0810 00:16:37.180754       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:16:38.189546       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:38.377369       1 controller.go:249] Starting service-catalog controller
I0810 00:16:38.579863       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:16:38.692153       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:16:38.742720       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v72: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:38.742644056 +0000 UTC m=+320.455895797
I0810 00:16:38.759016       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
E0810 00:16:39.193346       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:39.306991       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v78: Provision request for ServiceInstance in-flight to Broker
I0810 00:16:39.431629       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v79: The instance was provisioned successfully
I0810 00:16:39.936684       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v81: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:16:40.192535       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v82: The instance was deprovisioned successfully
E0810 00:16:40.215608       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:40.346036       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v82: Cleared finalizer
I0810 00:16:40.891318       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v84: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:16:40.891173867 +0000 UTC m=+322.604425571
I0810 00:16:41.033462       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
E0810 00:16:41.240461       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:41.361646       1 controller.go:283] Shutting down service-catalog controller
I0810 00:16:41.364165       1 controller.go:300] Shutdown service-catalog controller
--- PASS: TestCreateServiceBindingInvalidInstanceFailure (15.51s)
    --- PASS: TestCreateServiceBindingInvalidInstanceFailure/invalid_service_instance_name (15.51s)
        framework.go:104: Server started on port 34445
        framework.go:135: Test client will use API Server URL of https://localhost:34445
... skipping 55 lines ...
I0810 00:16:48.500482       1 etcd_config.go:131] Finished installing API groups
I0810 00:16:48.500919       1 run_server.go:117] Running the API server
I0810 00:16:51.778330       1 secure_serving.go:116] Serving securely on 127.0.0.1:41509
I0810 00:16:51.779187       1 util.go:242] Starting shared informers
I0810 00:16:51.779306       1 util.go:247] Started shared informers
I0810 00:16:51.802179       1 framework.go:170] Found server after 0 tries and duration 10.415652917s
E0810 00:16:51.937770       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:52.829824       1 controller.go:249] Starting service-catalog controller
E0810 00:16:52.947704       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:52.954663       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:16:52.988407       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:16:53.010845       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v90: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:53.010747168 +0000 UTC m=+334.723998896
I0810 00:16:53.027742       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
I0810 00:16:53.712880       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v96: Provision request for ServiceInstance in-flight to Broker
I0810 00:16:53.837635       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v97: The instance was provisioned successfully
E0810 00:16:53.952103       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:54.269773       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v99: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.270096       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v99: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:54.269729401 +0000 UTC m=+335.982981117
I0810 00:16:54.390646       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v99: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.392761       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v99: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:54.390612901 +0000 UTC m=+336.103864610
E0810 00:16:54.448980       1 controller_binding.go:729] ServiceBinding "test-namespace/test-binding" v99: Error updating status: Operation cannot be fulfilled on servicebindings.servicecatalog.k8s.io "test-binding": the object has been modified; please apply your changes to the latest version and try again
I0810 00:16:54.468381       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v99: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.469514       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v99: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:16:54.468349903 +0000 UTC m=+336.181601626
E0810 00:16:54.573765       1 controller_binding.go:729] ServiceBinding "test-namespace/test-binding" v99: Error updating status: Operation cannot be fulfilled on servicebindings.servicecatalog.k8s.io "test-binding": the object has been modified; please apply your changes to the latest version and try again
I0810 00:16:54.582466       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v100: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.610624       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v100: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.653813       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v100: References a non-existent ServiceInstance "test-namespace/nothereinstance"
I0810 00:16:54.848815       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v100: References a non-existent ServiceInstance "test-namespace/nothereinstance"
E0810 00:16:54.958190       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:55.201404       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v100: References a non-existent ServiceInstance "test-namespace/nothereinstance"
E0810 00:16:55.283765       1 controller_binding.go:729] ServiceBinding "test-namespace/test-binding" v100: Error updating status: Operation cannot be fulfilled on servicebindings.servicecatalog.k8s.io "test-binding": the object has been modified; please apply your changes to the latest version and try again
I0810 00:16:55.315308       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v101: Cleared finalizer
I0810 00:16:55.925612       1 controller_binding.go:122] ServiceBinding "test-namespace/test-binding": Not doing work because the ServiceBinding has been deleted
I0810 00:16:55.928942       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v103: Deprovision request for ServiceInstance in-flight to Broker
E0810 00:16:55.972743       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:56.048873       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v104: The instance was deprovisioned successfully
I0810 00:16:56.176283       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v104: Cleared finalizer
I0810 00:16:56.951445       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v106: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:16:56.950677132 +0000 UTC m=+338.663928874
E0810 00:16:56.983408       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:16:57.076674       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
I0810 00:16:57.339944       1 secure_serving.go:160] Stopped listening on 127.0.0.1:41509
I0810 00:16:57.350933       1 controller.go:283] Shutting down service-catalog controller
I0810 00:16:57.392015       1 controller.go:300] Shutdown service-catalog controller
--- PASS: TestCreateServiceBindingInvalidInstance (16.01s)
    --- PASS: TestCreateServiceBindingInvalidInstance/non-existent_service_instance_name (16.01s)
... skipping 56 lines ...
I0810 00:17:04.198799       1 etcd_config.go:131] Finished installing API groups
I0810 00:17:04.206607       1 run_server.go:117] Running the API server
I0810 00:17:07.060543       1 secure_serving.go:116] Serving securely on 127.0.0.1:39171
I0810 00:17:07.061262       1 util.go:242] Starting shared informers
I0810 00:17:07.061354       1 util.go:247] Started shared informers
I0810 00:17:07.082546       1 framework.go:170] Found server after 0 tries and duration 9.669773716s
E0810 00:17:07.121987       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:08.179839       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:08.608129       1 controller.go:249] Starting service-catalog controller
I0810 00:17:08.733090       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:17:08.743158       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:17:08.764228       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v112: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:08.764148511 +0000 UTC m=+350.477400231
I0810 00:17:08.767143       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
E0810 00:17:09.182373       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:09.522893       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v118: Provision request for ServiceInstance in-flight to Broker
I0810 00:17:09.557216       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v119: The instance was provisioned successfully
I0810 00:17:10.069005       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v121: References a non-bindable ClusterServiceClass (K8S: "12345" ExternalName: "test-service") and Plan ("test-nb-plan") combination
I0810 00:17:10.070090       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v121: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:10.068969071 +0000 UTC m=+351.782220775
I0810 00:17:10.070903       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v121: References a non-bindable ClusterServiceClass (K8S: "12345" ExternalName: "test-service") and Plan ("test-nb-plan") combination
E0810 00:17:10.184736       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:10.669942       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v123: Cleared finalizer
I0810 00:17:10.748463       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v125: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:17:10.860833       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v126: The instance was deprovisioned successfully
I0810 00:17:10.941000       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v126: Cleared finalizer
E0810 00:17:11.186644       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:11.675323       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v128: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:17:11.675167166 +0000 UTC m=+353.388418875
I0810 00:17:11.835922       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
I0810 00:17:12.014201       1 controller.go:283] Shutting down service-catalog controller
I0810 00:17:12.032675       1 secure_serving.go:160] Stopped listening on 127.0.0.1:39171
E0810 00:17:12.094882       1 watcher.go:214] watch chan error: rpc error: code = Canceled desc = context canceled
I0810 00:17:12.113279       1 controller.go:300] Shutdown service-catalog controller
--- PASS: TestCreateServiceBindingNonBindable (14.71s)
    --- PASS: TestCreateServiceBindingNonBindable/non-bindable_plan (14.71s)
        framework.go:104: Server started on port 39171
        framework.go:135: Test client will use API Server URL of https://localhost:39171
        controller_test.go:796: controller start
... skipping 53 lines ...
I0810 00:17:18.865886       1 etcd_config.go:131] Finished installing API groups
I0810 00:17:18.867473       1 run_server.go:117] Running the API server
I0810 00:17:22.530963       1 secure_serving.go:116] Serving securely on 127.0.0.1:46649
I0810 00:17:22.532093       1 util.go:242] Starting shared informers
I0810 00:17:22.532303       1 util.go:247] Started shared informers
I0810 00:17:22.566613       1 framework.go:170] Found server after 0 tries and duration 10.433576105s
E0810 00:17:22.772001       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:23.837225       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:23.967838       1 controller.go:249] Starting service-catalog controller
I0810 00:17:24.122509       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:17:24.168608       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:17:24.238967       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
I0810 00:17:24.244730       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v134: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:24.244652377 +0000 UTC m=+365.957904109
I0810 00:17:24.732620       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v140: Binding cannot begin because ClusterServiceClass and ClusterServicePlan references for ServiceInstance "test-namespace/test-instance" have not been resolved yet
I0810 00:17:24.733798       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v140: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:24.732597367 +0000 UTC m=+366.445849084
I0810 00:17:24.818448       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v141: Binding cannot begin because ClusterServiceClass and ClusterServicePlan references for ServiceInstance "test-namespace/test-instance" have not been resolved yet
E0810 00:17:24.841899       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:24.937392       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v141: Binding cannot begin because ClusterServiceClass and ClusterServicePlan references for ServiceInstance "test-namespace/test-instance" have not been resolved yet
I0810 00:17:24.978944       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v142: Provision request for ServiceInstance in-flight to Broker
I0810 00:17:25.003441       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v141: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
I0810 00:17:25.091780       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v143: Error provisioning ServiceInstance of ClusterServiceClass (K8S: "12345" ExternalName: "test-service") at ClusterServiceBroker "test-broker": Status: 502; ErrorMessage: error message; Description: response description; ResponseError: <nil>
I0810 00:17:25.091976       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v143: Error provisioning ServiceInstance of ClusterServiceClass (K8S: "12345" ExternalName: "test-service") at ClusterServiceBroker "test-broker": Status: 502; ErrorMessage: error message; Description: response description; ResponseError: <nil>
I0810 00:17:25.092112       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v143: The instance provision call failed with an ambiguous error; attempting to deprovision the instance in order to mitigate an orphaned resource
I0810 00:17:25.144948       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
2019-08-10 00:17:25.655767 W | etcdserver: request "header:<ID:7587840213561547787 > txn:<compare:<target:MOD key:\"/registry-1B587D36/servicecatalog.k8s.io/serviceinstances/test-namespace/test-instance\" mod_revision:143 > success:<request_put:<key:\"/registry-1B587D36/servicecatalog.k8s.io/serviceinstances/test-namespace/test-instance\" value_size:1654 >> failure:<request_range:<key:\"/registry-1B587D36/servicecatalog.k8s.io/serviceinstances/test-namespace/test-instance\" > >>" with result "size:16" took too long (405.557601ms) to execute
2019-08-10 00:17:25.661017 W | etcdserver: read-only range request "key:\"/registry-1B587D36/servicecatalog.k8s.io/servicebindings/test-namespace/test-binding\" " with result "range_response_count:1 size:929" took too long (392.901449ms) to execute
2019-08-10 00:17:25.662929 W | etcdserver: read-only range request "key:\"/registry-1B587D36/servicecatalog.k8s.io/servicebindings/test-namespace/test-binding\" " with result "range_response_count:1 size:929" took too long (319.979917ms) to execute
I0810 00:17:25.679524       1 trace.go:81] Trace[274306439]: "GuaranteedUpdate etcd3: *servicecatalog.ServiceInstance" (started: 2019-08-10 00:17:25.115529228 +0000 UTC m=+366.828780963) (total time: 563.85926ms):
Trace[274306439]: [562.879457ms] [440.186679ms] Transaction committed
I0810 00:17:25.680618       1 trace.go:81] Trace[869360525]: "Update /apis/servicecatalog.k8s.io/v1beta1/namespaces/test-namespace/serviceinstances/test-instance/status" (started: 2019-08-10 00:17:25.100651175 +0000 UTC m=+366.813902881) (total time: 579.823391ms):
Trace[869360525]: [579.32006ms] [567.820814ms] Object stored in database
I0810 00:17:25.681802       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
I0810 00:17:25.718884       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v145: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
E0810 00:17:25.870950       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:25.878779       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
I0810 00:17:26.089030       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
I0810 00:17:26.026207       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.207189       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.257045       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.344417       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.473732       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.656943       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:26.830028       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
E0810 00:17:26.878275       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:26.978059       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
E0810 00:17:27.882955       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:28.209981       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v144: Binding cannot begin because referenced ServiceInstance "test-namespace/test-instance" is not ready
I0810 00:17:28.302815       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
E0810 00:17:28.887477       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:29.890996       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:30.895519       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
2019-08-10 00:17:30.931882 W | etcdserver: read-only range request "key:\"/registry-1B587D36/servicecatalog.k8s.io/servicebindings/test-namespace/test-binding\" " with result "range_response_count:1 size:1003" took too long (140.896256ms) to execute
2019-08-10 00:17:30.936444 W | etcdserver: read-only range request "key:\"/registry-1B587D36/servicecatalog.k8s.io/servicebindings/test-namespace/test-binding\" " with result "range_response_count:1 size:1003" took too long (129.917396ms) to execute
I0810 00:17:30.941930       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v146: All associated ServiceBindings must be removed before this ServiceInstance can be deleted
I0810 00:17:31.038226       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v147: Cleared finalizer
I0810 00:17:31.039580       1 controller_binding.go:122] ServiceBinding "test-namespace/test-binding": Not doing work because the ServiceBinding has been deleted
I0810 00:17:31.708330       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v149: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:17:31.821738       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v150: The instance was deprovisioned successfully
E0810 00:17:31.898550       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:31.959213       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v150: Cleared finalizer
I0810 00:17:32.529084       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v152: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:17:32.52890335 +0000 UTC m=+374.242155056
E0810 00:17:32.902171       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:32.925034       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
I0810 00:17:32.996386       1 controller.go:283] Shutting down service-catalog controller
I0810 00:17:33.035842       1 secure_serving.go:160] Stopped listening on 127.0.0.1:46649
I0810 00:17:33.079502       1 controller.go:300] Shutdown service-catalog controller
--- PASS: TestCreateServiceBindingInstanceNotReady (20.96s)
    --- PASS: TestCreateServiceBindingInstanceNotReady/service_instance_not_ready (20.96s)
... skipping 56 lines ...
I0810 00:17:40.338041       1 etcd_config.go:131] Finished installing API groups
I0810 00:17:40.339034       1 run_server.go:117] Running the API server
I0810 00:17:42.674073       1 secure_serving.go:116] Serving securely on 127.0.0.1:38903
I0810 00:17:42.674851       1 util.go:242] Starting shared informers
I0810 00:17:42.674936       1 util.go:247] Started shared informers
I0810 00:17:42.710961       1 framework.go:170] Found server after 0 tries and duration 9.608952681s
E0810 00:17:42.784621       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:43.796706       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:44.019680       1 controller.go:249] Starting service-catalog controller
I0810 00:17:44.151600       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:17:44.159074       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:17:44.181076       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v158: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:44.18101821 +0000 UTC m=+385.894269911
I0810 00:17:44.183197       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
E0810 00:17:44.798053       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:44.866890       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v164: Provision request for ServiceInstance in-flight to Broker
I0810 00:17:44.938109       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v165: The instance was provisioned successfully
I0810 00:17:45.385270       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v167: Binding request for ServiceBinding in-flight to Broker
I0810 00:17:45.398164       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v167: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:17:45.385220522 +0000 UTC m=+387.098472220
I0810 00:17:45.542150       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v168: Injected bind result
E0810 00:17:45.805990       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:46.143265       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v170: Unbind request for ServiceBinding in-flight to Broker
I0810 00:17:46.289921       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v171: The binding was deleted successfully
I0810 00:17:46.408921       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v171: Cleared finalizer
E0810 00:17:46.811430       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:17:46.936949       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v173: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:17:47.044663       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v174: The instance was deprovisioned successfully
I0810 00:17:47.086335       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v174: Cleared finalizer
I0810 00:17:47.748921       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v176: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:17:47.748703954 +0000 UTC m=+389.461955682
E0810 00:17:47.819591       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
E0810 00:17:47.936051       1 controller_clusterservicebroker.go:683] ClusterServiceBroker "test-broker" v180: Error updating ready condition: Operation cannot be fulfilled on clusterservicebrokers.servicecatalog.k8s.io "test-broker": StorageError: invalid object, Code: 4, Key: /registry-649943F3/servicecatalog.k8s.io/clusterservicebrokers/test-broker, ResourceVersion: 0, AdditionalErrorMsg: Precondition failed: UID in precondition: ac71a127-b76b-49f8-8f83-7c05628d5a69, UID in object meta: 
I0810 00:17:48.174449       1 controller.go:283] Shutting down service-catalog controller
I0810 00:17:48.240922       1 controller.go:300] Shutdown service-catalog controller
=== RUN   TestCreateServiceBindingWithParameters/plain_params
I0810 00:17:48.252753       1 framework.go:163] Waiting for : "https://localhost:45365"
I0810 00:17:48.258896       1 util.go:73] service catalog is in standalone mode
I0810 00:17:48.419134       1 secure_serving.go:160] Stopped listening on 127.0.0.1:38903
... skipping 48 lines ...
I0810 00:17:57.908568       1 etcd_config.go:131] Finished installing API groups
I0810 00:17:57.910013       1 run_server.go:117] Running the API server
I0810 00:18:00.313682       1 secure_serving.go:116] Serving securely on 127.0.0.1:45365
I0810 00:18:00.330766       1 util.go:242] Starting shared informers
I0810 00:18:00.330897       1 util.go:247] Started shared informers
I0810 00:18:00.350102       1 framework.go:170] Found server after 0 tries and duration 12.097344865s
E0810 00:18:00.781887       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:01.742608       1 controller.go:249] Starting service-catalog controller
E0810 00:18:01.783651       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:02.119773       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:18:02.297915       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:18:02.531952       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v182: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:18:02.53074003 +0000 UTC m=+404.243991782
I0810 00:18:02.646654       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
E0810 00:18:02.788145       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:03.288486       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v188: Provision request for ServiceInstance in-flight to Broker
I0810 00:18:03.375009       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v189: The instance was provisioned successfully
E0810 00:18:03.799219       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:03.858356       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v191: Binding request for ServiceBinding in-flight to Broker
I0810 00:18:03.863049       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v191: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:18:03.858313619 +0000 UTC m=+405.571565317
I0810 00:18:04.074809       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v192: Injected bind result
E0810 00:18:04.806051       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:04.830214       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v194: Unbind request for ServiceBinding in-flight to Broker
I0810 00:18:04.906122       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v195: The binding was deleted successfully
I0810 00:18:04.969402       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v195: Cleared finalizer
I0810 00:18:05.529231       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v197: Deprovision request for ServiceInstance in-flight to Broker
I0810 00:18:05.607230       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v198: The instance was deprovisioned successfully
I0810 00:18:05.761470       1 controller_instance.go:2516] ServiceInstance "test-namespace/test-instance" v198: Cleared finalizer
E0810 00:18:05.813476       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:06.740766       1 controller_clusterservicebroker.go:657] ClusterServiceBroker "test-broker" v200: Found status change for condition "Ready": "True" -> "False"; setting lastTransitionTime to 2019-08-10 00:18:06.740618833 +0000 UTC m=+408.453870560
E0810 00:18:06.816094       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:07.052091       1 controller_clusterservicebroker.go:115] ClusterServiceBroker "test-broker": Not doing work because it has been deleted
I0810 00:18:07.333674       1 controller.go:283] Shutting down service-catalog controller
E0810 00:18:07.377108       1 watcher.go:214] watch chan error: rpc error: code = Canceled desc = context canceled
I0810 00:18:07.387316       1 controller.go:300] Shutdown service-catalog controller
=== RUN   TestCreateServiceBindingWithParameters/secret_params
I0810 00:18:07.417376       1 framework.go:163] Waiting for : "https://localhost:36147"
I0810 00:18:07.420328       1 util.go:73] service catalog is in standalone mode
I0810 00:18:07.620426       1 secure_serving.go:160] Stopped listening on 127.0.0.1:45365
I0810 00:18:09.778753       1 serving.go:312] Generated self-signed cert (/tmp/service-catalog-integration755002639/apiserver.crt, /tmp/service-catalog-integration755002639/apiserver.key)
... skipping 47 lines ...
I0810 00:18:13.689677       1 etcd_config.go:131] Finished installing API groups
I0810 00:18:13.690101       1 run_server.go:117] Running the API server
I0810 00:18:16.429401       1 secure_serving.go:116] Serving securely on 127.0.0.1:36147
I0810 00:18:16.430136       1 util.go:242] Starting shared informers
I0810 00:18:16.430257       1 util.go:247] Started shared informers
I0810 00:18:16.462662       1 framework.go:170] Found server after 0 tries and duration 9.045278482s
E0810 00:18:16.744810       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
2019-08-10 00:18:16.953932 W | etcdserver: read-only range request "key:\"/registry-0FD308F4/servicecatalog.k8s.io/servicebindings/\" range_end:\"/registry-0FD308F4/servicecatalog.k8s.io/servicebindings0\" limit:500 " with result "range_response_count:0 size:5" took too long (264.71128ms) to execute
2019-08-10 00:18:16.955631 W | etcdserver: read-only range request "key:\"/registry-0FD308F4/servicecatalog.k8s.io/clusterserviceplans/\" range_end:\"/registry-0FD308F4/servicecatalog.k8s.io/clusterserviceplans0\" limit:500 " with result "range_response_count:0 size:5" took too long (255.239747ms) to execute
E0810 00:18:17.803295       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:18.026040       1 controller.go:249] Starting service-catalog controller
I0810 00:18:18.426380       1 controller_clusterserviceclass.go:72] ClusterServiceClass "12345" (ExternalName: "test-service"): processing
I0810 00:18:18.565911       1 controller_clusterserviceplan.go:73] ClusterServicePlan "34567" (ExternalName: "test-plan"): processing
I0810 00:18:18.619389       1 controller_clusterserviceplan.go:73] ClusterServicePlan "nb34567" (ExternalName: "test-nb-plan"): processing
I0810 00:18:18.666777       1 controller_clusterservicebroker.go:650] ClusterServiceBroker "test-broker" v206: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:18:18.66669447 +0000 UTC m=+420.379946207
E0810 00:18:18.807004       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:19.147810       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v212: Provision request for ServiceInstance in-flight to Broker
I0810 00:18:19.207962       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v213: The instance was provisioned successfully
I0810 00:18:19.643394       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v215: Binding request for ServiceBinding in-flight to Broker
I0810 00:18:19.644005       1 controller_binding.go:690] ServiceBinding "test-namespace/test-binding" v215: Setting lastTransitionTime for condition "Ready" to 2019-08-10 00:18:19.643348617 +0000 UTC m=+421.356600307
I0810 00:18:19.786464       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v216: Injected bind result
E0810 00:18:19.820144       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
I0810 00:18:20.679912       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v218: Unbind request for ServiceBinding in-flight to Broker
I0810 00:18:20.755218       1 controller_binding.go:676] ServiceBinding "test-namespace/test-binding" v219: The binding was deleted successfully
I0810 00:18:20.807994       1 controller_binding.go:1491] ServiceBinding "test-namespace/test-binding" v219: Cleared finalizer
E0810 00:18:20.824176       1 reflector.go:283] k8s.io/client-go/informers/factory.go:133: Failed to watch *v1.Secret: unhandled watch: testing.WatchActionImpl{ActionImpl:testing.ActionImpl{Namespace:"", Verb:"watch", Resource:schema.GroupVersionResource{Group:"", Version:"v1", Resource:"secrets"}, Subresource:""}, WatchRestrictions:testing.WatchRestrictions{Labels:labels.internalSelector(nil), Fields:fields.andTerm{}, ResourceVersion:""}}
{"component":"entrypoint","file":"prow/entrypoint/run.go:163","func":"k8s.io/test-infra/prow/entrypoint.Options.ExecuteProcess","level":"error","msg":"Entrypoint received interrupt: terminated","time":"2019-08-10T00:18:21Z"}
I0810 00:18:21.382275       1 controller_instance.go:1748] ServiceInstance "test-namespace/test-instance" v221: Deprovision request for ServiceInstance in-flight to Broker