+ service docker start * Starting Docker: docker ...done. + [[ -n /home/prow/go ]] + export PATH=/home/prow/go/bin:/usr/local/go/bin:/opt/go/bin:/usr/lib/google-cloud-sdk/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin + PATH=/home/prow/go/bin:/usr/local/go/bin:/opt/go/bin:/usr/lib/google-cloud-sdk/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin + [[ -n '' ]] + exec prow/istio-integ-local-tests.sh + source /home/prow/go/src/istio.io/istio/prow/lib.sh + setup_and_export_git_sha + [[ -n prow ]] + [[ prow == \b\o\o\t\s\t\r\a\p ]] + [[ prow == \p\r\o\w ]] + export ARTIFACTS_DIR=/logs/artifacts + ARTIFACTS_DIR=/logs/artifacts + '[' -z 7dd2531d0cb36a75664c9f6a5e69b83d90306ee5 ']' + export GIT_SHA=7dd2531d0cb36a75664c9f6a5e69b83d90306ee5 + GIT_SHA=7dd2531d0cb36a75664c9f6a5e69b83d90306ee5 + gcloud auth configure-docker -q Docker configuration file updated. + cd /home/prow/go/src/istio.io/istio + make sync ISTIO_OUT=/home/prow/go/out/linux_amd64/release bin/init.sh /home/prow/go/out/linux_amd64/debug /home/prow/go/src/istio.io/istio Downloading envoy debug artifact: curl -fLSs https://storage.googleapis.com/istio-build/proxy/envoy-debug-1ae5ab2ce8a222021c1f1227c32490fabc20a6c6.tar.gz real 0m5.286s user 0m4.875s sys 0m2.398s /home/prow/go/src/istio.io/istio /home/prow/go/out/linux_amd64/release /home/prow/go/src/istio.io/istio Downloading envoy release artifact: curl -fLSs https://storage.googleapis.com/istio-build/proxy/envoy-alpha-1ae5ab2ce8a222021c1f1227c32490fabc20a6c6.tar.gz real 0m0.331s user 0m0.265s sys 0m0.111s /home/prow/go/src/istio.io/istio % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 100 8946k 100 8946k 0 0 65.8M 0 --:--:-- --:--:-- --:--:-- 66.1M touch /home/prow/go/out/linux_amd64/release/istio_is_init mkdir -p /home/prow/go/out/logs + JUNIT_UNIT_TEST_XML=/logs/artifacts/junit_unit-tests.xml + T=-v + make test.integration.local mkdir -p /logs/artifacts/ set -o pipefail; \ /usr/local/go/bin/go test -p 1 -v istio.io/istio/tests/integration2/citadel istio.io/istio/tests/integration2/echo istio.io/istio/tests/integration2/galley/conversion istio.io/istio/tests/integration2/galley/validation istio.io/istio/tests/integration2/mixer istio.io/istio/tests/integration2/pilot istio.io/istio/tests/integration2/pilot/security --istio.test.env native \ 2>&1 | tee >(/opt/go/bin/go-junit-report > /logs/artifacts/junit_unit-tests.xml) 2019-02-11T19:14:50.374970Z info CI Test Framework runtime settings: Environment: native TestID: citadel_test RunID: citadel-test-d81bcfac067048f7a2 NoCleanup: false WorkDir: /tmp/citadel-test-d81bcfac067048f7a2 === RUN TestSecretCreationKubernetes --- SKIP: TestSecretCreationKubernetes (0.00s) secret_creation_test.go:31: https://github.com/istio/istio/issues/10989 PASS ok istio.io/istio/tests/integration2/citadel 0.349s 2019-02-11T19:14:54.650230Z info CI Test Framework runtime settings: Environment: native TestID: echo_test RunID: echo-test-4cb08a0c12294e49b0604 NoCleanup: false WorkDir: /tmp/echo-test-4cb08a0c12294e49b0604 === RUN TestEcho Listening HTTP/1.1 on 38949 Listening HTTP/1.1 on 37809 Listening HTTP/1.1 on 37569 Listening HTTP/1.1 on 45473 Listening GRPC on 38111 Listening GRPC on 41963 2019-02-11T19:14:58.652246Z info parsed scheme: "" 2019-02-11T19:14:58.652295Z info scheme "" not registered, fallback to default scheme Listening HTTP/1.1 on 35373 Listening HTTP/1.1 on 37621 Listening HTTP/1.1 on 40229 Listening HTTP/1.1 on 39595 Listening GRPC on 41535 Listening GRPC on 34291 2019-02-11T19:14:58.652573Z info parsed scheme: "" 2019-02-11T19:14:58.652586Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:14:58.652606Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:41963 0 }] 2019-02-11T19:14:58.652678Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:14:58.652726Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:34291 0 }] 2019-02-11T19:14:58.652740Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:14:58.652831Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4203abd00, CONNECTING 2019-02-11T19:14:58.652902Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:14:58.652964Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42068c010, CONNECTING 2019-02-11T19:14:58.653293Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42068c010, READY 2019-02-11T19:14:58.654454Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4203abd00, READY --- PASS: TestEcho (4.06s) PASS ok istio.io/istio/tests/integration2/echo 4.393s 2019-02-11T19:15:02.980867Z info CI Test Framework runtime settings: Environment: native TestID: galley_conversion_test RunID: galley-conversion-test-8b523492 NoCleanup: false WorkDir: /tmp/galley-conversion-test-8b523492 === RUN TestConversion === RUN TestConversion/config.istio.io_v1alpha2_circonus 2019-02-11T19:15:06.983159Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:06.983961Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir297111605/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir297111605/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:06.984019Z info parsed scheme: "" 2019-02-11T19:15:06.984031Z info scheme "" not registered, fallback to default scheme === RUN TestConversion/config.istio.io_v1alpha2_circonus/config.istio.io_v1alpha2_circonus 2019-02-11T19:15:06.984125Z info runtime Starting processor... 2019-02-11T19:15:06.984298Z info parsed scheme: "" 2019-02-11T19:15:06.984321Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:06.984481Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40609 0 }] 2019-02-11T19:15:06.984500Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:06.985117Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:06.985316Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4206a8e40, CONNECTING 2019-02-11T19:15:06.986853Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4206a8e40, READY 2019-02-11T19:15:06.986936Z info mcp New MCP stream created 2019-02-11T19:15:06.987065Z info runtime Synchronization is complete, starting distribution. 2019-02-11T19:15:06.987472Z info mcp MCP: connection {addr=[::1]:43656 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs"} 2019-02-11T19:15:06.987527Z info mcp MCP: connection {addr=[::1]:43656 id=1}: WATCH for istio/config/v1alpha2/legacy/circonuses 2019-02-11T19:15:06.987544Z info mcp Watch(): created watch 1 for istio/config/v1alpha2/legacy/circonuses from group "default", version "" 2019-02-11T19:15:07.987636Z info mcp SetSnapshot(): respond to watch 1 for istio/config/v1alpha2/legacy/circonuses @ version "1" 2019-02-11T19:15:07.988171Z info mcp Watch(): created watch 2 for istio/config/v1alpha2/legacy/circonuses from group "default", version "1" === RUN TestConversion/extensions_v1beta1_ingress_basic 2019-02-11T19:15:07.989524Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:07.989608Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:07.989814Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:07.989839Z info mcp MCP: connection {addr=[::1]:43656 id=1}: CLOSED 2019-02-11T19:15:07.989906Z info mcp MCP: connection {addr=[::1]:43656 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:07.989923Z info runtime Stopping processor... 2019-02-11T19:15:07.990499Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:07.990957Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir777985552/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir777985552/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:07.990994Z info parsed scheme: "" 2019-02-11T19:15:07.991001Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:07.991026Z info runtime Starting processor... 2019-02-11T19:15:07.991187Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/extensions_v1beta1_ingress_basic/extensions_v1beta1_ingress_basic 2019-02-11T19:15:11.992326Z info runtime Stopping processor... 2019-02-11T19:15:11.992667Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:11.992880Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:11.993472Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir777985552/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir777985552/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:11.993517Z info parsed scheme: "" 2019-02-11T19:15:11.993534Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:11.993608Z info runtime Starting processor... 2019-02-11T19:15:11.993823Z info parsed scheme: "" 2019-02-11T19:15:11.994504Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:11.994774Z info ccResolverWrapper: sending new addresses to cc: [{[::]:39073 0 }] 2019-02-11T19:15:11.994819Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:11.994857Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:11.995046Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420a620c0, CONNECTING 2019-02-11T19:15:11.995056Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:15:11.995410Z info runtime Synchronization is complete, starting distribution. 2019-02-11T19:15:11.995546Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420a620c0, READY 2019-02-11T19:15:11.995620Z info mcp New MCP stream created 2019-02-11T19:15:11.996431Z info mcp MCP: connection {addr=[::1]:48540 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/edges", "istio/config/v1alpha2/legacy/listentries", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/templates", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/bypasses", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/noops", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/logentries", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/quotas", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/kubernetesenvs"} 2019-02-11T19:15:11.996493Z info mcp MCP: connection {addr=[::1]:48540 id=1}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:11.996502Z info mcp Watch(): created watch 1 for istio/networking/v1alpha3/gateways from group "default", version "" 2019-02-11T19:15:12.995944Z info conversions Ignore default wildcard ingress, use VirtualService :foo 2019-02-11T19:15:12.996029Z info mcp SetSnapshot(): respond to watch 1 for istio/networking/v1alpha3/gateways @ version "0_2" 2019-02-11T19:15:12.996436Z info mcp Watch(): created watch 2 for istio/networking/v1alpha3/gateways from group "default", version "0_2" 2019-02-11T19:15:12.997733Z info parsed scheme: "" 2019-02-11T19:15:12.997757Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:12.997768Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:12.997812Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" === RUN TestConversion/extensions_v1beta1_ingress_merge 2019-02-11T19:15:12.997900Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:12.997958Z info mcp MCP: connection {addr=[::1]:48540 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:12.997918Z info mcp MCP: connection {addr=[::1]:48540 id=1}: CLOSED 2019-02-11T19:15:12.997999Z info runtime Stopping processor... 2019-02-11T19:15:12.998504Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:12.998998Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:12.999044Z info parsed scheme: "" 2019-02-11T19:15:12.999055Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:12.999085Z info runtime Starting processor... 2019-02-11T19:15:12.999297Z info runtime Synchronization is complete, starting distribution. 2019-02-11T19:15:17.000171Z info runtime Stopping processor... 2019-02-11T19:15:17.000605Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:17.000674Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:17.001220Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:17.001272Z info parsed scheme: "" 2019-02-11T19:15:17.001280Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:17.001314Z info runtime Starting processor... 2019-02-11T19:15:17.001470Z info parsed scheme: "" 2019-02-11T19:15:17.001486Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:17.001560Z info ccResolverWrapper: sending new addresses to cc: [{[::]:46259 0 }] 2019-02-11T19:15:17.001592Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:17.001609Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:17.001665Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42070e130, CONNECTING 2019-02-11T19:15:17.002580Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42070e130, READY 2019-02-11T19:15:17.002697Z info mcp New MCP stream created 2019-02-11T19:15:17.003628Z info runtime Synchronization is complete, starting distribution. 2019-02-11T19:15:17.004431Z info mcp MCP: connection {addr=[::1]:41844 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules"} 2019-02-11T19:15:17.004514Z info mcp MCP: connection {addr=[::1]:41844 id=1}: WATCH for istio/networking/v1alpha3/virtualservices 2019-02-11T19:15:17.004531Z info mcp Watch(): created watch 1 for istio/networking/v1alpha3/virtualservices from group "default", version "" 2019-02-11T19:15:18.004255Z info mcp SetSnapshot(): respond to watch 1 for istio/networking/v1alpha3/virtualservices @ version "0_4" 2019-02-11T19:15:18.004675Z info mcp Watch(): created watch 2 for istio/networking/v1alpha3/virtualservices from group "default", version "0_4" 2019-02-11T19:15:18.005281Z info parsed scheme: "" 2019-02-11T19:15:18.005318Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:18.005330Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:18.005375Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:18.005416Z info mcp MCP: connection {addr=[::1]:41844 id=1}: CLOSED 2019-02-11T19:15:18.005434Z info mcp MCP: connection {addr=[::1]:41844 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:18.005424Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:18.005455Z info ccResolverWrapper: sending new addresses to cc: [{[::]:46259 0 }] 2019-02-11T19:15:18.005468Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:18.005451Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:18.005542Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42010e1c0, CONNECTING 2019-02-11T19:15:18.005541Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:15:18.005842Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42010e1c0, READY 2019-02-11T19:15:18.005881Z info mcp New MCP stream created 2019-02-11T19:15:18.006223Z info mcp MCP: connection {addr=[::1]:41846 id=2}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules"} 2019-02-11T19:15:18.006260Z info mcp MCP: connection {addr=[::1]:41846 id=2}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:18.006509Z info mcp Watch(): created watch 3 for istio/networking/v1alpha3/gateways from group "default", version "0_3" === RUN TestConversion/extensions_v1beta1_ingress_merge/extensions_v1beta1_ingress_merge_0 2019-02-11T19:15:18.006652Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:18.006765Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:18.007202Z info mcp MCP: connection {addr=[::1]:41846 id=2}: CLOSED 2019-02-11T19:15:18.007244Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:18.007251Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:18.007238Z info mcp MCP: connection {addr=[::1]:41846 id=2}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:18.007290Z info runtime Stopping processor... 2019-02-11T19:15:18.007622Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:18.007678Z info meshconfig Reloaded mesh config: ingressClass: cls ingressControllerMode: STRICT 2019-02-11T19:15:18.008667Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir659930671/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:18.008736Z info parsed scheme: "" 2019-02-11T19:15:18.008753Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:18.008991Z info runtime Starting processor... 2019-02-11T19:15:18.009137Z info parsed scheme: "" 2019-02-11T19:15:18.009155Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:18.009238Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:18.009275Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:18.009312Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4203b21d0, CONNECTING 2019-02-11T19:15:18.009305Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:18.009499Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4203b21d0, READY 2019-02-11T19:15:18.009549Z info mcp New MCP stream created 2019-02-11T19:15:18.009890Z info runtime Synchronization is complete, starting distribution. 2019-02-11T19:15:18.010037Z info mcp MCP: connection {addr=[::1]:36004 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:18.010107Z info mcp MCP: connection {addr=[::1]:36004 id=1}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:18.010114Z info mcp Watch(): created watch 1 for istio/networking/v1alpha3/gateways from group "default", version "" 2019-02-11T19:15:19.010419Z info mcp SetSnapshot(): respond to watch 1 for istio/networking/v1alpha3/gateways @ version "0_3" 2019-02-11T19:15:19.010935Z info mcp Watch(): created watch 2 for istio/networking/v1alpha3/gateways from group "default", version "0_3" 2019-02-11T19:15:19.011570Z info parsed scheme: "" 2019-02-11T19:15:19.011604Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:19.011625Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:19.011672Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.011694Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:19.011705Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:19.011868Z info mcp MCP: connection {addr=[::1]:36004 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:19.011716Z info mcp MCP: connection {addr=[::1]:36004 id=1}: CLOSED 2019-02-11T19:15:19.012320Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4209147b0, CONNECTING 2019-02-11T19:15:19.012353Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:19.012411Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.012562Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4209147b0, READY 2019-02-11T19:15:19.012615Z info mcp New MCP stream created 2019-02-11T19:15:19.013101Z info mcp MCP: connection {addr=[::1]:36006 id=2}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:19.013188Z info mcp MCP: connection {addr=[::1]:36006 id=2}: WATCH for istio/networking/v1alpha3/virtualservices 2019-02-11T19:15:19.013907Z info mcp Watch(): created watch 3 for istio/networking/v1alpha3/virtualservices from group "default", version "0_4" 2019-02-11T19:15:19.015072Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:19.015106Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.015223Z info mcp MCP: connection {addr=[::1]:36006 id=2}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:19.015252Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.015279Z info mcp MCP: connection {addr=[::1]:36006 id=2}: CLOSED 2019-02-11T19:15:19.015340Z info parsed scheme: "" 2019-02-11T19:15:19.015357Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:19.015387Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:19.015399Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:19.015426Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420aca330, CONNECTING 2019-02-11T19:15:19.015525Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:19.015670Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420aca330, READY 2019-02-11T19:15:19.015728Z info mcp New MCP stream created 2019-02-11T19:15:19.016145Z info mcp MCP: connection {addr=[::1]:36008 id=3}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:19.016184Z info mcp MCP: connection {addr=[::1]:36008 id=3}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:19.016426Z info mcp Watch(): created watch 4 for istio/networking/v1alpha3/gateways from group "default", version "0_3" 2019-02-11T19:15:19.016712Z info parsed scheme: "" 2019-02-11T19:15:19.016731Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:19.016752Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:19.016766Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:19.016806Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:19.016770Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.016839Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420a188e0, CONNECTING 2019-02-11T19:15:19.016851Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:19.016888Z info mcp MCP: connection {addr=[::1]:36008 id=3}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:19.016874Z info mcp MCP: connection {addr=[::1]:36008 id=3}: CLOSED 2019-02-11T19:15:19.016916Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:19.017020Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420a188e0, READY 2019-02-11T19:15:19.017053Z info mcp New MCP stream created 2019-02-11T19:15:19.017360Z info mcp MCP: connection {addr=[::1]:36010 id=4}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:19.017415Z info mcp MCP: connection {addr=[::1]:36010 id=4}: WATCH for istio/networking/v1alpha3/virtualservices 2019-02-11T19:15:19.017704Z info mcp Watch(): created watch 5 for istio/networking/v1alpha3/virtualservices from group "default", version "0_4" 2019-02-11T19:15:20.015894Z info mcp SetSnapshot(): respond to watch 5 for istio/networking/v1alpha3/virtualservices @ version "0_10" 2019-02-11T19:15:20.016321Z info mcp Watch(): created watch 6 for istio/networking/v1alpha3/virtualservices from group "default", version "0_10" === RUN TestConversion/extensions_v1beta1_ingress_merge/extensions_v1beta1_ingress_merge_1 2019-02-11T19:15:20.016587Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:20.016686Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:20.016742Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:20.016752Z info mcp MCP: connection {addr=[::1]:36010 id=4}: CLOSED 2019-02-11T19:15:20.016751Z info mcp MCP: connection {addr=[::1]:36010 id=4}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:20.016907Z info parsed scheme: "" 2019-02-11T19:15:20.016931Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:20.017049Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:20.017123Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:20.017186Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42089c100, CONNECTING 2019-02-11T19:15:20.017537Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42089c100, READY 2019-02-11T19:15:20.017208Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:20.017627Z info mcp New MCP stream created 2019-02-11T19:15:20.017967Z info mcp MCP: connection {addr=[::1]:36012 id=5}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:20.018008Z info mcp MCP: connection {addr=[::1]:36012 id=5}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:20.018259Z info mcp Watch(): created watch 7 for istio/networking/v1alpha3/gateways from group "default", version "0_9" 2019-02-11T19:15:20.019361Z info parsed scheme: "" 2019-02-11T19:15:20.019380Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:20.019396Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:20.019451Z info ccResolverWrapper: sending new addresses to cc: [{[::]:40367 0 }] 2019-02-11T19:15:20.019491Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:20.019496Z info mcp MCP: connection {addr=[::1]:36012 id=5}: CLOSED 2019-02-11T19:15:20.019452Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:20.019529Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42089c390, CONNECTING 2019-02-11T19:15:20.019532Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:20.019534Z info mcp MCP: connection {addr=[::1]:36012 id=5}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:20.019547Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:20.019825Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42089c390, READY 2019-02-11T19:15:20.019902Z info mcp New MCP stream created 2019-02-11T19:15:20.020556Z info mcp MCP: connection {addr=[::1]:36014 id=6}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers"} 2019-02-11T19:15:20.020616Z info mcp MCP: connection {addr=[::1]:36014 id=6}: WATCH for istio/networking/v1alpha3/virtualservices 2019-02-11T19:15:20.021357Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:20.021367Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" === RUN TestConversion/networking.istio.io_v1alpha3_destinationRule 2019-02-11T19:15:20.021766Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:20.021777Z info mcp MCP: connection {addr=[::1]:36014 id=6}: CLOSED 2019-02-11T19:15:20.021815Z info mcp MCP: connection {addr=[::1]:36014 id=6}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:20.021862Z info runtime Stopping processor... 2019-02-11T19:15:20.022379Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:20.022839Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir076894658/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir076894658/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:20.022880Z info parsed scheme: "" 2019-02-11T19:15:20.022887Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:20.022893Z info runtime Starting processor... 2019-02-11T19:15:20.023087Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/networking.istio.io_v1alpha3_destinationRule/networking.istio.io_v1alpha3_destinationRule 2019-02-11T19:15:24.024505Z info parsed scheme: "" 2019-02-11T19:15:24.024538Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:24.024710Z info ccResolverWrapper: sending new addresses to cc: [{[::]:45281 0 }] 2019-02-11T19:15:24.024734Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:24.024772Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:24.024898Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42043ed30, CONNECTING 2019-02-11T19:15:24.024908Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:15:24.025328Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42043ed30, READY 2019-02-11T19:15:24.025375Z info mcp New MCP stream created 2019-02-11T19:15:24.025639Z info mcp MCP: connection {addr=[::1]:34268 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests"} 2019-02-11T19:15:24.025735Z info mcp MCP: connection {addr=[::1]:34268 id=1}: WATCH for istio/networking/v1alpha3/destinationrules 2019-02-11T19:15:24.026162Z info mcp Watch(): created watch 1 for istio/networking/v1alpha3/destinationrules from group "default", version "0" 2019-02-11T19:15:25.025862Z info mcp SetSnapshot(): respond to watch 1 for istio/networking/v1alpha3/destinationrules @ version "1" 2019-02-11T19:15:25.026255Z info mcp Watch(): created watch 2 for istio/networking/v1alpha3/destinationrules from group "default", version "1" === RUN TestConversion/networking.istio.io_v1alpha3_gateway 2019-02-11T19:15:25.027669Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:25.027674Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:25.027813Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:25.027827Z info mcp MCP: connection {addr=[::1]:34268 id=1}: CLOSED 2019-02-11T19:15:25.027842Z info mcp MCP: connection {addr=[::1]:34268 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:25.027890Z info runtime Stopping processor... 2019-02-11T19:15:25.028384Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:25.028817Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir608624185/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir608624185/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:25.028850Z info parsed scheme: "" 2019-02-11T19:15:25.028863Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:25.028887Z info runtime Starting processor... 2019-02-11T19:15:25.029017Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/networking.istio.io_v1alpha3_gateway/networking.istio.io_v1alpha3_gateway 2019-02-11T19:15:29.030282Z info parsed scheme: "" 2019-02-11T19:15:29.030307Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:29.030417Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:29.030853Z info ccResolverWrapper: sending new addresses to cc: [{[::]:42729 0 }] 2019-02-11T19:15:29.031118Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:29.031210Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420964290, CONNECTING 2019-02-11T19:15:29.032252Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420964290, READY 2019-02-11T19:15:29.032327Z info mcp New MCP stream created 2019-02-11T19:15:29.033446Z info mcp MCP: connection {addr=[::1]:35118 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries"} 2019-02-11T19:15:29.033512Z info mcp MCP: connection {addr=[::1]:35118 id=1}: WATCH for istio/networking/v1alpha3/gateways 2019-02-11T19:15:29.033839Z info mcp Watch(): created watch 1 for istio/networking/v1alpha3/gateways from group "default", version "0" 2019-02-11T19:15:30.032556Z info mcp SetSnapshot(): respond to watch 1 for istio/networking/v1alpha3/gateways @ version "1" === RUN TestConversion/v1_endpoints 2019-02-11T19:15:30.033059Z info mcp Watch(): created watch 2 for istio/networking/v1alpha3/gateways from group "default", version "1" 2019-02-11T19:15:30.033144Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:30.033185Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:30.033250Z info mcp MCP: connection {addr=[::1]:35118 id=1}: CLOSED 2019-02-11T19:15:30.033300Z info mcp MCP: connection {addr=[::1]:35118 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:30.033309Z info runtime Stopping processor... 2019-02-11T19:15:30.033399Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:30.033940Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:30.034603Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir903965252/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir903965252/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:30.034647Z info parsed scheme: "" 2019-02-11T19:15:30.034667Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:30.034666Z info runtime Starting processor... 2019-02-11T19:15:30.035085Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/v1_endpoints/v1_endpoints 2019-02-11T19:15:34.036273Z info parsed scheme: "" 2019-02-11T19:15:34.036306Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:34.036430Z info ccResolverWrapper: sending new addresses to cc: [{[::]:46799 0 }] 2019-02-11T19:15:34.036497Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:34.036548Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4204803c0, CONNECTING 2019-02-11T19:15:34.036551Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:34.037030Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4204803c0, READY 2019-02-11T19:15:34.037098Z info mcp New MCP stream created 2019-02-11T19:15:34.037489Z info mcp MCP: connection {addr=[::1]:35798 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "k8s/core/v1/pods", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas"} 2019-02-11T19:15:34.037576Z info mcp MCP: connection {addr=[::1]:35798 id=1}: WATCH for k8s/core/v1/endpoints 2019-02-11T19:15:34.037939Z info mcp Watch(): created watch 1 for k8s/core/v1/endpoints from group "default", version "0" 2019-02-11T19:15:35.039062Z info mcp SetSnapshot(): respond to watch 1 for k8s/core/v1/endpoints @ version "1" 2019-02-11T19:15:35.039557Z info mcp Watch(): created watch 2 for k8s/core/v1/endpoints from group "default", version "1" === RUN TestConversion/v1_node 2019-02-11T19:15:35.041087Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:35.041149Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:35.041181Z info mcp MCP: connection {addr=[::1]:35798 id=1}: CLOSED 2019-02-11T19:15:35.041204Z info mcp MCP: connection {addr=[::1]:35798 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:35.041195Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:35.041234Z info runtime Stopping processor... 2019-02-11T19:15:35.041824Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:35.042328Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir536813267/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir536813267/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:35.042359Z info parsed scheme: "" 2019-02-11T19:15:35.042369Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:35.042401Z info runtime Starting processor... 2019-02-11T19:15:35.042530Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/v1_node/v1_node 2019-02-11T19:15:39.043895Z info parsed scheme: "" 2019-02-11T19:15:39.043933Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:39.044050Z info ccResolverWrapper: sending new addresses to cc: [{[::]:37163 0 }] 2019-02-11T19:15:39.044078Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:39.044157Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420214120, CONNECTING 2019-02-11T19:15:39.044179Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:39.044374Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420214120, READY 2019-02-11T19:15:39.044417Z info mcp New MCP stream created 2019-02-11T19:15:39.044936Z info mcp MCP: connection {addr=[::1]:39092 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/templates", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/bypasses", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/noops", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/logentries", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/quotas", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/edges", "istio/config/v1alpha2/legacy/listentries"} 2019-02-11T19:15:39.045032Z info mcp MCP: connection {addr=[::1]:39092 id=1}: WATCH for k8s/core/v1/nodes 2019-02-11T19:15:39.045329Z info mcp Watch(): created watch 1 for k8s/core/v1/nodes from group "default", version "0" 2019-02-11T19:15:40.106511Z info mcp SetSnapshot(): respond to watch 1 for k8s/core/v1/nodes @ version "1" 2019-02-11T19:15:40.107008Z info mcp Watch(): created watch 2 for k8s/core/v1/nodes from group "default", version "1" === RUN TestConversion/v1_pod 2019-02-11T19:15:40.108300Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:40.108353Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:40.108503Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:40.108535Z info mcp MCP: connection {addr=[::1]:39092 id=1}: CLOSED 2019-02-11T19:15:40.108560Z info mcp MCP: connection {addr=[::1]:39092 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:40.108622Z info runtime Stopping processor... 2019-02-11T19:15:40.109279Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:40.109980Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir610029590/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir610029590/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:40.110027Z info parsed scheme: "" 2019-02-11T19:15:40.110035Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:40.110097Z info runtime Starting processor... 2019-02-11T19:15:40.110325Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/v1_pod/v1_pod 2019-02-11T19:15:44.111989Z info parsed scheme: "" 2019-02-11T19:15:44.112025Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:44.112642Z info ccResolverWrapper: sending new addresses to cc: [{[::]:35777 0 }] 2019-02-11T19:15:44.112700Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:44.112939Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4208d4f30, CONNECTING 2019-02-11T19:15:44.113374Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4208d4f30, READY 2019-02-11T19:15:44.113526Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:44.113740Z info mcp New MCP stream created 2019-02-11T19:15:44.114513Z info mcp MCP: connection {addr=[::1]:59596 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings", "istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "k8s/extensions/v1beta1/ingresses", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "istio/networking/v1alpha3/serviceentries", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans"} 2019-02-11T19:15:44.114624Z info mcp MCP: connection {addr=[::1]:59596 id=1}: WATCH for k8s/core/v1/pods 2019-02-11T19:15:44.205714Z info mcp Watch(): created watch 1 for k8s/core/v1/pods from group "default", version "0" 2019-02-11T19:15:45.213744Z info mcp SetSnapshot(): respond to watch 1 for k8s/core/v1/pods @ version "1" 2019-02-11T19:15:45.214373Z info mcp Watch(): created watch 2 for k8s/core/v1/pods from group "default", version "1" 2019-02-11T19:15:45.221229Z error mcp Error receiving MCP response: rpc error: code = Unavailable desc = transport is closing 2019-02-11T19:15:45.221309Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:45.221305Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:45.221358Z info mcp MCP: connection {addr=[::1]:59596 id=1}: CLOSED === RUN TestConversion/v1_service 2019-02-11T19:15:45.221386Z info mcp MCP: connection {addr=[::1]:59596 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:45.221693Z info runtime Stopping processor... 2019-02-11T19:15:45.222335Z info meshconfig Reloaded mesh config: 2019-02-11T19:15:45.223005Z info tf Started Galley with args: KubeConfig: ResyncPeriod: 0s APIAddress: tcp://0.0.0.0:0 EnableGrpcTracing: false MaxReceivedMessageSize: 1048576 MaxConcurrentStreams: 1024 IntrospectionOptions: {Port:0 Address:127.0.0.1} Insecure: true AccessListFile: /etc/config/accesslist.yaml EnableServer: true KeyFile: /etc/certs/key.pem CertificateFile: /etc/certs/cert-chain.pem CACertificateFile: /etc/certs/root-cert.pem ConfigFilePath: /tmp/galley-conversion-test-8b523492/galley-workdir478546557/config MeshConfigFile: /tmp/galley-conversion-test-8b523492/galley-workdir478546557/mesh-config/meshconfig.yaml DomainSuffix: cluster.local DisableResourceReadyCheck: true ExcludedResourceKinds: [] SinkAddress: SinkAuthMode: 2019-02-11T19:15:45.223052Z info parsed scheme: "" 2019-02-11T19:15:45.223060Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:45.223087Z info runtime Starting processor... 2019-02-11T19:15:45.223263Z info runtime Synchronization is complete, starting distribution. === RUN TestConversion/v1_service/v1_service 2019-02-11T19:15:49.224502Z info parsed scheme: "" 2019-02-11T19:15:49.224533Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:15:49.224680Z info ccResolverWrapper: sending new addresses to cc: [{[::]:35525 0 }] 2019-02-11T19:15:49.224697Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:15:49.224738Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d590c0, CONNECTING 2019-02-11T19:15:49.224929Z info mcp (re)trying to establish new MCP stream 2019-02-11T19:15:49.225156Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d590c0, READY 2019-02-11T19:15:49.225257Z info mcp New MCP stream created 2019-02-11T19:15:49.225604Z info mcp MCP: connection {addr=[::1]:57440 id=1}: NEW (AggregatedMeshConfigService) supported collections: []string{"istio/config/v1alpha2/httpapispecbindings", "istio/config/v1alpha2/legacy/authorizations", "istio/config/v1alpha2/legacy/dogstatsds", "istio/config/v1alpha2/legacy/fluentds", "istio/config/v1alpha2/legacy/stdios", "istio/authentication/v1alpha1/meshpolicies", "istio/config/v1alpha2/legacy/prometheuses", "istio/policy/v1beta1/instances", "k8s/core/v1/pods", "istio/config/v1alpha2/legacy/kubernetesenvs", "istio/config/v1alpha2/legacy/metrics", "istio/config/v1alpha2/legacy/statsds", "istio/rbac/v1alpha1/clusterrbacconfigs", "k8s/core/v1/endpoints", "istio/config/v1alpha2/legacy/edges", "istio/rbac/v1alpha1/servicerolebindings", "istio/config/v1alpha2/legacy/listentries", "istio/config/v1alpha2/templates", "istio/mixer/v1/config/client/quotaspecbindings", "istio/networking/v1alpha3/virtualservices", "istio/policy/v1beta1/rules", "istio/rbac/v1alpha1/rbacconfigs", "istio/config/v1alpha2/httpapispecs", "istio/config/v1alpha2/legacy/apikeys", "istio/config/v1alpha2/legacy/listcheckers", "istio/config/v1alpha2/legacy/zipkins", "istio/policy/v1beta1/attributemanifests", "k8s/extensions/v1beta1/ingresses", "k8s/core/v1/nodes", "istio/authentication/v1alpha1/policies", "istio/config/v1alpha2/legacy/checknothings", "istio/config/v1alpha2/legacy/solarwindses", "istio/networking/v1alpha3/envoyfilters", "istio/networking/v1alpha3/gateways", "istio/networking/v1alpha3/serviceentries", "istio/config/v1alpha2/legacy/deniers", "istio/config/v1alpha2/legacy/kuberneteses", "istio/config/v1alpha2/legacy/signalfxs", "istio/config/v1alpha2/legacy/bypasses", "istio/config/v1alpha2/legacy/rbacs", "istio/config/v1alpha2/legacy/stackdrivers", "istio/networking/v1alpha3/destinationrules", "istio/config/v1alpha2/legacy/noops", "istio/networking/v1alpha3/sidecars", "istio/config/v1alpha2/legacy/logentries", "istio/mixer/v1/config/client/quotaspecs", "k8s/core/v1/services", "istio/config/v1alpha2/legacy/quotas", "istio/policy/v1beta1/handlers", "istio/config/v1alpha2/legacy/circonuses", "istio/config/v1alpha2/legacy/redisquotas", "istio/config/v1alpha2/legacy/tracespans", "istio/config/v1alpha2/legacy/cloudwatches", "istio/config/v1alpha2/legacy/memquotas", "istio/config/v1alpha2/legacy/opas", "istio/rbac/v1alpha1/serviceroles", "istio/config/v1alpha2/adapters", "istio/config/v1alpha2/legacy/reportnothings"} 2019-02-11T19:15:49.225669Z info mcp MCP: connection {addr=[::1]:57440 id=1}: WATCH for k8s/core/v1/services 2019-02-11T19:15:49.225940Z info mcp Watch(): created watch 1 for k8s/core/v1/services from group "default", version "0" 2019-02-11T19:15:50.226684Z info mcp SetSnapshot(): respond to watch 1 for k8s/core/v1/services @ version "1" 2019-02-11T19:15:50.227141Z info mcp Watch(): created watch 2 for k8s/core/v1/services from group "default", version "1" --- PASS: TestConversion (47.25s) --- PASS: TestConversion/config.istio.io_v1alpha2_circonus (5.01s) --- PASS: TestConversion/config.istio.io_v1alpha2_circonus/config.istio.io_v1alpha2_circonus (1.01s) --- PASS: TestConversion/extensions_v1beta1_ingress_basic (5.01s) --- PASS: TestConversion/extensions_v1beta1_ingress_basic/extensions_v1beta1_ingress_basic (1.01s) --- PASS: TestConversion/extensions_v1beta1_ingress_merge (7.02s) --- PASS: TestConversion/extensions_v1beta1_ingress_merge/extensions_v1beta1_ingress_merge_0 (1.01s) --- PASS: TestConversion/extensions_v1beta1_ingress_merge/extensions_v1beta1_ingress_merge_1 (0.00s) --- PASS: TestConversion/networking.istio.io_v1alpha3_destinationRule (5.01s) --- PASS: TestConversion/networking.istio.io_v1alpha3_destinationRule/networking.istio.io_v1alpha3_destinationRule (1.00s) --- PASS: TestConversion/networking.istio.io_v1alpha3_gateway (5.01s) --- PASS: TestConversion/networking.istio.io_v1alpha3_gateway/networking.istio.io_v1alpha3_gateway (1.00s) --- PASS: TestConversion/v1_endpoints (5.01s) --- PASS: TestConversion/v1_endpoints/v1_endpoints (1.01s) --- PASS: TestConversion/v1_node (5.07s) --- PASS: TestConversion/v1_node/v1_node (1.06s) --- PASS: TestConversion/v1_pod (5.11s) --- PASS: TestConversion/v1_pod/v1_pod (1.11s) --- PASS: TestConversion/v1_service (5.01s) --- PASS: TestConversion/v1_service/v1_service (1.00s) PASS 2019-02-11T19:15:50.228068Z error mcp Error receiving MCP response: rpc error: code = Canceled desc = context canceled 2019-02-11T19:15:50.228110Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:50.228174Z info mcp MCP: connection {addr=[::1]:57440 id=1}: CLOSED 2019-02-11T19:15:50.228234Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:15:50.228166Z info mcp MCP: connection {addr=[::1]:57440 id=1}: TERMINATED "rpc error: code = Canceled desc = context canceled" 2019-02-11T19:15:50.228450Z info runtime Stopping processor... ok istio.io/istio/tests/integration2/galley/conversion 47.639s 2019-02-11T19:15:54.897886Z info CI Test Framework runtime settings: Environment: native TestID: galley_validation_test RunID: galley-validation-test-7f6bb254 NoCleanup: false WorkDir: /tmp/galley-validation-test-7f6bb254 === RUN TestValidation --- SKIP: TestValidation (1.00s) validation_test.go:65: Missing requirement: unknown component `environment(kubernetes)` PASS ok istio.io/istio/tests/integration2/galley/validation 1.360s 2019-02-11T19:16:00.047214Z info CI Test Framework runtime settings: Environment: native TestID: mixer_test RunID: mixer-test-ddb055d1c55341509acd NoCleanup: false WorkDir: /tmp/mixer-test-ddb055d1c55341509acd === RUN TestCheck_Allow 2019-02-11T19:16:06.359236Z info Awaiting for config store sync... 2019-02-11T19:16:06.359287Z info Starting runtime config watch... 2019-02-11T19:16:06.359353Z info Built new config.Snapshot: id='0' 2019-02-11T19:16:06.359367Z info Cleaning up handler table, with config ID:-1 2019-02-11T19:16:06.359406Z info Built new config.Snapshot: id='1' 2019-02-11T19:16:06.359420Z info Cleaning up handler table, with config ID:0 2019-02-11T19:16:06.359576Z info Starting monitor server... 2019-02-11T19:16:06.362353Z info parsed scheme: "" 2019-02-11T19:16:06.362376Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:06.362512Z info fakes Starting Policy Backend 2019-02-11T19:16:06.362538Z info ControlZ available at 10.44.67.141:9876 2019-02-11T19:16:06.362570Z info parsed scheme: "" 2019-02-11T19:16:06.362593Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:06.362576Z info fakes Starting the GRPC service at port: 39947 2019-02-11T19:16:06.362595Z info ccResolverWrapper: sending new addresses to cc: [{[::]:36075 0 }] 2019-02-11T19:16:06.362629Z info ClientConn switching balancer to "pick_first" NM: apiVersion: "config.istio.io/v1alpha2" kind: checknothing metadata: name: checknothing1 namespace: istio-system spec: --- apiVersion: "config.istio.io/v1alpha2" kind: rule metadata: name: rule1 namespace: istio-system spec: actions: - handler: handler1.bypass instances: - checknothing1.checknothing --- apiVersion: "config.istio.io/v1alpha2" kind: bypass metadata: name: handler1 namespace: istio-system spec: backend_address: 127.0.0.1:39947 2019-02-11T19:16:06.362724Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420096d20, CONNECTING 2019-02-11T19:16:06.362758Z info ccResolverWrapper: sending new addresses to cc: [{:39947 0 }] 2019-02-11T19:16:06.362815Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:06.362880Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420484230, CONNECTING 2019-02-11T19:16:06.363046Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420096d20, READY 2019-02-11T19:16:06.363114Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420484230, READY 2019-02-11T19:16:07.861387Z info Publishing 4 events 2019-02-11T19:16:07.861573Z info Built new config.Snapshot: id='2' 2019-02-11T19:16:07.861685Z info parsed scheme: "" 2019-02-11T19:16:07.861749Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:07.861868Z info Cleaning up handler table, with config ID:1 2019-02-11T19:16:07.861944Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:39947 0 }] 2019-02-11T19:16:07.861996Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:07.862072Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4206e80b0, CONNECTING 2019-02-11T19:16:07.862428Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4206e80b0, READY 2019-02-11T19:16:09.363462Z info fakes Backend.Set denyCheck = false NM: response.time NM: request.time NM: destination.service NM: svc.istio-system NM: origin.ip NM: context.protocol NM: http NM: destination.name NM: somesrvcname NM: destination.namespace NM: istio-system 2019-02-11T19:16:09.364429Z info fakes Backend.HandleCheckNothing &HandleCheckNothingRequest{Instance:&InstanceMsg{Name:checknothing1.checknothing.istio-system,},AdapterConfig:nil,DedupId:51e75fa5-276f-4f30-b7b1-6e9c6aa896b0,} --- PASS: TestCheck_Allow (9.32s) === RUN TestCheck_Deny 2019-02-11T19:16:09.365280Z info fakes Backend.Reset NM: apiVersion: "config.istio.io/v1alpha2" kind: checknothing metadata: name: checknothing1 namespace: istio-system spec: --- apiVersion: "config.istio.io/v1alpha2" kind: rule metadata: name: rule1 namespace: istio-system spec: actions: - handler: handler1.bypass instances: - checknothing1.checknothing --- apiVersion: "config.istio.io/v1alpha2" kind: bypass metadata: name: handler1 namespace: istio-system spec: backend_address: 127.0.0.1:39947 2019-02-11T19:16:15.367022Z info fakes Backend.Set denyCheck = true NM: context.protocol NM: http NM: destination.name NM: somesrvcname NM: destination.namespace NM: istio-system NM: response.time NM: request.time NM: destination.service NM: svc.istio-system NM: origin.ip 2019-02-11T19:16:15.368297Z info fakes Backend.HandleCheckNothing &HandleCheckNothingRequest{Instance:&InstanceMsg{Name:checknothing1.checknothing.istio-system,},AdapterConfig:nil,DedupId:b0a4479c-b414-4f12-b3d1-5b13dd353236,} --- PASS: TestCheck_Deny (6.00s) === RUN TestMixer_Report_Direct 2019-02-11T19:16:15.368891Z info fakes Backend.Reset NM: apiVersion: "config.istio.io/v1alpha2" kind: metric metadata: name: metric1 namespace: istio-system spec: value: "2" dimensions: target_port: destination.port | 9696 origin_ip: origin.ip | ip("4.5.6.7") --- apiVersion: "config.istio.io/v1alpha2" kind: rule metadata: name: rule1 namespace: istio-system spec: actions: - handler: handler1.bypass instances: - metric1.metric --- apiVersion: "config.istio.io/v1alpha2" kind: bypass metadata: name: handler1 namespace: istio-system spec: backend_address: 127.0.0.1:39947 2019-02-11T19:16:19.861175Z info Publishing 3 events 2019-02-11T19:16:19.861402Z info Built new config.Snapshot: id='3' 2019-02-11T19:16:19.861487Z info parsed scheme: "" 2019-02-11T19:16:19.861562Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:19.861709Z info Cleaning up handler table, with config ID:2 2019-02-11T19:16:19.861743Z info adapters adapter closed all scheduled daemons and workers {"adapter": "handler1.bypass.istio-system"} 2019-02-11T19:16:19.861773Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:19.861765Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:39947 0 }] 2019-02-11T19:16:19.861851Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:19.861986Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:19.862068Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d78310, CONNECTING 2019-02-11T19:16:19.862511Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d78310, READY NM: request.time NM: destination.service NM: svc.istio-system NM: destination.port NM: origin.ip NM: context.protocol NM: http NM: destination.name NM: somesrvcname NM: destination.namespace NM: istio-system NM: response.time 2019-02-11T19:16:21.371541Z info fakes Backend.HandleMetric &HandleMetricRequest{Instances:[&InstanceMsg{Value:&istio_policy_v1beta11.Value{Value:&Value_Int64Value{Int64Value:2,},},Dimensions:map[string]*istio_policy_v1beta11.Value{origin_ip: &Value{Value:&Value_IpAddressValue{IpAddressValue:&IPAddress{Value:[1 2 3 4],},},},target_port: &Value{Value:&Value_Int64Value{Int64Value:7678,},},},MonitoredResourceType:,MonitoredResourceDimensions:map[string]*istio_policy_v1beta11.Value{},Name:metric1.metric.istio-system,}],AdapterConfig:nil,DedupId:3d274dc0-cc1d-409a-899c-e3e8df549242,} NM: { "name": "metric1.metric.istio-system", "value": { "int64Value": "2" }, "dimensions": { "origin_ip": { "ipAddressValue": { "value": "AQIDBA==" } }, "target_port": { "int64Value": "7678" } } } --- PASS: TestMixer_Report_Direct (6.00s) === RUN TestIngessToPrometheus_ServiceMetric 2019-02-11T19:16:21.373089Z info fakes Backend.Reset --- SKIP: TestIngessToPrometheus_ServiceMetric (0.00s) scenarios_test.go:37: Missing requirement: unknown component `prometheus` === RUN TestIngessToPrometheus_IngressMetric 2019-02-11T19:16:21.373464Z info fakes Backend.Reset --- SKIP: TestIngessToPrometheus_IngressMetric (0.00s) scenarios_test.go:47: Missing requirement: unknown component `prometheus` === RUN TestTcpMetric --- SKIP: TestTcpMetric (0.00s) scenarios_test.go:107: https://github.com/istio/istio/issues/11430 PASS 2019-02-11T19:16:21.373628Z info fakes Backend.Close 2019-02-11T19:16:21.373711Z info transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:39947->127.0.0.1:34562: use of closed network connection 2019-02-11T19:16:21.373735Z info transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:39947->127.0.0.1:34572: use of closed network connection 2019-02-11T19:16:21.373773Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.404871Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.404904Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.405017Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.405046Z info ControlZ terminated 2019-02-11T19:16:21.405061Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.405054Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:21.405083Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d78310, TRANSIENT_FAILURE 2019-02-11T19:16:21.405210Z info grpc: addrConn.createTransport failed to connect to {:39947 0 }. Err :connection error: desc = "transport: Error while dialing dial tcp :39947: connect: connection refused". Reconnecting... 2019-02-11T19:16:21.405126Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420484230, TRANSIENT_FAILURE 2019-02-11T19:16:21.405238Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420484230, CONNECTING 2019-02-11T19:16:21.405249Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420484230, TRANSIENT_FAILURE 2019-02-11T19:16:21.405693Z info grpc: addrConn.createTransport failed to connect to {127.0.0.1:39947 0 }. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:39947: connect: connection refused". Reconnecting... 2019-02-11T19:16:21.405227Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d78310, CONNECTING 2019-02-11T19:16:21.406139Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420d78310, TRANSIENT_FAILURE ok istio.io/istio/tests/integration2/mixer 21.719s # istio.io/istio/tests/integration2/pilot tests/integration2/pilot/sidecar_api_test.go:45:12: unknown field 'DNSDomain' in struct literal of type "istio.io/istio/pilot/pkg/model".Proxy FAIL istio.io/istio/tests/integration2/pilot [build failed] 2019-02-11T19:16:26.193628Z info CI Test Framework runtime settings: Environment: native TestID: authn_permissive_test RunID: authn-permissive-test-f43817f15 NoCleanup: false WorkDir: /tmp/authn-permissive-test-f43817f15 === RUN TestAuthnPermissive 2019-02-11T19:16:33.583361Z info Awaiting for config store sync... 2019-02-11T19:16:33.583396Z info Starting runtime config watch... 2019-02-11T19:16:33.583460Z info Built new config.Snapshot: id='0' 2019-02-11T19:16:33.583474Z info Cleaning up handler table, with config ID:-1 2019-02-11T19:16:33.583517Z info Built new config.Snapshot: id='1' 2019-02-11T19:16:33.583537Z info Cleaning up handler table, with config ID:0 2019-02-11T19:16:33.583734Z info Starting monitor server... 2019-02-11T19:16:33.586816Z info parsed scheme: "" 2019-02-11T19:16:33.586875Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:33.587028Z info mesh networks configuration not provided 2019-02-11T19:16:33.587029Z info ControlZ available at 10.44.67.141:9876 2019-02-11T19:16:33.587060Z info ccResolverWrapper: sending new addresses to cc: [{[::]:34243 0 }] 2019-02-11T19:16:33.587078Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:33.587131Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4200968f0, CONNECTING 2019-02-11T19:16:33.587163Z info ads Starting ADS server with rateLimiter=10 burst=100 2019-02-11T19:16:33.587228Z info parsed scheme: "" 2019-02-11T19:16:33.587236Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:33.587266Z info ccResolverWrapper: sending new addresses to cc: [{[::]:33789 0 }] 2019-02-11T19:16:33.587271Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:33.587294Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42048dbc0, CONNECTING 2019-02-11T19:16:33.587319Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4200968f0, READY 2019-02-11T19:16:33.587306Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:16:33.587579Z info pickfirstBalancer: HandleSubConnStateChange: 0xc42048dbc0, READY 2019-02-11T19:16:33.587640Z info starting discovery service at http=[::]:40887 grpc=[::]:33789 Listening HTTP/1.1 on 40763 Listening HTTP/1.1 on 34179 Listening HTTP/1.1 on 40475 Listening HTTP/1.1 on 36287 Listening GRPC on 39385 Listening GRPC on 46301 2019-02-11T19:16:33.687927Z info ads Push debounce stable[1] 3: 100.048686ms since last change, 100.099974ms since last push, full=true 2019-02-11T19:16:33.688249Z info ads XDS: Pushing 2019-02-11T19:16:33Z/0 Services: 1, ConnectedEndpoints: 0 2019-02-11T19:16:33.688271Z info ads Cluster init time 433ns 2019-02-11T19:16:33Z/0 2019-02-11T19:16:33.688275Z info ads PushAll done 2019-02-11T19:16:33Z/0 170ns 2019-02-11T19:16:36.186396Z info Failed to export to Prometheus: cannot register the collector: duplicate metrics collector registration attempted 2019-02-11T19:16:37.317084Z info parsed scheme: "" 2019-02-11T19:16:37.317121Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:37.317296Z info ccResolverWrapper: sending new addresses to cc: [{[::]:33789 0 }] 2019-02-11T19:16:37.317329Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:37.317396Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420287140, CONNECTING 2019-02-11T19:16:37.317635Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420287140, READY 2019-02-11T19:16:37.318322Z info ads ADS:CDS: REQ [::1]:40022 sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 107.325µs raw: node: type_url:"type.googleapis.com/envoy.api.v2.Cluster" 2019-02-11T19:16:37.318520Z info ads CDS: PUSH 2019-02-11T19:16:33Z/0 for sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 "[::1]:40022", Clusters: 6, Services 1 2019-02-11T19:16:37.329194Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420b73f80 0} 2019-02-11T19:16:37.333357Z info ads LDS: PUSH for node:a.8pxMwZjI0T addr:"[::1]:40022" listeners:5 4688 2019-02-11T19:16:37.344083Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:1 2019-02-11T19:16:37.365630Z info parsed scheme: "" 2019-02-11T19:16:37.365666Z info scheme "" not registered, fallback to default scheme Listening HTTP/1.1 on 38163 Listening HTTP/1.1 on 39993 Listening HTTP/1.1 on 44125 Listening HTTP/1.1 on 42591 2019-02-11T19:16:37.365811Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:46301 0 }] Listening GRPC on 36033 2019-02-11T19:16:37.365854Z info ClientConn switching balancer to "pick_first" Listening GRPC on 34547 2019-02-11T19:16:37.365933Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420ecca50, CONNECTING 2019-02-11T19:16:37.366403Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420ecca50, READY 2019-02-11T19:16:37.432009Z info parsed scheme: "" 2019-02-11T19:16:37.432040Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:37.432107Z info ccResolverWrapper: sending new addresses to cc: [{[::]:33789 0 }] 2019-02-11T19:16:37.432114Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:37.432162Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420f9e2d0, CONNECTING 2019-02-11T19:16:37.432210Z info blockingPicker: the picked transport is not ready, loop back to repick 2019-02-11T19:16:37.432403Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420f9e2d0, READY 2019-02-11T19:16:37.432937Z info ads ADS:CDS: REQ [::1]:40032 sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 212.713µs raw: node: type_url:"type.googleapis.com/envoy.api.v2.Cluster" 2019-02-11T19:16:37.433198Z info ads CDS: PUSH 2019-02-11T19:16:33Z/0 for sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 "[::1]:40032", Clusters: 12, Services 1 2019-02-11T19:16:37.452046Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420e55830 0} 2019-02-11T19:16:37.453797Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420e559e0 0} 2019-02-11T19:16:37.456199Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420e55a10 0} 2019-02-11T19:16:37.459538Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420e55a40 0} 2019-02-11T19:16:37.460436Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420e55a70 0} 2019-02-11T19:16:37.460862Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420e55aa0 0} 2019-02-11T19:16:37.462349Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420e55ad0 0} 2019-02-11T19:16:37.465972Z info ads LDS: PUSH for node:b.nhfiTPZnp6 addr:"[::1]:40032" listeners:11 15198 2019-02-11T19:16:37.465956Z info ads Push debounce stable[2] 8: 100.009172ms since last change, 100.100087ms since last push, full=true 2019-02-11T19:16:37.466494Z info ads XDS: Pushing 2019-02-11T19:16:37Z/1 Services: 2, ConnectedEndpoints: 2 2019-02-11T19:16:37.466546Z info ads Cluster init time 23.53µs 2019-02-11T19:16:37Z/1 2019-02-11T19:16:37.466596Z info ads Pushing sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 2019-02-11T19:16:37.466676Z info ads PushAll done 2019-02-11T19:16:37Z/1 121.234µs 2019-02-11T19:16:37.466701Z info ads Pushing sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 2019-02-11T19:16:37.467033Z info ads CDS: PUSH 2019-02-11T19:16:37Z/1 for sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 "[::1]:40022", Clusters: 18, Services 2 2019-02-11T19:16:37.467033Z info ads CDS: PUSH 2019-02-11T19:16:37Z/1 for sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 "[::1]:40032", Clusters: 18, Services 2 2019-02-11T19:16:37.467457Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420e55830 0} 2019-02-11T19:16:37.467458Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420e55830 0} 2019-02-11T19:16:37.469222Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420e559e0 0} 2019-02-11T19:16:37.470704Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420e559e0 0} 2019-02-11T19:16:37.471073Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420e55a10 0} 2019-02-11T19:16:37.473396Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420e55a40 0} 2019-02-11T19:16:37.473805Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420e55a10 0} 2019-02-11T19:16:37.473960Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420e55a70 0} 2019-02-11T19:16:37.474409Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420e55aa0 0} 2019-02-11T19:16:37.475610Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420e55a40 0} 2019-02-11T19:16:37.476125Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420e55a70 0} 2019-02-11T19:16:37.476288Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420e55ad0 0} 2019-02-11T19:16:37.476560Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420e55aa0 0} 2019-02-11T19:16:37.482675Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420e55ad0 0} 2019-02-11T19:16:37.488897Z info ads LDS: PUSH for node:b.nhfiTPZnp6 addr:"[::1]:40032" listeners:17 23932 2019-02-11T19:16:37.489373Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:1 2019-02-11T19:16:37.495645Z info ads LDS: PUSH for node:a.8pxMwZjI0T addr:"[::1]:40022" listeners:17 23932 2019-02-11T19:16:37.496086Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:1 2019-02-11T19:16:37.496213Z info ads Push finished: 30.156344ms { "ProxyStatus": {}, "Start": "2019-02-11T19:16:37.466052512Z", "End": "2019-02-11T19:16:37.496108434Z" } 2019-02-11T19:16:37.531589Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:5 2019-02-11T19:16:37.540938Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:5 2019-02-11T19:16:37.575015Z info parsed scheme: "" 2019-02-11T19:16:37.575068Z info scheme "" not registered, fallback to default scheme Listening HTTP/1.1 on 36117 Listening HTTP/1.1 on 42301 Listening HTTP/1.1 on 44897 Listening HTTP/1.1 on 37967 Listening GRPC on 43393 Listening GRPC on 43209 2019-02-11T19:16:37.575244Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:34547 0 }] 2019-02-11T19:16:37.575400Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:37.575464Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4202db9a0, CONNECTING 2019-02-11T19:16:37.575873Z info pickfirstBalancer: HandleSubConnStateChange: 0xc4202db9a0, READY 2019-02-11T19:16:37.651915Z info parsed scheme: "" 2019-02-11T19:16:37.651946Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:37.652003Z info ccResolverWrapper: sending new addresses to cc: [{[::]:33789 0 }] 2019-02-11T19:16:37.652011Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:37.652052Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420ecd510, CONNECTING 2019-02-11T19:16:37.652544Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420ecd510, READY 2019-02-11T19:16:37.652997Z info ads ADS:CDS: REQ [::1]:40042 sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 136.2µs raw: node: type_url:"type.googleapis.com/envoy.api.v2.Cluster" 2019-02-11T19:16:37.653270Z info ads CDS: PUSH 2019-02-11T19:16:37Z/1 for sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 "[::1]:40042", Clusters: 24, Services 2 2019-02-11T19:16:37.675398Z info ads Push debounce stable[3] 8: 100.130931ms since last change, 100.140393ms since last push, full=true 2019-02-11T19:16:37.675737Z info ads XDS: Pushing 2019-02-11T19:16:37Z/2 Services: 3, ConnectedEndpoints: 3 2019-02-11T19:16:37.675847Z info ads Cluster init time 85.448µs 2019-02-11T19:16:37Z/2 2019-02-11T19:16:37.675899Z info ads Pushing sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 2019-02-11T19:16:37.675914Z info ads PushAll done 2019-02-11T19:16:37Z/2 51.626µs 2019-02-11T19:16:37.675902Z info ads Pushing sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 2019-02-11T19:16:37.675922Z info ads Pushing sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 2019-02-11T19:16:37.676202Z info ads CDS: PUSH 2019-02-11T19:16:37Z/2 for sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 "[::1]:40042", Clusters: 30, Services 3 2019-02-11T19:16:37.676223Z info ads CDS: PUSH 2019-02-11T19:16:37Z/2 for sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 "[::1]:40032", Clusters: 30, Services 3 2019-02-11T19:16:37.676347Z info ads CDS: PUSH 2019-02-11T19:16:37Z/2 for sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 "[::1]:40022", Clusters: 30, Services 3 2019-02-11T19:16:37.676449Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc4211ca120 0} 2019-02-11T19:16:37.676643Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc4211ca120 0} 2019-02-11T19:16:37.678073Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc4211ca2d0 0} 2019-02-11T19:16:37.678385Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc4211ca2d0 0} 2019-02-11T19:16:37.679543Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc4211ca300 0} 2019-02-11T19:16:37.679889Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc4211ca300 0} 2019-02-11T19:16:37.682630Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc4211ca330 0} 2019-02-11T19:16:37.683643Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc4211ca360 0} 2019-02-11T19:16:37.684114Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc4211ca390 0} 2019-02-11T19:16:37.685345Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc4211ca330 0} 2019-02-11T19:16:37.685833Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc4211ca360 0} 2019-02-11T19:16:37.686435Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc4211ca390 0} 2019-02-11T19:16:37.686619Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc4211ca3c0 0} 2019-02-11T19:16:37.688607Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc4211ca3c0 0} 2019-02-11T19:16:37.689322Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc4211ca570 0} 2019-02-11T19:16:37.691530Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc4211ca570 0} 2019-02-11T19:16:37.692477Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc4211ca5a0 0} 2019-02-11T19:16:37.693198Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc4211ca120 0} 2019-02-11T19:16:37.693256Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc4211ca5a0 0} 2019-02-11T19:16:37.694019Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc4211ca5d0 0} 2019-02-11T19:16:37.694401Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc4211ca600 0} 2019-02-11T19:16:37.694772Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc4211ca2d0 0} 2019-02-11T19:16:37.694825Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc4211ca630 0} 2019-02-11T19:16:37.694827Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc4211ca5d0 0} 2019-02-11T19:16:37.695254Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc4211ca600 0} 2019-02-11T19:16:37.695640Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc4211ca630 0} 2019-02-11T19:16:37.696275Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc4211ca300 0} 2019-02-11T19:16:37.696634Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc4211ca660 0} 2019-02-11T19:16:37.697177Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc4211ca660 0} 2019-02-11T19:16:37.697608Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc4211ca330 0} 2019-02-11T19:16:37.697975Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc4211ca360 0} 2019-02-11T19:16:37.698319Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc4211ca390 0} 2019-02-11T19:16:37.699592Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc4211ca3c0 0} 2019-02-11T19:16:37.701420Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc4211ca570 0} 2019-02-11T19:16:37.703464Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc4211ca5a0 0} 2019-02-11T19:16:37.708515Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc4211ca5d0 0} 2019-02-11T19:16:37.708977Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc4211ca600 0} 2019-02-11T19:16:37.709422Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc4211ca630 0} 2019-02-11T19:16:37.710944Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc4211ca660 0} 2019-02-11T19:16:37.715619Z info ads LDS: PUSH for node:a.8pxMwZjI0T addr:"[::1]:40022" listeners:29 43176 2019-02-11T19:16:37.716733Z info ads LDS: PUSH for node:b.nhfiTPZnp6 addr:"[::1]:40032" listeners:29 43176 2019-02-11T19:16:37.717143Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:5 2019-02-11T19:16:37.720079Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:5 2019-02-11T19:16:37.720340Z info ads Push finished: 44.898823ms { "ProxyStatus": {}, "Start": "2019-02-11T19:16:37.675435981Z", "End": "2019-02-11T19:16:37.720300609Z" } 2019-02-11T19:16:37.727892Z info ads LDS: PUSH for node:c.AlhAId3-_E addr:"[::1]:40042" listeners:29 43176 2019-02-11T19:16:37.772210Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:9 2019-02-11T19:16:37.772883Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:9 2019-02-11T19:16:37.805998Z info ads ADS: RDS: PUSH for node: c.AlhAId3-_E addr:[::1]:40042 routes:9 2019-02-11T19:16:37.905553Z info parsed scheme: "" 2019-02-11T19:16:37.905609Z info scheme "" not registered, fallback to default scheme 2019-02-11T19:16:37.905758Z info ccResolverWrapper: sending new addresses to cc: [{127.0.0.1:43209 0 }] 2019-02-11T19:16:37.905831Z info ClientConn switching balancer to "pick_first" 2019-02-11T19:16:37.905877Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420122910, CONNECTING 2019-02-11T19:16:37.906393Z info pickfirstBalancer: HandleSubConnStateChange: 0xc420122910, READY 2019-02-11T19:16:38.005909Z info ads Push debounce stable[4] 8: 100.118003ms since last change, 100.138085ms since last push, full=true 2019-02-11T19:16:38.006488Z info ads XDS: Pushing 2019-02-11T19:16:38Z/3 Services: 4, ConnectedEndpoints: 3 2019-02-11T19:16:38.006629Z info ads Cluster init time 106.616µs 2019-02-11T19:16:38Z/3 2019-02-11T19:16:38.006722Z info ads Pushing sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 2019-02-11T19:16:38.006749Z info ads Pushing sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 2019-02-11T19:16:38.006761Z info ads PushAll done 2019-02-11T19:16:38Z/3 92.929µs 2019-02-11T19:16:38.006859Z info ads Pushing sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 2019-02-11T19:16:38.007094Z info ads CDS: PUSH 2019-02-11T19:16:38Z/3 for sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 "[::1]:40022", Clusters: 42, Services 4 2019-02-11T19:16:38.007197Z info ads CDS: PUSH 2019-02-11T19:16:38Z/3 for sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 "[::1]:40042", Clusters: 42, Services 4 2019-02-11T19:16:38.007305Z info ads CDS: PUSH 2019-02-11T19:16:38Z/3 for sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 "[::1]:40032", Clusters: 42, Services 4 2019-02-11T19:16:38.007399Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420fe1380 0} 2019-02-11T19:16:38.007694Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420fe1380 0} 2019-02-11T19:16:38.008013Z info Use default filter chain for {tcp 127.0.0.1 34243 0xc420fe1380 0} 2019-02-11T19:16:38.009442Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420fe1530 0} 2019-02-11T19:16:38.010273Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420fe1530 0} 2019-02-11T19:16:38.010529Z info Use default filter chain for {tcp 127.0.0.1 42885 0xc420fe1530 0} 2019-02-11T19:16:38.010981Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420fe1560 0} 2019-02-11T19:16:38.012407Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420fe1590 0} 2019-02-11T19:16:38.012741Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420fe1560 0} 2019-02-11T19:16:38.012815Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420fe15c0 0} 2019-02-11T19:16:38.012922Z info Use default filter chain for {tcp 127.0.0.1 44855 0xc420fe1560 0} 2019-02-11T19:16:38.013164Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420fe15f0 0} 2019-02-11T19:16:38.014759Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420fe1620 0} 2019-02-11T19:16:38.015066Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420fe1590 0} 2019-02-11T19:16:38.015331Z info Use default filter chain for {tcp 127.0.0.1 46281 0xc420fe1590 0} 2019-02-11T19:16:38.015638Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420fe15c0 0} 2019-02-11T19:16:38.015907Z info Use default filter chain for {tcp 127.0.0.1 36607 0xc420fe15c0 0} 2019-02-11T19:16:38.016243Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420fe15f0 0} 2019-02-11T19:16:38.016489Z info Use default filter chain for {tcp 127.0.0.1 42389 0xc420fe15f0 0} 2019-02-11T19:16:38.016560Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc420fe17d0 0} 2019-02-11T19:16:38.018031Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc420fe1800 0} 2019-02-11T19:16:38.018989Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420fe1620 0} 2019-02-11T19:16:38.019156Z info Use default filter chain for {tcp 127.0.0.1 39535 0xc420fe1620 0} 2019-02-11T19:16:38.019615Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc420fe1830 0} 2019-02-11T19:16:38.020013Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc420fe1860 0} 2019-02-11T19:16:38.020501Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc420fe1890 0} 2019-02-11T19:16:38.021379Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc420fe17d0 0} 2019-02-11T19:16:38.021545Z info Use default filter chain for {tcp 127.0.0.1 40079 0xc420fe17d0 0} 2019-02-11T19:16:38.024952Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc420fe18c0 0} 2019-02-11T19:16:38.025215Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc420fe1800 0} 2019-02-11T19:16:38.027838Z info Use default filter chain for {tcp 127.0.0.1 38277 0xc420fe1800 0} 2019-02-11T19:16:38.028419Z info Use default filter chain for {tcp 127.0.0.1 43211 0xc420fe1a70 0} 2019-02-11T19:16:38.028760Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc420fe1830 0} 2019-02-11T19:16:38.029315Z info Use default filter chain for {tcp 127.0.0.1 40729 0xc420fe1830 0} 2019-02-11T19:16:38.029393Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc420fe1860 0} 2019-02-11T19:16:38.029687Z info Use default filter chain for {tcp 127.0.0.1 37493 0xc420fe1860 0} 2019-02-11T19:16:38.030027Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc420fe1890 0} 2019-02-11T19:16:38.030320Z info Use default filter chain for {tcp 127.0.0.1 38975 0xc420fe1890 0} 2019-02-11T19:16:38.030884Z info Use default filter chain for {tcp 127.0.0.1 40607 0xc420fe1aa0 0} 2019-02-11T19:16:38.031839Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc420fe18c0 0} 2019-02-11T19:16:38.032462Z info Use default filter chain for {tcp 127.0.0.1 42003 0xc420fe18c0 0} 2019-02-11T19:16:38.033220Z info Use default filter chain for {tcp 127.0.0.1 33843 0xc420fe1ad0 0} 2019-02-11T19:16:38.033501Z info Use default filter chain for {tcp 127.0.0.1 43211 0xc420fe1a70 0} 2019-02-11T19:16:38.033813Z info Use default filter chain for {tcp 127.0.0.1 39449 0xc420fe1b00 0} 2019-02-11T19:16:38.034419Z info Use default filter chain for {tcp 127.0.0.1 41891 0xc420fe1b30 0} 2019-02-11T19:16:38.034940Z info Use default filter chain for {tcp 127.0.0.1 43211 0xc420fe1a70 0} 2019-02-11T19:16:38.035117Z info Use default filter chain for {tcp 127.0.0.1 40607 0xc420fe1aa0 0} 2019-02-11T19:16:38.036528Z info Use default filter chain for {tcp 127.0.0.1 33843 0xc420fe1ad0 0} 2019-02-11T19:16:38.036849Z info Use default filter chain for {tcp 127.0.0.1 42019 0xc420fe1b60 0} 2019-02-11T19:16:38.036920Z info Use default filter chain for {tcp 127.0.0.1 39449 0xc420fe1b00 0} 2019-02-11T19:16:38.037283Z info Use default filter chain for {tcp 127.0.0.1 40607 0xc420fe1aa0 0} 2019-02-11T19:16:38.037299Z info Use default filter chain for {tcp 127.0.0.1 41891 0xc420fe1b30 0} 2019-02-11T19:16:38.038845Z info Use default filter chain for {tcp 127.0.0.1 42019 0xc420fe1b60 0} 2019-02-11T19:16:38.039610Z info Use default filter chain for {tcp 127.0.0.1 33843 0xc420fe1ad0 0} 2019-02-11T19:16:38.040224Z info Use default filter chain for {tcp 127.0.0.1 39449 0xc420fe1b00 0} 2019-02-11T19:16:38.040881Z info Use default filter chain for {tcp 127.0.0.1 41891 0xc420fe1b30 0} 2019-02-11T19:16:38.043185Z info Use default filter chain for {tcp 127.0.0.1 42019 0xc420fe1b60 0} 2019-02-11T19:16:38.061467Z info ads LDS: PUSH for node:c.AlhAId3-_E addr:"[::1]:40042" listeners:41 62420 2019-02-11T19:16:38.063513Z info ads LDS: PUSH for node:a.8pxMwZjI0T addr:"[::1]:40022" listeners:41 62420 2019-02-11T19:16:38.069461Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:9 2019-02-11T19:16:38.069467Z info ads ADS: RDS: PUSH for node: c.AlhAId3-_E addr:[::1]:40042 routes:9 2019-02-11T19:16:38.071866Z info ads LDS: PUSH for node:b.nhfiTPZnp6 addr:"[::1]:40032" listeners:41 62420 2019-02-11T19:16:38.074640Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:9 2019-02-11T19:16:38.074712Z info ads Push finished: 68.74271ms { "ProxyStatus": {}, "Start": "2019-02-11T19:16:38.005965875Z", "End": "2019-02-11T19:16:38.074683592Z" } 2019-02-11T19:16:38.137369Z info ads ADS: RDS: PUSH for node: c.AlhAId3-_E addr:[::1]:40042 routes:13 2019-02-11T19:16:38.140957Z info ads ADS: RDS: PUSH for node: b.nhfiTPZnp6 addr:[::1]:40032 routes:13 2019-02-11T19:16:38.142220Z info ads ADS: RDS: PUSH for node: a.8pxMwZjI0T addr:[::1]:40022 routes:13 2019-02-11T19:16:38.811093Z info ads LDS: PUSH for node:a.8pxMwZjI0T addr:"[::1]:40016" listeners:41 101991 --- PASS: TestAuthnPermissive (12.62s) PASS 2019-02-11T19:16:38.812085Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.812177Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.812268Z info transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:34253->127.0.0.1:58662: use of closed network connection 2019-02-11T19:16:38.812331Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.812528Z info rpc error: code = Canceled desc = context canceled 2019-02-11T19:16:38.812678Z info rpc error: code = Canceled desc = grpc: the client connection is closing 2019-02-11T19:16:38.812730Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.812777Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.812827Z info ads ADS: "[::1]:40022" sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-1 terminated EOF 2019-02-11T19:16:38.812970Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813006Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813101Z info transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:45323->127.0.0.1:54004: use of closed network connection 2019-02-11T19:16:38.813166Z info rpc error: code = Canceled desc = context canceled 2019-02-11T19:16:38.813242Z info rpc error: code = Canceled desc = grpc: the client connection is closing 2019-02-11T19:16:38.813263Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813268Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813454Z info ads ADS: "[::1]:40032" sidecar~127.0.0.1~b.nhfiTPZnp6~istio-system.svc.local-2 terminated rpc error: code = Canceled desc = context canceled 2019-02-11T19:16:38.813460Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813582Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813704Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813720Z info transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:40171->127.0.0.1:35176: use of closed network connection 2019-02-11T19:16:38.813725Z info rpc error: code = Canceled desc = context canceled 2019-02-11T19:16:38.813710Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.813804Z info rpc error: code = Canceled desc = grpc: the client connection is closing 2019-02-11T19:16:38.813956Z info ads ADS: "[::1]:40042" sidecar~127.0.0.1~c.AlhAId3-_E~istio-system.svc.local-3 terminated EOF 2019-02-11T19:16:38.814025Z info transport: http2Server.HandleStreams failed to read frame: read tcp [::1]:33789->[::1]:40042: read: connection reset by peer 2019-02-11T19:16:38.814026Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814067Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814182Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814189Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814213Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814254Z info ads ADS: "[::1]:40016" sidecar~127.0.0.1~a.8pxMwZjI0T~istio-system.svc.local-4 terminated rpc error: code = Canceled desc = context canceled 2019-02-11T19:16:38.814263Z info transport: loopyWriter.run returning. connection error: desc = "transport is closing" 2019-02-11T19:16:38.814266Z warn http: Server closed 2019-02-11T19:16:38.814282Z info ControlZ terminated ok istio.io/istio/tests/integration2/pilot/security 12.996s tests/integration2/tests.mk:61: recipe for target 'test.integration.local' failed make: *** [test.integration.local] Error 2